- 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
18 Answer(s)
-
0
Hello ,
Please check this similar issue https://github.com/StackExchange/StackExchange.Redis/issues/1120#issuecomment-818588316 and try the solution.
Thanks,
-
0
Hi,
Just tested this, but adding sslprotocols=tls12 to the connection string didn't help. We're currently also not using Redis with SSL. We experience the issue also in localhost.
Best regards, Steff
-
0
Hello ,
Please check this https://abp.io/support/questions/5847/redis-commands-timeout
Thanks
-
0
Thanks! Increasing the MinThreads seems to work:
public class Program { public static async Task<int> Main(string[] args) { try { ... System.Threading.ThreadPool.GetMinThreads(out int minWorkerThreads, out int minCompletionPortThreads); System.Threading.ThreadPool.SetMinThreads(minWorkerThreads * 50, minCompletionPortThreads * 50); ... } ... } }
I've tested this by multiplying the MinThreads with 50, resulting in 1000 worker threads and 50 completion port threads. I'm not sure if this is a best practice. Is 50 times too much? How should I choose a good amount of threads?
This might also result in some other issues according to Microsoft docs: https://learn.microsoft.com/en-us/dotnet/standard/threading/the-managed-thread-pool#thread-pool-minimums
Isn't this just a framework issue? Calling the cache too much? I would think that the managed thread pool should do it's job just fine, without adjusting the minimum of worker threads.
-
0
I'll check this
-
0
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
Hi,
This should not be a problem; ABP only calls once in a HTTP request.
And you can try disable dynamic claims system to test it
context.Services.Configure<AbpClaimsPrincipalFactoryOptions>(options => { options.IsDynamicClaimsEnabled = false; });
-
0
When you enable the Dynamic Claims feature, in each request, we read the claims (from Redis) of the request to check current permissions in the current session. If you disable it, when you revoke permission from a user, he needs to log out / log in to refresh his permissions.
-
0
Thanks for the feedback!
Disabling dynamic claims (which we also don't want to) doesn't fix the issue. I see it's trying to retrieve & expire localizations from the cache?
Stack trace: API log gets spammed with: +- 50 times:
2024-10-02 11:01:19Z [WRN] The message timed out in the backlog attempting to send because no connection became available, command=HMGET, timeout: 5000, outbound: 0KiB, inbound: 1KiB, inst: 0, qu: 37, qs: 0, aw: True, bw: CheckingForTimeoutComplete, rs: ReadAsync, ws: Idle, in: 0, in-pipe: 0, out-pipe: 0, last-in: 1, cur-in: 0, sync-ops: 448, async-ops: 4074, serverEndpoint: localhost:6379, conn-sec: 31,24, 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=39,Free=32728,Min=20,Max=32767), POOL: (Threads=39,QueuedItems=47,CompletedItems=68595,Timers=15), 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: The message timed out in the backlog attempting to send because no connection became available, command=HMGET, timeout: 5000, outbound: 0KiB, inbound: 1KiB, inst: 0, qu: 37, qs: 0, aw: True, bw: CheckingForTimeoutComplete, rs: ReadAsync, ws: Idle, in: 0, in-pipe: 0, out-pipe: 0, last-in: 1, cur-in: 0, sync-ops: 448, async-ops: 4074, serverEndpoint: localhost:6379, conn-sec: 31,24, 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=39,Free=32728,Min=20,Max=32767), POOL: (Threads=39,QueuedItems=47,CompletedItems=68595,Timers=15), 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-02 11:01:19Z [WRN] ---------- Exception Data ---------- Redis-Message = HMGET t:661be86b-0b72-db1a-9151-3a0624e8440d,c:Volo.Abp.LanguageManagement.Texts,k:Fuzed:ExternalPortal_en-BE Redis-Timeout = 5000 Redis-Write-State = Idle Redis-Read-State = ReadAsync Redis-OutboundDeltaKB = 0KiB Redis-InboundDeltaKB = 1KiB Redis-OpsSinceLastHeartbeat = 0 Redis-Queue-Awaiting-Write = 37 Redis-Queue-Awaiting-Response = 0 Redis-Active-Writer = True Redis-Backlog-Writer = CheckingForTimeoutComplete Redis-Inbound-Bytes = 0 Redis-Inbound-Pipe-Bytes = 0 Redis-Outbound-Pipe-Bytes = 0 Redis-Last-Result-Bytes = 1 Redis-Inbound-Buffer-Bytes = 0 Redis-Sync-Ops = 448 Redis-Async-Ops = 4074 Redis-Server-Endpoint = localhost:6379 Redis-Server-Connected-Seconds = 31,24 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=39,Free=32728,Min=20,Max=32767) Redis-ThreadPool-Items = (Threads=39,QueuedItems=47,CompletedItems=68595,Timers=15) Redis-Busy-Workers = 39 Redis-Version = 2.7.27.49176 redis-command = HMGET t:661be86b-0b72-db1a-9151-3a0624e8440d,c:Volo.Abp.LanguageManagement.Texts,k:Fuzed:ExternalPortal_en-BE request-sent-status = WaitingInBacklog redis-server = localhost:6379
+- 50 times:
2024-10-02 11:01:37Z [WRN] Timeout performing EXPIRE (5000ms), next: EXPIRE t:661be86b-0b72-db1a-9151-3a0624e8440d,c:Volo.Abp.LanguageManagement.Texts,k:Fuzed:Platform_en, inst: 28, qu: 0, qs: 28, aw: False, bw: SpinningDown, rs: ReadAsync, ws: Idle, in: 1060, in-pipe: 0, out-pipe: 0, last-in: 0, cur-in: 0, sync-ops: 674, async-ops: 4074, serverEndpoint: localhost:6379, conn-sec: 49,66, 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=66,Free=32701,Min=20,Max=32767), POOL: (Threads=66,QueuedItems=25,CompletedItems=68718,Timers=14), 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 EXPIRE (5000ms), next: EXPIRE t:661be86b-0b72-db1a-9151-3a0624e8440d,c:Volo.Abp.LanguageManagement.Texts,k:Fuzed:Platform_en, inst: 28, qu: 0, qs: 28, aw: False, bw: SpinningDown, rs: ReadAsync, ws: Idle, in: 1060, in-pipe: 0, out-pipe: 0, last-in: 0, cur-in: 0, sync-ops: 674, async-ops: 4074, serverEndpoint: localhost:6379, conn-sec: 49,66, 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=66,Free=32701,Min=20,Max=32767), POOL: (Threads=66,QueuedItems=25,CompletedItems=68718,Timers=14), 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.KeyExpire(RedisKey key, Nullable`1 expiry, ExpireWhen when, CommandFlags flags) in /_/src/StackExchange.Redis/RedisDatabase.cs:line 840 at Microsoft.Extensions.Caching.StackExchangeRedis.RedisCache.Refresh(IDatabase cache, String key, Nullable`1 absExpr, Nullable`1 sldExpr) 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-02 11:01:37Z [WRN] ---------- Exception Data ---------- Redis-Message = EXPIRE t:661be86b-0b72-db1a-9151-3a0624e8440d,c:Volo.Abp.LanguageManagement.Texts,k:Fuzed:Platform_en-BE Redis-Message-Next = EXPIRE t:661be86b-0b72-db1a-9151-3a0624e8440d,c:Volo.Abp.LanguageManagement.Texts,k:Fuzed:Platform_en Redis-OpsSinceLastHeartbeat = 28 Redis-Queue-Awaiting-Write = 0 Redis-Queue-Awaiting-Response = 28 Redis-Active-Writer = False Redis-Backlog-Writer = SpinningDown Redis-Read-State = ReadAsync Redis-Write-State = Idle Redis-Inbound-Bytes = 1060 Redis-Inbound-Pipe-Bytes = 0 Redis-Outbound-Pipe-Bytes = 0 Redis-Last-Result-Bytes = 0 Redis-Inbound-Buffer-Bytes = 0 Redis-Sync-Ops = 674 Redis-Async-Ops = 4074 Redis-Server-Endpoint = localhost:6379 Redis-Server-Connected-Seconds = 49,66 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=66,Free=32701,Min=20,Max=32767) Redis-ThreadPool-Items = (Threads=66,QueuedItems=25,CompletedItems=68718,Timers=14) Redis-Busy-Workers = 66 Redis-Version = 2.7.27.49176 redis-command = EXPIRE t:661be86b-0b72-db1a-9151-3a0624e8440d,c:Volo.Abp.LanguageManagement.Texts,k:Fuzed:Platform_en-BE request-sent-status = Sent redis-server = localhost:6379
+- 50 times:
2024-10-02 11:01:41Z [DBG] Added 0 entity changes to the current audit log
-
0
ok then we'll look deeper into this issue
-
0
Hi
I see it's trying to retrieve & expire localizations from the cache?
Please share full http request debug logs of this exception.
Thanks
-
0
@maliming Can I send the full log to you by email?
-
0
sure, liming.ma@volosoft.com
-
0
sure, liming.ma@volosoft.com
I've just sent you the full log by email.
-
0
hi
Please try to remove
DynamicLocalizationResourceContributor
and try again.public override void ConfigureServices(ServiceConfigurationContext context) { PostConfigure<AbpLocalizationOptions>(options => { options.GlobalContributors.Remove<DynamicLocalizationResourceContributor>(); }); }
-
0
Please try to remove
DynamicLocalizationResourceContributor
and try again.That does the job! Removing the DynamicLocalizationResourceContributor from the language management module gives a big performance boost. Which functionality do we lose by removing this?
-
0
You can't use dynamic localization texts from database without
DynamicLocalizationResourceContributor
-
0
I just found this related question: https://abp.io/support/questions/2880/Redis-performance-issues-in-LanguageManagement-DynamicLocalizationResourceContributor
-
0
hi
This may be a problem caused by the async API.
I will check it later.