habbes / sharpbench

Online playground for quick throwaway C# microbenchmarks
https://sharpbench.dev
0 stars 2 forks source link

Server shutdown due to connection timeout (again) #19

Open habbes opened 3 months ago

habbes commented 3 months ago

Despite having a try-catch for the RedisTimeoutException, the worker crashed due to a timeout, this time due to RedisConnectionException

info: Sharpbench.Runner.Worker[0]
      Deleting folder '/tmp/45ku5u2z.wcz'
fail: Microsoft.Extensions.Hosting.Internal.Host[9]
      BackgroundService failed
      StackExchange.Redis.RedisConnectionException: The message timed out in the backlog attempting to send because no connection became available (5000ms) - Last Connection Exception: SocketFailure (ReadSocketError/ConnectionReset, 0-read, last-recv: 0) on viaduct.proxy.rlwy.net:13148/Interactive, Flushed/Faulted, last: ECHO, origin: ReadFromPipe, outstanding: 13, last-read: 0s ago, last-write: 0s ago, unanswered-write: 0s ago, keep-alive: 60s, state: ConnectedEstablishing, mgr: 9 of 10 available, last-heartbeat: never, last-mbeat: 0s ago, global: 0s ago, v: 2.7.23.42580, command=RPOP, timeout: 5000, inst: 0, qu: 0, qs: 0, aw: False, bw: CheckingForTimeout, last-in: 0, cur-in: 0, sync-ops: 3, async-ops: 21903, serverEndpoint: viaduct.proxy.rlwy.net:13148, conn-sec: n/a, aoc: 1, mc: 1/1/0, mgr: 10 of 10 available, clientName: sharpbenchvm(SE.Redis-v2.7.23.42580), IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=3,Free=32764,Min=2,Max=32767), POOL: (Threads=4,QueuedItems=0,CompletedItems=176406,Timers=1), v: 2.7.23.42580 (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.RedisConnectionException: SocketFailure (ReadSocketError/ConnectionReset, 0-read, last-recv: 0) on viaduct.proxy.rlwy.net:13148/Interactive, Flushed/Faulted, last: ECHO, origin: ReadFromPipe, outstanding: 13, last-read: 0s ago, last-write: 0s ago, unanswered-write: 0s ago, keep-alive: 60s, state: ConnectedEstablishing, mgr: 9 of 10 available, last-heartbeat: never, last-mbeat: 0s ago, global: 0s ago, v: 2.7.23.42580
       ---> Pipelines.Sockets.Unofficial.ConnectionResetException: Connection reset by peer
       ---> System.Net.Sockets.SocketException (104): Connection reset by peer
         at Pipelines.Sockets.Unofficial.Internal.Throw.Socket(Int32 errorCode) in /_/src/Pipelines.Sockets.Unofficial/Internal/Throw.cs:line 59
         at Pipelines.Sockets.Unofficial.SocketConnection.DoReceiveAsync() in /_/src/Pipelines.Sockets.Unofficial/SocketConnection.Receive.cs:line 64
         --- End of inner exception stack trace ---
         at System.IO.Pipelines.PipeCompletion.ThrowLatchedException()
         at System.IO.Pipelines.Pipe.GetReadAsyncResult()
         at StackExchange.Redis.PhysicalConnection.ReadFromPipe()
         --- End of inner exception stack trace ---
         --- End of inner exception stack trace ---
         at Sharpbench.Core.JobQueue.GetNextJob() in /home/azureuser/sharpbench/core/JobQueue.cs:line 77
         at Sharpbench.Core.JobQueue.ListenForJobs(CancellationToken clt)+MoveNext() in /home/azureuser/sharpbench/core/JobQueue.cs:line 57
         at Sharpbench.Core.JobQueue.ListenForJobs(CancellationToken clt)+System.Threading.Tasks.Sources.IValueTaskSource<System.Boolean>.GetResult()
         at Sharpbench.Runner.Worker.ExecuteAsync(CancellationToken stoppingToken) in /home/azureuser/sharpbench/runner/Worker.cs:line 23
         at Sharpbench.Runner.Worker.ExecuteAsync(CancellationToken stoppingToken) in /home/azureuser/sharpbench/runner/Worker.cs:line 23
         at Microsoft.Extensions.Hosting.Internal.Host.TryExecuteBackgroundServiceAsync(BackgroundService backgroundService)
crit: Microsoft.Extensions.Hosting.Internal.Host[10]
      The HostOptions.BackgroundServiceExceptionBehavior is configured to StopHost. A BackgroundService has thrown an unhandled exception, and the IHost instance is stopping. To avoid this behavior, configure this to Ignore; however the BackgroundService will not be restarted.
      StackExchange.Redis.RedisConnectionException: The message timed out in the backlog attempting to send because no connection became available (5000ms) - Last Connection Exception: SocketFailure (ReadSocketError/ConnectionReset, 0-read, last-recv: 0) on viaduct.proxy.rlwy.net:13148/Interactive, Flushed/Faulted, last: ECHO, origin: ReadFromPipe, outstanding: 13, last-read: 0s ago, last-write: 0s ago, unanswered-write: 0s ago, keep-alive: 60s, state: ConnectedEstablishing, mgr: 9 of 10 available, last-heartbeat: never, last-mbeat: 0s ago, global: 0s ago, v: 2.7.23.42580, command=RPOP, timeout: 5000, inst: 0, qu: 0, qs: 0, aw: False, bw: CheckingForTimeout, last-in: 0, cur-in: 0, sync-ops: 3, async-ops: 21903, serverEndpoint: viaduct.proxy.rlwy.net:13148, conn-sec: n/a, aoc: 1, mc: 1/1/0, mgr: 10 of 10 available, clientName: sharpbenchvm(SE.Redis-v2.7.23.42580), IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=3,Free=32764,Min=2,Max=32767), POOL: (Threads=4,QueuedItems=0,CompletedItems=176406,Timers=1), v: 2.7.23.42580 (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.RedisConnectionException: SocketFailure (ReadSocketError/ConnectionReset, 0-read, last-recv: 0) on viaduct.proxy.rlwy.net:13148/Interactive, Flushed/Faulted, last: ECHO, origin: ReadFromPipe, outstanding: 13, last-read: 0s ago, last-write: 0s ago, unanswered-write: 0s ago, keep-alive: 60s, state: ConnectedEstablishing, mgr: 9 of 10 available, last-heartbeat: never, last-mbeat: 0s ago, global: 0s ago, v: 2.7.23.42580
       ---> Pipelines.Sockets.Unofficial.ConnectionResetException: Connection reset by peer
       ---> System.Net.Sockets.SocketException (104): Connection reset by peer
         at Pipelines.Sockets.Unofficial.Internal.Throw.Socket(Int32 errorCode) in /_/src/Pipelines.Sockets.Unofficial/Internal/Throw.cs:line 59
         at Pipelines.Sockets.Unofficial.SocketConnection.DoReceiveAsync() in /_/src/Pipelines.Sockets.Unofficial/SocketConnection.Receive.cs:line 64
         --- End of inner exception stack trace ---
         at System.IO.Pipelines.PipeCompletion.ThrowLatchedException()
         at System.IO.Pipelines.Pipe.GetReadAsyncResult()
         at StackExchange.Redis.PhysicalConnection.ReadFromPipe()
         --- End of inner exception stack trace ---
         --- End of inner exception stack trace ---
         at Sharpbench.Core.JobQueue.GetNextJob() in /home/azureuser/sharpbench/core/JobQueue.cs:line 77
         at Sharpbench.Core.JobQueue.ListenForJobs(CancellationToken clt)+MoveNext() in /home/azureuser/sharpbench/core/JobQueue.cs:line 57
         at Sharpbench.Core.JobQueue.ListenForJobs(CancellationToken clt)+System.Threading.Tasks.Sources.IValueTaskSource<System.Boolean>.GetResult()
         at Sharpbench.Runner.Worker.ExecuteAsync(CancellationToken stoppingToken) in /home/azureuser/sharpbench/runner/Worker.cs:line 23
         at Sharpbench.Runner.Worker.ExecuteAsync(CancellationToken stoppingToken) in /home/azureuser/sharpbench/runner/Worker.cs:line 23
         at Microsoft.Extensions.Hosting.Internal.Host.TryExecuteBackgroundServiceAsync(BackgroundService backgroundService)
info: Microsoft.Hosting.Lifetime[0]
      Application is shutting down...
habbes commented 3 months ago

Another one, this time when publishing a message, not when listening:

Unhandled exception. Unhandled exception. Unhandled exception. Unhandled exception. StackExchange.Redis.RedisTimeoutException: Timeout awaiting response (outbound=7KiB, inbound=0KiB, 5016ms elapsed, timeout is 5000ms), command=PUBLISH, next: PUBLISH message:8bcf6650-ddf9-47d0-8fd4-f2393d283172:Log, inst: 0, qu: 0, qs: 39, aw: False, bw: Inactive, rs: ReadAsync, ws: Idle, in: 0, in-pipe: 0, out-pipe: 0, last-in: 1, cur-in: 0, sync-ops: 8, async-ops: 139685, serverEndpoint: viaduct.proxy.rlwy.net:13148, conn-sec: 391921.11, aoc: 1, mc: 1/1/0, mgr: 10 of 10 available, clientName: sharpbenchvm(SE.Redis-v2.7.23.42580), IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=5,Free=32762,Min=2,Max=32767), POOL: (Threads=5,QueuedItems=3,CompletedItems=1012149,Timers=3), v: 2.7.23.42580 (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 Sharpbench.Core.JobMessageStream.PublishMessage(JobMessage message) in /home/azureuser/sharpbench/core/JobMessageStream.cs:line 43
   at Sharpbench.Runner.JobRunner.BroadcastMessage[T](String jobId, JobMessageType type, T message) in /home/azureuser/sharpbench/runner/JobRunner.cs:line 338
   at Sharpbench.Runner.JobRunner.<>c__DisplayClass15_0.<<RunDockerStep>b__0>d.MoveNext() in /home/azureuser/sharpbench/runner/JobRunner.cs:line 291
--- End of stack trace from previous location ---
   at System.Threading.Tasks.Task.<>c.<ThrowAsync>b__128_1(Object state)
   at System.Threading.ThreadPoolWorkQueue.Dispatch()
   at System.Threading.PortableThreadPool.WorkerThread.WorkerThreadStart()
StackExchange.Redis.RedisTimeoutException: Timeout awaiting response (outbound=7KiB, inbound=0KiB, 5060ms elapsed, timeout is 5000ms), command=PUBLISH, next: PUBLISH message:8bcf6650-ddf9-47d0-8fd4-f2393d283172:Log, inst: 0, qu: 0, qs: 39, aw: False, bw: Inactive, rs: ReadAsync, ws: Idle, in: 0, in-pipe: 0, out-pipe: 0, last-in: 1, cur-in: 0, sync-ops: 8, async-ops: 139685, serverEndpoint: viaduct.proxy.rlwy.net:13148, conn-sec: 391921.11, aoc: 1, mc: 1/1/0, mgr: 10 of 10 available, clientName: sharpbenchvm(SE.Redis-v2.7.23.42580), IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=5,Free=32762,Min=2,Max=32767), POOL: (Threads=5,QueuedItems=2,CompletedItems=1012149,Timers=3), v: 2.7.23.42580 (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 Sharpbench.Core.JobMessageStream.PublishMessage(JobMessage message) in /home/azureuser/sharpbench/core/JobMessageStream.cs:line 43
   at Sharpbench.Runner.JobRunner.BroadcastMessage[T](String jobId, JobMessageType type, T message) in /home/azureuser/sharpbench/runner/JobRunner.cs:line 338
   at Sharpbench.Runner.JobRunner.<>c__DisplayClass15_0.<<RunDockerStep>b__0>d.MoveNext() in /home/azureuser/sharpbench/runner/JobRunner.cs:line 291
--- End of stack trace from previous location ---
   at System.Threading.Tasks.Task.<>c.<ThrowAsync>b__128_1(Object state)
   at System.Threading.ThreadPoolWorkQueue.Dispatch()
   at System.Threading.PortableThreadPool.WorkerThread.WorkerThreadStart()
StackExchange.Redis.RedisTimeoutException: Timeout awaiting response (outbound=8KiB, inbound=0KiB, 5204ms elapsed, timeout is 5000ms), command=PUBLISH, next: PUBLISH message:8bcf6650-ddf9-47d0-8fd4-f2393d283172:Log, inst: 0, qu: 0, qs: 39, aw: False, bw: Inactive, rs: ReadAsync, ws: Idle, in: 0, in-pipe: 0, out-pipe: 0, last-in: 1, cur-in: 0, sync-ops: 8, async-ops: 139685, serverEndpoint: viaduct.proxy.rlwy.net:13148, conn-sec: 391921.11, aoc: 1, mc: 1/1/0, mgr: 10 of 10 available, clientName: sharpbenchvm(SE.Redis-v2.7.23.42580), IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=2,Free=32765,Min=2,Max=32767), POOL: (Threads=4,QueuedItems=0,CompletedItems=1012149,Timers=3), v: 2.7.23.42580 (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 Sharpbench.Core.JobMessageStream.PublishMessage(JobMessage message) in /home/azureuser/sharpbench/core/JobMessageStream.cs:line 43
   at Sharpbench.Runner.JobRunner.BroadcastMessage[T](String jobId, JobMessageType type, T message) in /home/azureuser/sharpbench/runner/JobRunner.cs:line 338
   at Sharpbench.Runner.JobRunner.<>c__DisplayClass15_0.<<RunDockerStep>b__0>d.MoveNext() in /home/azureuser/sharpbench/runner/JobRunner.cs:line 291
--- End of stack trace from previous location ---
   at System.Threading.Tasks.Task.<>c.<ThrowAsync>b__128_1(Object state)
   at System.Threading.ThreadPoolWorkQueue.Dispatch()
   at System.Threading.PortableThreadPool.WorkerThread.WorkerThreadStart()