Skip to content
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

System.TimeoutException: Timeout performing EVAL #508

Closed
sllabres opened this issue Oct 18, 2016 · 7 comments
Closed

System.TimeoutException: Timeout performing EVAL #508

sllabres opened this issue Oct 18, 2016 · 7 comments

Comments

@sllabres
Copy link

sllabres commented Oct 18, 2016

Hi,

I'm hoping someone can help us with an issue we see sporadically. Our website generally sees traffic of about 2,000 - 4,000 requests per minute (>9,000 in peak periods).

I'm not sure on what the triggers are but we see periods where we see a large spike in the type of error seen below (all of them are timeout performing EVAL). We've had incidents whereby the entire site has been down for hours. Since upgrading and tweaking our configuration the incident generally lasts no longer than 30 minutes but often only lasts a few minutes.

Our website is an azure cloud service and we're using a Redis cache in azure. I've raised the incidents with Microsoft but we're no closer to understanding why this happens.

I don't suppose anyone has any suggestions of things to try or look for? We're thinking about setting up a private redis instance running on the same VNET to see if that helps.

Thanks,

Seb

System.TimeoutException: Timeout performing EVAL, inst: 10, mgr: Inactive, err: never, queue: 197, qu: 0, qs: 197, qc: 0, wr: 0, wq: 0, in: 0, ar: 0, IOCP: (Busy=0,Free=400,Min=200,Max=400), WORKER: (Busy=18,Free=3982,Min=2000,Max=4000), clientName: RD00155D45CA4D
at StackExchange.Redis.ConnectionMultiplexer.ExecuteSyncImpl[T](Message message, ResultProcessor`1 processor, ServerEndPoint server) in c:\TeamCity\buildAgent\work\3ae0647004edff78\StackExchange.Redis\StackExchange\Redis\ConnectionMultiplexer.cs:line 1937
at StackExchange.Redis.ConnectionMultiplexer.ExecuteSyncImpl[T](Message message, ResultProcessor`1 processor, ServerEndPoint server) in c:\TeamCity\buildAgent\work\3ae0647004edff78\StackExchange.Redis\StackExchange\Redis\ConnectionMultiplexer.cs:line 1902
at StackExchange.Redis.RedisBase.ExecuteSync[T](Message message, ResultProcessor`1 processor, ServerEndPoint server) in c:\TeamCity\buildAgent\work\3ae0647004edff78\StackExchange.Redis\StackExchange\Redis\RedisBase.cs:line 80
at StackExchange.Redis.RedisDatabase.ScriptEvaluate(String script, RedisKey[] keys, RedisValue[] values, CommandFlags flags) in c:\TeamCity\buildAgent\work\3ae0647004edff78\StackExchange.Redis\StackExchange\Redis\RedisDatabase.cs:line 886
at Microsoft.Web.Redis.StackExchangeClientConnection.<>c__DisplayClass4.<Eval>b__3() in d:\TeamCityBuildAgent\work\f55792526e6d9089\src\Shared\StackExchangeClientConnection.cs:line 117
at Microsoft.Web.Redis.StackExchangeClientConnection.RetryForScriptNotFound(Func`1 redisOperation) in d:\TeamCityBuildAgent\work\f55792526e6d9089\src\Shared\StackExchangeClientConnection.cs:line 135
at Microsoft.Web.Redis.StackExchangeClientConnection.RetryLogic(Func`1 redisOperation) in d:\TeamCityBuildAgent\work\f55792526e6d9089\src\Shared\StackExchangeClientConnection.cs:line 159
at Microsoft.Web.Redis.StackExchangeClientConnection.Eval(String script, String[] keyArgs, Object[] valueArgs) in d:\TeamCityBuildAgent\work\f55792526e6d9089\src\Shared\StackExchangeClientConnection.cs:line 117
at Microsoft.Web.Redis.RedisConnectionWrapper.UpdateExpiryTime(Int32 timeToExpireInSeconds) in d:\TeamCityBuildAgent\work\f55792526e6d9089\src\RedisSessionStateProvider\RedisConnectionWrapper.cs:line 87
at Microsoft.Web.Redis.RedisSessionStateProvider.ResetItemTimeout(HttpContext context, String id) in d:\TeamCityBuildAgent\work\f55792526e6d9089\src\RedisSessionStateProvider\RedisSessionStateProvider.cs:line 294
at System.Web.SessionState.SessionStateModule.BeginAcquireState(Object source, EventArgs e, AsyncCallback cb, Object extraData)
at System.Web.HttpApplication.AsyncEventExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()
at System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean& completedSynchronously)
@SimpleDays
Copy link

I've also met problems like you,how to slove it?

@nemaroller
Copy link

nemaroller commented Jun 21, 2017

I have been utilizing StackExchange Redis for a few years with an on-premise Redis installation. But against an Azure Redis cache, we get this during web app deploys - and in my opinion seems to be an issue with the EVAL command the Microsoft RedisSessionStateProvider package is executing to execute its dynamic script on the Redis server. (It must use EVAL because StackExchange uses pipelining). This MS package generates script each time to read, write, or delete session state ids and data. Something in the way the script is written is probably causing issues, because when the error occurs, StackExchange client reports the queue > 1 (usually 8 or more) and qu is 0, qs is 8, and the worker and IOCP threads are below minimum thresholds (Busy=0, Min=2). It usually means we have Timeout issues for a 5-10 minutes, then all of a sudden, everything starts working again.

@NickCraver
Copy link
Collaborator

If anyone is still hitting issues here please refer to the blog article @doterme helpfully linked above: https://azure.microsoft.com/zh-tw/blog/investigating-timeout-exceptions-in-stackexchange-redis-for-azure-redis-cache/ and open an issue if you're still having trouble :)

@Almeonamy
Copy link

@NickCraver, I still have trouble during web app deploys.

Timeout performing EVAL (5000ms), next: EVAL, inst: 6, qu: 0, qs: 6, aw: False, rs: ReadAsync, ws: Idle, in: 0, serverEndpoint: Unspecified/education-erp-cache.redis.cache.windows.net:6380, mgr: 10 of 10 available, clientName: RD0003FF72B73F, IOCP: (Busy=0,Free=1000,Min=2,Max=1000), WORKER: (Busy=6,Free=32761,Min=2,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)
StackExchange.Redis.RedisTimeoutException: Timeout performing EVAL (5000ms), next: EVAL, inst: 6, qu: 0, qs: 6, aw: False, rs: ReadAsync, ws: Idle, in: 0, serverEndpoint: Unspecified/education-erp-cache.redis.cache.windows.net:6380, mgr: 10 of 10 available, clientName: RD0003FF72B73F, IOCP: (Busy=0,Free=1000,Min=2,Max=1000), WORKER: (Busy=6,Free=32761,Min=2,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)
at StackExchange.Redis.ConnectionMultiplexer.ExecuteSyncImpl[T](Message message, ResultProcessor`1 processor, ServerEndPoint server)
at StackExchange.Redis.RedisBase.ExecuteSync[T](Message message, ResultProcessor`1 processor, ServerEndPoint server)
at StackExchange.Redis.RedisDatabase.ScriptEvaluate(String script, RedisKey[] keys, RedisValue[] values, CommandFlags flags)
at Microsoft.Web.Redis.StackExchangeClientConnection.<>c__DisplayClass7_0.<Eval>b__0() in C:\TeamCity\buildAgent\work\59b31e8e4035fd30\src\Shared\StackExchangeClientConnection.cs:line 68
at Microsoft.Web.Redis.StackExchangeClientConnection.OperationExecutor(Func`1 redisOperation) in C:\TeamCity\buildAgent\work\59b31e8e4035fd30\src\Shared\StackExchangeClientConnection.cs:line 95
at Microsoft.Web.Redis.StackExchangeClientConnection.RetryLogic(Func`1 redisOperation) in C:\TeamCity\buildAgent\work\59b31e8e4035fd30\src\Shared\StackExchangeClientConnection.cs:line 122
at Microsoft.Web.Redis.StackExchangeClientConnection.Eval(String script, String[] keyArgs, Object[] valueArgs) in C:\TeamCity\buildAgent\work\59b31e8e4035fd30\src\Shared\StackExchangeClientConnection.cs:line 68
at Microsoft.Web.Redis.RedisConnectionWrapper.Set(ISessionStateItemCollection data, Int32 sessionTimeout) in C:\TeamCity\buildAgent\work\59b31e8e4035fd30\src\RedisSessionStateProvider\RedisConnectionWrapper.cs:line 137
at Microsoft.Web.Redis.RedisSessionStateProvider.<SetAndReleaseItemExclusiveAsync>d__25.MoveNext() in C:\TeamCity\buildAgent\work\59b31e8e4035fd30\src\RedisSessionStateProvider\RedisSessionStateProvider.cs:line 433
--- 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.<ReleaseStateAsyncImpl>d__80.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.<>c__DisplayClass285_0.<ExecuteStepImpl>b__0()
at System.Web.HttpApplication.ExecuteStepImpl(IExecutionStep step)
at System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean& completedSynchronously)

@magneto00
Copy link

please scale to higher sku even if logs shows cpu iddle, and apply timeout limit like 30 sec.

@Tiant1987
Copy link

I've also met problems like you,how to slove it?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

8 participants