Getting a Timeout Exception

[precisemath]

We are using .NET Framework 462. As soon as we upgraded to version: 2.0.593.37019 we started getting the timeout issue. We did not have this issue previously.

Timeout awaiting response (outbound=0KiB, inbound=0KiB, 5187ms elapsed, timeout is 5000ms), inst: 0, qu: 0, qs: 1, aw: False, rs: ReadAsync, ws: Idle, in: 0, mgr: 10 of 10 available,
IOCP: (Busy=0,Free=1000,Min=16,Max=1000), WORKER: (Busy=1,Free=32766,Min=16,Max=32767), v: 2.0.593.37019 (Please take a look at this article for some common client-side issues that can cause timeouts: https://stackexchange.github.io/StackExchange.Redis/Timeouts)"

[mgravell]

OK. I can't see from the error, but do you know what message it was sending? I've seen some anecdotal reports of "eval" being problematic sometimes, in particular. Also, is this sync or async?

…

On Fri, 5 Apr 2019, 19:32 Pavan Narendra, ***@***.***> wrote: We are using .NET Framework 462. As soon as we upgraded to version: 2.0.593.37019 we started getting the timeout issue. We did not have this issue previously. Timeout awaiting response (outbound=0KiB, inbound=0KiB, 5187ms elapsed, timeout is 5000ms), inst: 0, qu: 0, qs: 1, aw: False, rs: ReadAsync, ws: Idle, in: 0, mgr: 10 of 10 available, IOCP: (Busy=0,Free=1000,Min=16,Max=1000), WORKER: (Busy=1,Free=32766,Min=16,Max=32767), v: 2.0.593.37019 (Please take a look at this article for some common client-side issues that can cause timeouts: https://stackexchange.github.io/StackExchange.Redis/Timeouts)" — You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub <#1114>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AABDsAbp6l4GEgMwx2eGDBrvEuxRDG7Pks5vd5argaJpZM4cffwL> .

[precisemath]

Here is the command that I am running: redisDB.SetAddAsync(key,vals) where redisDB is an instance of the Redis Database. The number of vals are NOT more than 1000. We run 10 of these commands in parallel.
It is throwing an exception on this command. This exception only occurred when we upgraded the library otherwise was working fine.

[mgravell]

I notice that there's no "in-pipe"/"out-pipe" data here; can I ask - is this talking to a TLS endpoint? (I'm trying to determine whether the lack of in-pipe/out-pipe is a: because the pipe was toast, vs b: because it wasn't queryable (because: TLS)

[precisemath]

If by TLS you are asking me whether we are using a ssl, here is a part of the configuration that we use to connect to the redis DB: ssl=True,abortConnect=False

[mgravell]

OK, so indeed the SSL/TLS explains the absence of some numbers I was looking for. Let me see if I can find a way to get those, to see what is happening ...

[matthewDDennis]

I am also trying to use this in a .NET4.6.2 ASP.NET WebForms app. All calls are synchronous.
Errors are similar to the errors below. Hope this helps.

Timeout performing HDEL user/info/ (2000ms), inst: 1, qu: 0, qs: 3,aw: False, bs: Inactive, in: 0, in-pipe: 23024962, out-pipe: 0,serverEndpoint: 192.168.5.133:6379, mgr: 9 of 10 available,clientName: CP-WEB3, IOCP: (Busy=0,Free=1000,Min=16,Max=1000),WORKER: (Busy=70,Free=32697,Min=16,Max=32767), v: 2.0.588.23261 (Please take a look at this article for some common client-side issues that can cause timeouts: https://stackexchange.github.io/StackExchange.Redis/Timeouts

also

The timeout was reached before the message could be written to the output buffer, and it was not sent, 
 
timeout: 2000, 
phys: Idle, 
outbound: 0KiB, 
inbound: 0KiB, 
inst: 0, 
qu: 0, 
qs: 0, 
aw: True, 
bs: Inactive, 
in: 0, 
in-pipe: 0, 
out-pipe: 0,
serverEndpoint: 192.168.5.133:6380, 
mgr: 10 of 10 available, 
clientName: CP-WEB2, 
IOCP: (
Busy=50,
Free=950,
Min=16,
Max=1000
), 
WORKER: (
Busy=794,
Free=31973,
Min=16,
Max=32767
), 
v: 2.0.588.23261

[matthewDDennis]

aslo gettng this error

No connection is available to service this operation: HGET forum/name; Thread was being aborted.; IOCP: (Busy=0,Free=1000,Min=16,Max=1000), WORKER: (Busy=92,Free=32675,Min=16,Max=32767), Local-CPU: n/a (inner: InternalFailure (None, last-recv: 3832) on 192.168.5.133:6380/Interactive, Writing, last: HGET, origin: WriteMessageToServerInsideWriteLock, outstanding: 0, last-read: 0s ago, last-write: 0s ago, keep-alive: 60s, state: ConnectedEstablished, mgr: 9 of 10 available, in: 0, in-pipe: 0, out-pipe: 0, last-heartbeat: 0s ago, last-mbeat: 0s ago, global: 0s ago, v: 2.0.588.23261 (inner: Thread was being aborted.

[matthewDDennis]

and this

Timeout performing HGETALL content/languages/token-counts/C# (2000ms), inst: 0, qu: 0, qs: 1, aw: False, bs: Inactive, in: 65536, in-pipe: 6154508, out-pipe: 0, serverEndpoint: 192.168.5.133:6379, mgr: 9 of 10 available, clientName: JOBS1, IOCP: (Busy=0,Free=1000,Min=4,Max=1000), WORKER: (Busy=1,Free=32766,Min=4,Max=32767), v: 2.0.588.23261 (Please take a look at this article for some common client-side issues that can cause timeouts: https://stackexchange.github.io/StackExchange.Redis/Timeouts)

[mgravell]

The two with a massive in-pipe look like you've issued a small request that generates a *huge* response. r601 should tell you exactly what the "now and next" messages are in the read queue, if it isn't obvious in your own code. I hadn't pushed 601 to nuget, but I can do that now. Ultimately, if you request something huge, you *either* need to switch to iterative mechanisms (for example, preferring "hscan" over "hgetall" if querying a large hash), or you'll need a huge timeout - because bandwidth will be the limiting factor. The middle one (thread was being aborted) smells like an asp.net app-pool recycle?

…

On Mon, 15 Apr 2019, 20:46 Matthew Dennis, ***@***.***> wrote: and this Timeout performing HGETALL content/languages/token-counts/C# (2000ms), inst: 0, qu: 0, qs: 1, aw: False, bs: Inactive, in: 65536, in-pipe: 6154508, out-pipe: 0, serverEndpoint: 192.168.5.133:6379, mgr: 9 of 10 available, clientName: JOBS1, IOCP: (Busy=0,Free=1000,Min=4,Max=1000), WORKER: (Busy=1,Free=32766,Min=4,Max=32767), v: 2.0.588.23261 (Please take a look at this article for some common client-side issues that can cause timeouts: https://stackexchange.github.io/StackExchange.Redis/Timeouts) — You are receiving this because you commented. Reply to this email directly, view it on GitHub <#1114 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AABDsIHFssadj8nk9B5WW0rPlk9Yiyi3ks5vhNcDgaJpZM4cffwL> .

[mgravell]

I should also note that if the huge op is big enough to make the library think the heartbeat has failed, then that could also momentarily cause the "no connection is available" issue.

…

On Tue, 16 Apr 2019, 11:11 Marc Gravell, ***@***.***> wrote: The two with a massive in-pipe look like you've issued a small request that generates a *huge* response. r601 should tell you exactly what the "now and next" messages are in the read queue, if it isn't obvious in your own code. I hadn't pushed 601 to nuget, but I can do that now. Ultimately, if you request something huge, you *either* need to switch to iterative mechanisms (for example, preferring "hscan" over "hgetall" if querying a large hash), or you'll need a huge timeout - because bandwidth will be the limiting factor. The middle one (thread was being aborted) smells like an asp.net app-pool recycle? On Mon, 15 Apr 2019, 20:46 Matthew Dennis, ***@***.***> wrote: > and this > > Timeout performing HGETALL content/languages/token-counts/C# (2000ms), > inst: 0, qu: 0, qs: 1, aw: False, bs: Inactive, in: 65536, in-pipe: > 6154508, out-pipe: 0, serverEndpoint: 192.168.5.133:6379, mgr: 9 of 10 > available, clientName: JOBS1, IOCP: (Busy=0,Free=1000,Min=4,Max=1000), > WORKER: (Busy=1,Free=32766,Min=4,Max=32767), v: 2.0.588.23261 (Please take > a look at this article for some common client-side issues that can cause > timeouts: https://stackexchange.github.io/StackExchange.Redis/Timeouts) > > — > You are receiving this because you commented. > Reply to this email directly, view it on GitHub > <#1114 (comment)>, > or mute the thread > <https://github.com/notifications/unsubscribe-auth/AABDsIHFssadj8nk9B5WW0rPlk9Yiyi3ks5vhNcDgaJpZM4cffwL> > . >

[matthewDDennis]

You are correct. I found out that someone else was doing a hgetall all with a massive response. I’ll get this fixed d and report back.

Thanks.

[mgravell]

r601 is now on nuget and may be useful for anyone seeing this kind of timeout if the cause of the timeout is ultimately : large payloads blocking the pipes.

[ganaware]

I have encounterd the same problems too. The exceptions said that:

• Timeout performing GET (5000ms), next: SELECT, inst: 0, qu: 20333, qs: 3769, aw: True, bw: Flushing, rs: ReadAsync, ws: Flushing, in: 8192, in-pipe: 0, out-pipe: 524307, serverEndpoint: Unspecified/localhost:6379, mgr: 9 of 10 available, clientName: AYULON, IOCP: (Busy=24,Free=976,Min=8,Max=1000), WORKER: (Busy=1,Free=32766,Min=8,Max=32767), v: 2.0.601.3402 (Please take a look at this article for some common client-side issues that can cause timeouts: https://stackexchange.github.io/StackExchange.Redis/Timeouts)
• Failed to write
• No connection is available to service this operation: GET dummy; IOCP: (Busy=24,Free=976,Min=8,Max=1000), WORKER: (Busy=2,Free=32765,Min=8,Max=32767), Local-CPU: n/a

Fortunately, I maybe found a workaround. After I replaced all appearances of IDatabase by IDatabaseAsync (namely I am using async-APIs only), the problems seem to be disappeared.

--

• StackExchange.Redis 2.0.601
• .NET Core 2.1
• Windows7(64bit)

[Rodrigo-Andrade]

@mgravell I understand that the lib does pipelining, how does the (Sync/Async)Timeout is impacted by pipelining? i could not find in the code how the pipelining is being done, like, how many messages you send at a time.