Redis | Caching failed for GetItem

[bettes914]

Hi,

I am getting this error on a regular base

{ "Type": "System.Data.Entity.Core.EntityCommandExecutionException", "Message": "An error occurred while executing the command definition. See the inner exception for details.", "Data": { "MS_LoggedBy": [ "AmbuWeb.API.Util.AmbuWebExceptionLoggerService", "AmbuWeb.Common.Exceptions.NLogExceptionLogger" ] }, "InnerException": { "Type": "EFCache.Redis.RedisCacheException", "Message": "Redis | Caching failed for GetItem", "Data": {}, "InnerException": { "Type": "StackExchange.Redis.RedisServerException", "Message": "ERR invalid expire time in 'psetex' command", "Data": {}, "TargetSite": "T ExecuteSyncImpl[T](StackExchange.Redis.Message, StackExchange.Redis.ResultProcessor1[T], StackExchange.Redis.ServerEndPoint, T)",
"StackTrace": " at StackExchange.Redis.ConnectionMultiplexer.ExecuteSyncImpl[T](Message message, ResultProcessor1 processor, ServerEndPoint server, T defaultValue) in /_/src/StackExchange.Redis/ConnectionMultiplexer.cs:line 2103\r\n at StackExchange.Redis.RedisDatabase.StringSet(RedisKey key, RedisValue value, Nullable1 expiry, When when, CommandFlags flags) in /_/src/StackExchange.Redis/RedisDatabase.cs:line 3284\r\n at EFCache.Redis.StackExchangeRedisExtensions.Set[T](IDatabase cache, String key, T value, TimeSpan expiry) in C:\Source\Repos\EFCache.Redis\EFCache.Redis\StackExchangeRedisExtensions.cs:line 20\r\n at EFCache.Redis.RedisCache.GetItem(String key, Object& value) in C:\Source\Repos\EFCache.Redis\EFCache.Redis\RedisCache.cs:line 117",
"Source": "StackExchange.Redis",
"HResult": -2146233088
},
"TargetSite": "Void OnCachingFailed(System.Exception, System.String)",
"StackTrace": " at EFCache.Redis.RedisCache.OnCachingFailed(Exception e, String memberName) in C:\Source\Repos\EFCache.Redis\EFCache.Redis\RedisCache.cs:line 63\r\n at EFCache.Redis.RedisCache.GetItem(String key, Object& value) in C:\Source\Repos\EFCache.Redis\EFCache.Redis\RedisCache.cs:line 119\r\n at EFCache.CachingCommand.ExecuteDbDataReader(CommandBehavior behavior)\r\n at System.Data.Entity.Infrastructure.Interception.InternalDispatcher1.Dispatch[TTarget,TInterceptionContext,TResult](TTarget target, Func3 operation, TInterceptionContext interceptionContext, Action3 executing, Action3 executed)\r\n at System.Data.Entity.Infrastructure.Interception.DbCommandDispatcher.Reader(DbCommand command, DbCommandInterceptionContext interceptionContext)\r\n at System.Data.Entity.Core.EntityClient.Internal.EntityCommandDefinition.ExecuteStoreCommands(EntityCommand entityCommand, CommandBehavior behavior)",
"Source": "EFCache.Redis",
"HResult": -2146233088
},
"TargetSite": "System.Data.Common.DbDataReader ExecuteStoreCommands(System.Data.Entity.Core.EntityClient.EntityCommand, System.Data.CommandBehavior)",
"StackTrace": " at System.Data.Entity.Core.EntityClient.Internal.EntityCommandDefinition.ExecuteStoreCommands(EntityCommand entityCommand, CommandBehavior behavior)\r\n at System.Data.Entity.Core.Objects.Internal.ObjectQueryExecutionPlan.Execute[TResultType](ObjectContext context, ObjectParameterCollection parameterValues)\r\n at System.Data.Entity.Core.Objects.ObjectContext.ExecuteInTransaction[T](Func1 func, IDbExecutionStrategy executionStrategy, Boolean startLocalTransaction, Boolean releaseConnectionOnSuccess)\r\n at System.Data.Entity.Core.Objects.ObjectQuery1.<>c__DisplayClass41_0.b__0()\r\n at System.Data.Entity.Core.Objects.ObjectQuery1.GetResults(Nullable1 forMergeOption)\r\n at System.Data.Entity.Core.Objects.ObjectQuery1.<System.Collections.Generic.IEnumerable<T>.GetEnumerator>b__31_0()\r\n at System.Data.Entity.Internal.LazyEnumerator1.MoveNext()\r\n at System.Collections.Generic.List1..ctor(IEnumerable1 collection)\r\n at System.Linq.Enumerable.ToList[TSource](IEnumerable`1 source)\r\n at AmbuWeb.Business.User.AuthorizationService.IsAuthorizedForTaskSecurable(String securableCode, Int32 userId, Int32 customerId) in D:\a\1\s\AmbuWeb.Business\User\AuthorizationService.cs:line 93\r\n at AmbuWeb.API.Util.TaskAuthorizeAttribute.IsAuthorized(HttpActionContext actionContext)\r\n at System.Web.Http.AuthorizeAttribute.OnAuthorization(HttpActionContext actionContext)\r\n at AmbuWeb.API.Util.TaskAuthorizeAttribute.OnAuthorization(HttpActionContext actionContext)\r\n at System.Web.Http.Filters.AuthorizationFilterAttribute.OnAuthorizationAsync(HttpActionContext actionContext, CancellationToken cancellationToken)\r\n--- End of stack trace from previous location where exception was thrown ---\r\n at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()\r\n at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)\r\n at System.Web.Http.Filters.AuthorizationFilterAttribute.d__3.MoveNext()\r\n--- End of stack trace from previous location where exception was thrown ---\r\n at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()\r\n at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)\r\n at System.Web.Http.Filters.AuthorizationFilterAttribute.d__3.MoveNext()\r\n--- End of stack trace from previous location where exception was thrown ---\r\n at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()\r\n at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)\r\n at System.Web.Http.Dispatcher.HttpControllerDispatcher.d__15.MoveNext()",
"Source": "EntityFramework",
"HResult": -2146232004
}

Here (StackExchange/StackExchange.Redis#2045) is said that the problem "ERR invalid expire time in 'psetex' command" is caused by a zero or negative expiry value

I tracked this down in code and see the following problem

in line 78 : a local variable now is created
in line 101 : there is a check against now to see if the entry is expired
in line 117 : when the entry is not expired, a timespan is calculated against the actual datetime instead of the variable now which can result in a negative time span.

`