-
Notifications
You must be signed in to change notification settings - Fork 1.5k
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
The message timed out in the backlog attempting to send because no connection became available #2698
Comments
Marc and I are trying to reason about this and our best guess is that the lowered timeout to 1000ms which is also the frequency of flushing of backlog items may be colliding when there's a pause of any duration and commands come in just at the heartbeat interval. My recommendation here would be if your timeout is lower like 1000ms then you likely want to lower the |
I'll try that to see if it reduces or eliminates the issue. Thanks! |
I haven't tried this. |
@NickCraver Timeout awaiting response (outbound=0KiB, inbound=0KiB, 1178ms elapsed, timeout is 1000ms), command=GET, next: GET xxx:34169274, inst: 0, qu: 0, qs: 81, aw: False, bw: SpinningDown, rs: ReadAsync, ws: Idle, in: 0, in-pipe: 0, out-pipe: 0, last-in: 1659, cur-in: 0, sync-ops: 1, async-ops: 6650939, serverEndpoint: x.x.x.x:6379, conn-sec: 23737.05, aoc: 0, mc: 1/1/0, mgr: 6 of 6 available, clientName: myproject(SE.Redis-v2.7.33.41805), PerfCounterHelperkeyHashSlot: 7263, IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=16,Free=32751,Min=500,Max=32767), POOL: (Threads=30,QueuedItems=12,CompletedItems=83240631,Timers=27), v: 2.7.33.41805 (Please take a look at this article for some common client-side issues that can cause timeouts: https://stackexchange.github.io/StackExchange.Redis/Timeouts) The message timed out in the backlog attempting to send because no connection became available, command=GET, timeout: 1000, outbound: 0KiB, inbound: 0KiB, inst: 0, qu: 28, qs: 0, aw: False, bw: CheckingForTimeout, rs: ReadAsync, ws: Idle, in: 0, in-pipe: 0, out-pipe: 0, last-in: 1654, cur-in: 0, sync-ops: 1, async-ops: 58884859, serverEndpoint: x.x.x.x:6379, conn-sec: 241878.26, aoc: 0, mc: 1/1/0, mgr: 6 of 6 available, clientName: myproject(SE.Redis-v2.7.33.41805), PerfCounterHelperkeyHashSlot: 6881, IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=6,Free=32761,Min=500,Max=32767), POOL: (Threads=11,QueuedItems=1,CompletedItems=741107568,Timers=27), v: 2.7.33.41805 (Please take a look at this article for some common client-side issues that can cause timeouts: https://stackexchange.github.io/StackExchange.Redis/Timeouts) The message timed out in the backlog attempting to send because no connection became available, command=GET, timeout: 1000, outbound: 0KiB, inbound: 0KiB, inst: 0, qu: 29, qs: 0, aw: False, bw: CheckingForTimeout, rs: ReadAsync, ws: Idle, in: 0, in-pipe: 0, out-pipe: 0, last-in: 1654, cur-in: 0, sync-ops: 1, async-ops: 58884859, serverEndpoint: x.x.x.x:6379, conn-sec: 241878.26, aoc: 0, mc: 1/1/0, mgr: 6 of 6 available, clientName: myproject(SE.Redis-v2.7.33.41805), PerfCounterHelperkeyHashSlot: 9585, IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=6,Free=32761,Min=500,Max=32767), POOL: (Threads=11,QueuedItems=0,CompletedItems=741107568,Timers=27), v: 2.7.33.41805 (Please take a look at this article for some common client-side issues that can cause timeouts: https://stackexchange.github.io/StackExchange.Redis/Timeouts) The message timed out in the backlog attempting to send because no connection became available, command=GET, timeout: 1000, outbound: 0KiB, inbound: 0KiB, inst: 0, qu: 32, qs: 0, aw: False, bw: CheckingForTimeout, rs: ReadAsync, ws: Idle, in: 0, in-pipe: 0, out-pipe: 0, last-in: 1654, cur-in: 0, sync-ops: 1, async-ops: 58884859, serverEndpoint: x.x.x.x:6379, conn-sec: 241878.26, aoc: 0, mc: 1/1/0, mgr: 6 of 6 available, clientName: myproject(SE.Redis-v2.7.33.41805), PerfCounterHelperkeyHashSlot: 6491, IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=4,Free=32763,Min=500,Max=32767), POOL: (Threads=11,QueuedItems=0,CompletedItems=741107567,Timers=27), v: 2.7.33.41805 (Please take a look at this article for some common client-side issues that can cause timeouts: https://stackexchange.github.io/StackExchange.Redis/Timeouts) |
@cwhsu1984 I'm not sure why you're touching the backlog, my guess would be bursty spikes to the outbound socket writer. Is your load slamming in concentrated spikes in general? |
How do I know if this is the case? Is there anything I can do to debug on this? What I can tell you is that our application is a read heavy one. The read operation is 40x volume to the write. |
I'd recommend logging the disconnect/reconnect events (see https://github.com/StackExchange/StackExchange.Redis/blob/main/src/StackExchange.Redis/ConnectionMultiplexer.Events.cs) - so we can take a look at when timings are happening. At a 1 sec timeout, it's probable that we're disconnecting, but not reconnecting and processing in time, perhaps the reconnect takes a bit in your environment. You can pass a text writer into the |
thanks, let me try it |
In case someone needs it, this is how I log the connection
And the usage is like this.
|
@NickCraver Ever since my last tuning to the system, I face a different issue.
Previous, I set it to 500 workers, then I get the same error. |
Hi,
I'm getting lots of timeout like belows:
StackExchange.Redis.RedisTimeoutException: The message timed out in the backlog attempting to send because no connection became available, command=GET, timeout: 1000, outbound: 0KiB, inbound: 0KiB, inst: 0, qu: 12, qs: 0, aw: False, bw: CheckingForTimeout, rs: ReadAsync, ws: Idle, in: 0, in-pipe: 0, out-pipe: 0, last-in: 1659, cur-in: 0, sync-ops: 1, async-ops: 3759721, serverEndpoint: x.x.x.x:6379, conn-sec: 55196.89, aoc: 0, mc: 1/1/0, mgr: 6 of 6 available, clientName: myservice-6cfccff48c-q65wd(SE.Redis-v2.7.33.41805), PerfCounterHelperkeyHashSlot: 11447, IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=13,Free=32754,Min=500,Max=32767), POOL: (Threads=13,QueuedItems=123,CompletedItems=214865365,Timers=39), v: 2.7.33.41805 (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=GET, timeout: 1000, outbound: 0KiB, inbound: 0KiB, inst: 0, qu: 15, qs: 0, aw: False, bw: CheckingForTimeout, rs: ReadAsync, ws: Idle, in: 0, in-pipe: 0, out-pipe: 0, last-in: 1686, cur-in: 0, sync-ops: 1, async-ops: 3759721, serverEndpoint: x.x.x.x:6379, conn-sec: 55196.87, aoc: 0, mc: 1/1/0, mgr: 6 of 6 available, clientName: myservice-6cfccff48c-q65wd(SE.Redis-v2.7.33.41805), PerfCounterHelperkeyHashSlot: 9891, IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=13,Free=32754,Min=500,Max=32767), POOL: (Threads=13,QueuedItems=74,CompletedItems=214865364,Timers=39), v: 2.7.33.41805 (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=GET, timeout: 1000, outbound: 0KiB, inbound: 0KiB, inst: 0, qu: 17, qs: 0, aw: False, bw: CheckingForTimeout, rs: ReadAsync, ws: Idle, in: 0, in-pipe: 0, out-pipe: 0, last-in: 1686, cur-in: 0, sync-ops: 1, async-ops: 3759721, serverEndpoint: x.x.x.x:6379, conn-sec: 55196.87, aoc: 0, mc: 1/1/0, mgr: 6 of 6 available, clientName: myservice-6cfccff48c-q65wd(SE.Redis-v2.7.33.41805), PerfCounterHelperkeyHashSlot: 9839, IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=13,Free=32754,Min=500,Max=32767), POOL: (Threads=13,QueuedItems=72,CompletedItems=214865364,Timers=39), v: 2.7.33.41805 (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=GET, timeout: 1000, outbound: 0KiB, inbound: 0KiB, inst: 0, qu: 22, qs: 0, aw: False, bw: CheckingForTimeout, rs: ReadAsync, ws: Idle, in: 0, in-pipe: 0, out-pipe: 0, last-in: 1686, cur-in: 0, sync-ops: 1, async-ops: 3759721, serverEndpoint: x.x.x.x:6379, conn-sec: 55196.87, aoc: 0, mc: 1/1/0, mgr: 6 of 6 available, clientName: myservice-6cfccff48c-q65wd(SE.Redis-v2.7.33.41805), PerfCounterHelperkeyHashSlot: 9877, IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=13,Free=32754,Min=500,Max=32767), POOL: (Threads=13,QueuedItems=67,CompletedItems=214865364,Timers=39), v: 2.7.33.41805 (Please take a look at this article for some common client-side issues that can cause timeouts: https://stackexchange.github.io/StackExchange.Redis/Timeouts)
My service has over 20 pods and connecting to a redis cluster with 6 nodes.
I check the cpu and memory usage, my container cpu, memory is all below 30% when errors occur.
It happens over 200 times in a second, and it's gone. But I can see the same error from time to time.
When the errors occur, redis client connection is not high(below 200).
At the peak time, I can see over 600 connections without error, so it seems the error is not related to peak traffic.
I have configured the minThread already. Plus, I don't think it's a thread issue based on the worker pool details above.
And most operations are async-ops, so it doesn't seem related to sync or async issue.
What are the possible reasons for this timeout error?
Thanks.
The text was updated successfully, but these errors were encountered: