Redis cache timeout on multiple concurrent authenticated API requests due to retrieving dynamic claims cache for user? #8007

s.beckers created 2 months ago

ABP Framework version: v8.1.4
UI Type: Angular
Database System: EF Core (SQL Server)
Tiered (for MVC) or Auth Server Separated (for Angular): no

We're displaying some image thumbnails (+-100, 40/40px) on a web page, each image is retrieved from an authorized API endpoint. The API ends up crashing/unavailable due to Redis caching timeouts. K8S health checks fail, and API container reboots..

Stack trace: API log gets spammed with: +- 50 times:

2024-10-01 07:40:53Z [DBG] Get dynamic claims cache for user: c7356510-4d74-f816-9a7d-3a0624e8562a

+- 40 times:

2024-10-01 07:41:02Z [WRN] Timeout performing HMGET (5000ms), next: EXPIRE t:661be86b-0b72-db1a-9151-3a0624e8440d,c:Volo.Abp.LanguageManagement.Texts,k:Fuzed:Platform_en, inst: 128, qu: 0, qs: 128, aw: False, bw: SpinningDown, rs: ReadAsync, ws: Idle, in: 17250, in-pipe: 0, out-pipe: 0, last-in: 1, cur-in: 0, sync-ops: 573, async-ops: 5444, serverEndpoint: localhost:6379, conn-sec: 25,21, aoc: 0, mc: 1/1/0, mgr: 10 of 10 available, clientName: FZDNOT06(SE.Redis-v2.7.27.49176), IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=49,Free=32718,Min=20,Max=32767), POOL: (Threads=49,QueuedItems=4,CompletedItems=71543,Timers=18), v: 2.7.27.49176 (Please take a look at this article for some common client-side issues that can cause timeouts: https://stackexchange.github.io/StackExchange.Redis/Timeouts)
StackExchange.Redis.RedisTimeoutException: Timeout performing HMGET (5000ms), next: EXPIRE t:661be86b-0b72-db1a-9151-3a0624e8440d,c:Volo.Abp.LanguageManagement.Texts,k:Fuzed:Platform_en, inst: 128, qu: 0, qs: 128, aw: False, bw: SpinningDown, rs: ReadAsync, ws: Idle, in: 17250, in-pipe: 0, out-pipe: 0, last-in: 1, cur-in: 0, sync-ops: 573, async-ops: 5444, serverEndpoint: localhost:6379, conn-sec: 25,21, aoc: 0, mc: 1/1/0, mgr: 10 of 10 available, clientName: FZDNOT06(SE.Redis-v2.7.27.49176), IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=49,Free=32718,Min=20,Max=32767), POOL: (Threads=49,QueuedItems=4,CompletedItems=71543,Timers=18), v: 2.7.27.49176 (Please take a look at this article for some common client-side issues that can cause timeouts: https://stackexchange.github.io/StackExchange.Redis/Timeouts)
   at StackExchange.Redis.ConnectionMultiplexer.ExecuteSyncImpl[T](Message message, ResultProcessor`1 processor, ServerEndPoint server, T defaultValue) in /_/src/StackExchange.Redis/ConnectionMultiplexer.cs:line 2105
   at StackExchange.Redis.RedisDatabase.HashGet(RedisKey key, RedisValue[] hashFields, CommandFlags flags) in /_/src/StackExchange.Redis/RedisDatabase.cs:line 407
   at Microsoft.Extensions.Caching.StackExchangeRedis.RedisCache.GetAndRefresh(String key, Boolean getData)
   at Volo.Abp.Caching.DistributedCache`2.Get(TCacheKey key, Nullable`1 hideErrors, Boolean considerUow)
2024-10-01 07:41:02Z [WRN] ---------- Exception Data ----------
Redis-Message = EXPIRE t:661be86b-0b72-db1a-9151-3a0624e8440d,c:Volo.Abp.LanguageManagement.Texts,k:Fuzed:Platform_en
Redis-Message-Next = EXPIRE t:661be86b-0b72-db1a-9151-3a0624e8440d,c:Volo.Abp.LanguageManagement.Texts,k:Fuzed:Platform_en
Redis-OpsSinceLastHeartbeat = 128
Redis-Queue-Awaiting-Write = 0
Redis-Queue-Awaiting-Response = 128
Redis-Active-Writer = False
Redis-Backlog-Writer = SpinningDown
Redis-Read-State = ReadAsync
Redis-Write-State = Idle
Redis-Inbound-Bytes = 17250
Redis-Inbound-Pipe-Bytes = 0
Redis-Outbound-Pipe-Bytes = 0
Redis-Last-Result-Bytes = 1
Redis-Inbound-Buffer-Bytes = 0
Redis-Sync-Ops = 573
Redis-Async-Ops = 5444
Redis-Server-Endpoint = localhost:6379
Redis-Server-Connected-Seconds = 25,2
Redis-Abort-On-Connect = 0
Redis-Multiplexer-Connects = 1/1/0
Redis-Manager = 10 of 10 available
Redis-Client-Name = FZDNOT06(SE.Redis-v2.7.27.49176)
Redis-ThreadPool-IO-Completion = (Busy=0,Free=1000,Min=1,Max=1000)
Redis-ThreadPool-Workers = (Busy=49,Free=32718,Min=20,Max=32767)
Redis-ThreadPool-Items = (Threads=49,QueuedItems=4,CompletedItems=71543,Timers=18)
Redis-Busy-Workers = 49
Redis-Version = 2.7.27.49176
redis-command = EXPIRE t:661be86b-0b72-db1a-9151-3a0624e8440d,c:Volo.Abp.LanguageManagement.Texts,k:Fuzed:Platform_en
request-sent-status = Sent
redis-server = localhost:6379

Again +- 50 times:

2024-10-01 07:40:53Z [DBG] Get dynamic claims cache for user: c7356510-4d74-f816-9a7d-3a0624e8562a

+- 50 times:

2024-10-01 07:41:14Z [DBG] Added 0 entity changes to the current audit log

29 Answer(s)