Timeouts occurring with little load

530 views Asked by At

We have recently started using aspnet-redis-providers for an ASP.NET web application using framework V4.7.2. We are getting timeouts that we cannot explain. We have been working with enterprise redis and there does not yet appear to be anything to explain these on the redis server. The errors come in small groups 2-10 at a time. There is no significant load on the application machines and no significant load on the redis machines. Here is a stack from the application error

==-- Error --==
Assembly    : AppName, Version=2014.2.1.1, Culture=neutral, PublicKeyToken=null
Type        : AppName.Global
ThreadID    : 22
MessageID   : 
Source      : StackExchange.Redis
Method      : T ExecuteSyncImpl[T](StackExchange.Redis.Message, StackExchange.Redis.ResultProcessor`1[T], StackExchange.Redis.ServerEndPoint)
Date        : 2022-05-31
Time        : 21:11:21.6051
DateTime    : 2022-05-31 21:11:21.6051
Computer    : MachineName
Error       : Timeout performing EVAL (5000ms), next: EVAL, inst: 0, qu: 0, qs: 0, aw: False, bw: SpinningDown, rs: ReadAsync, ws: Idle, in: 131072, serverEndpoint: redis-path:port, mc: 1/1/0, mgr: 9 of 10 available, clientName: MachineName(SE.Redis-v2.5.61.22961), IOCP: (Busy=2,Free=998,Min=400,Max=1000), WORKER: (Busy=2,Free=32765,Min=400,Max=32767), v: 2.5.61.22961 (Please take a look at this article for some common client-side issues that can cause timeouts: https://stackexchange.github.io/StackExchange.Redis/Timeouts)
Stack Trace :    at StackExchange.Redis.ConnectionMultiplexer.ExecuteSyncImpl[T](Message message, ResultProcessor`1 processor, ServerEndPoint server) in /_/src/StackExchange.Redis/ConnectionMultiplexer.cs:line 1857
   at StackExchange.Redis.RedisBase.ExecuteSync[T](Message message, ResultProcessor`1 processor, ServerEndPoint server) in /_/src/StackExchange.Redis/RedisBase.cs:line 53
   at StackExchange.Redis.RedisDatabase.ScriptEvaluate(String script, RedisKey[] keys, RedisValue[] values, CommandFlags flags) in /_/src/StackExchange.Redis/RedisDatabase.cs:line 1212
   at Microsoft.Web.Redis.StackExchangeClientConnection.<>c__DisplayClass7_0.<Eval>b__0()
   at Microsoft.Web.Redis.StackExchangeClientConnection.OperationExecutor(Func`1 redisOperation)
   at Microsoft.Web.Redis.StackExchangeClientConnection.RetryLogic(Func`1 redisOperation)
   at Microsoft.Web.Redis.StackExchangeClientConnection.Eval(String script, String[] keyArgs, Object[] valueArgs)
   at Microsoft.Web.Redis.RedisConnectionWrapper.TryTakeWriteLockAndGetData(DateTime lockTime, Int32 lockTimeout, Object& lockId, ISessionStateItemCollection& data, Int32& sessionTimeout)
   at Microsoft.Web.Redis.RedisSessionStateProvider.GetItemFromSessionStore(Boolean isWriteLockRequired, HttpContextBase context, String id, CancellationToken cancellationToken, Boolean& locked, TimeSpan& lockAge, Object& lockId, SessionStateActions& actions)
   at Microsoft.Web.Redis.RedisSessionStateProvider.<GetItemExclusiveAsync>d__20.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at Microsoft.AspNet.SessionState.SessionStateModuleAsync.<GetSessionStateItemAsync>d__74.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.AspNet.SessionState.SessionStateModuleAsync.<AcquireStateAsync>d__65.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.AspNet.SessionState.TaskAsyncHelper.EndTask(IAsyncResult ar)
   at System.Web.HttpApplication.AsyncEventExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()
   at System.Web.HttpApplication.ExecuteStepImpl(IExecutionStep step)
   at System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean& completedSynchronously)
Build: 5/27/2022 3:10:56 PM
Url: TheUrlCausingTheRequestThatFailed
Message: Timeout performing EVAL (5000ms), next: EVAL, inst: 0, qu: 0, qs: 0, aw: False, bw: SpinningDown, rs: ReadAsync, ws: Idle, in: 131072, serverEndpoint: redis-path:port, mc: 1/1/0, mgr: 9 of 10 available, clientName: MachineName(SE.Redis-v2.5.61.22961), IOCP: (Busy=2,Free=998,Min=400,Max=1000), WORKER: (Busy=2,Free=32765,Min=400,Max=32767), v: 2.5.61.22961 (Please take a look at this article for some common client-side issues that can cause timeouts: https://stackexchange.github.io/StackExchange.Redis/Timeouts)
==-------------------------------------------------------------------==

We cannot recreate this in any of our lower environments but our automation testing does seem to generate the error consistently. We have tried the suggestions in the link provided in the error. Anyone have a similar experience or have configuration suggestions? Anyone willing to share their config setup for a .net application using Redis as a custom session state provider?

1

There are 1 answers

0
chriswatts On BEST ANSWER

We eventually determined that we had a programming error and we had a session that was bloating to be over 21MB. We were getting this error as the process was timing out trying to stream that large session back to the session provider. We have corrected the issue causing the large session and the timeout is gone.