November Happy Hour will be moved to Thursday December 5th.

AI OnAI Off

Failed to read cache key

Mari Jørgensen
Mari Jørgensen
Vote:
 

I am investigating an issue where data is not updated as part of an import job. I have confirmed that logic is correct, the problem seem to be that product is not being saved. 

In the log files I can see error messages like "Failed to Read cacheKey" and "System.Data.SqlClient.SqlException: Execution Timeout Expired." - see sample of full log message below.

We are running the site in Azure and using version 11.10.6 of Episerver.CMS.Core.

I know there were issues related to Episerver caching and version .NET 4.7 (ref https://vimvq1987.com/episerver-caching-issue-net-4-7/), but those should not apply since we are running v 11.10.6.

The import processes quite a huge amount of updates and works in batches of 24 which is processed in parallell. 

2019-03-20 02:20:56,349 [15] ERROR EPiServer.Framework.Cache.ObjectInstanceCacheExtensions: Failed to Read cacheKey = 'EP:ECF:Version:85016'
System.Data.SqlClient.SqlException (0x80131904): Execution Timeout Expired. The timeout period elapsed prior to completion of the operation or the server is not responding. ---> System.ComponentModel.Win32Exception (0x80004005): The wait operation timed out
at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)
at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)
at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)
at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString, Boolean isInternal, Boolean forDescribeParameterEncryption, Boolean shouldCacheForAlwaysEncrypted)
at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async, Int32 timeout, Task& task, Boolean asyncWrite, Boolean inRetry, SqlDataReader ds, Boolean describeParameterEncryptionRequest)
at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, TaskCompletionSource`1 completion, Int32 timeout, Task& task, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry)
at System.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(TaskCompletionSource`1 completion, String methodName, Boolean sendToPipe, Int32 timeout, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry)
at System.Data.SqlClient.SqlCommand.ExecuteNonQuery()
at EPiServer.Data.Providers.SqlTransientErrorsRetryPolicy.Execute[TResult](Func`1 method)
at Mediachase.Data.Provider.SqlDataProvider.ExecuteNonExec(DataCommand command)
at Mediachase.MetaDataPlus.Common.DBHelper.ExecuteNonQuery(String connectionString, CommandType commandType, String commandText, Int32 commandTimeout, DataParameter[] commandParameters)
at EPiServer.Commerce.Catalog.DataAccess.CatalogContentVersionDB.UpdateContentVersion(List`1 mappingData, DataTable workIdMapping, Boolean publishAction)
at EPiServer.Commerce.Catalog.Provider.CatalogContentVersionStore.CreateContentVersion(CatalogContentBase content, String currentUser, Boolean publishAction, Boolean skipSetCommonDraft)
at EPiServer.Commerce.Catalog.Provider.CatalogContentVersionStore.EnsureDraftsInAllLanguages(VersionCollection versionCollection, ContentReference contentLink)
at EPiServer.Commerce.Catalog.Provider.CatalogContentVersionStore.GetListFromDb(ContentReference contentLink)
at EPiServer.Commerce.Catalog.Provider.CatalogContentVersionStore.<>c__DisplayClass36_0.<GetContentVersions>b__0()
at EPiServer.Framework.Cache.ObjectInstanceCacheExtensions.ReadThroughWithWait[T](IObjectInstanceCache cache, String cacheKey, Func`1 readValue, Func`2 evictionPolicy)
at EPiServer.Commerce.Catalog.Provider.CatalogContentVersionStore.GetContentVersions(ContentReference contentLink)
at EPiServer.Commerce.Catalog.Provider.CatalogContentVersionStore.<>c__DisplayClass23_0.<List>b__0()
at EPiServer.Framework.Cache.ObjectInstanceCacheExtensions.ReadThroughWithWait[T](IObjectInstanceCache cache, String cacheKey, Func`1 readValue, Func`2 evictionPolicy)
ClientConnectionId:46c399d9-4ba2-405d-90f8-6b6cd197f407
Error Number:-2,State:0,Class:11
ClientConnectionId before routing:bd5514a4-0bf2-48e8-87fb-eaa7858584d3
Routing Destination:a5c98a899196.tr31.westeurope1-a.worker.database.windows.net,11119
System.Data.SqlClient.SqlException (0x80131904): Execution Timeout Expired. The timeout period elapsed prior to completion of the operation or the server is not responding. ---> System.ComponentModel.Win32Exception (0x80004005): The wait operation timed out
at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)
at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)
at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)
at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString, Boolean isInternal, Boolean forDescribeParameterEncryption, Boolean shouldCacheForAlwaysEncrypted)
at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async, Int32 timeout, Task& task, Boolean asyncWrite, Boolean inRetry, SqlDataReader ds, Boolean describeParameterEncryptionRequest)
at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, TaskCompletionSource`1 completion, Int32 timeout, Task& task, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry)
at System.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(TaskCompletionSource`1 completion, String methodName, Boolean sendToPipe, Int32 timeout, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry)
at System.Data.SqlClient.SqlCommand.ExecuteNonQuery()
at EPiServer.Data.Providers.SqlTransientErrorsRetryPolicy.Execute[TResult](Func`1 method)
at Mediachase.Data.Provider.SqlDataProvider.ExecuteNonExec(DataCommand command)
at Mediachase.MetaDataPlus.Common.DBHelper.ExecuteNonQuery(String connectionString, CommandType commandType, String commandText, Int32 commandTimeout, DataParameter[] commandParameters)
at EPiServer.Commerce.Catalog.DataAccess.CatalogContentVersionDB.UpdateContentVersion(List`1 mappingData, DataTable workIdMapping, Boolean publishAction)
at EPiServer.Commerce.Catalog.Provider.CatalogContentVersionStore.CreateContentVersion(CatalogContentBase content, String currentUser, Boolean publishAction, Boolean skipSetCommonDraft)
at EPiServer.Commerce.Catalog.Provider.CatalogContentVersionStore.EnsureDraftsInAllLanguages(VersionCollection versionCollection, ContentReference contentLink)
at EPiServer.Commerce.Catalog.Provider.CatalogContentVersionStore.GetListFromDb(ContentReference contentLink)
at EPiServer.Commerce.Catalog.Provider.CatalogContentVersionStore.<>c__DisplayClass36_0.<GetContentVersions>b__0()
at EPiServer.Framework.Cache.ObjectInstanceCacheExtensions.ReadThroughWithWait[T](IObjectInstanceCache cache, String cacheKey, Func`1 readValue, Func`2 evictionPolicy)
at EPiServer.Commerce.Catalog.Provider.CatalogContentVersionStore.GetContentVersions(ContentReference contentLink)
at EPiServer.Commerce.Catalog.Provider.CatalogContentVersionStore.<>c__DisplayClass23_0.<List>b__0()
at EPiServer.Framework.Cache.ObjectInstanceCacheExtensions.ReadThroughWithWait[T](IObjectInstanceCache cache, String cacheKey, Func`1 readValue, Func`2 evictionPolicy)
ClientConnectionId:46c399d9-4ba2-405d-90f8-6b6cd197f407

2019-03-20 02:20:57,099 [15] ERROR lambda_method: One or more errors occurred.
System.AggregateException: One or more errors occurred. ---> System.Data.SqlClient.SqlException: Execution Timeout Expired.  The timeout period elapsed prior to completion of the operation or the server is not responding. ---> System.ComponentModel.Win32Exception: The wait operation timed out
   --- End of inner exception stack trace ---
   at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)
   at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)
   at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)
   at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString, Boolean isInternal, Boolean forDescribeParameterEncryption, Boolean shouldCacheForAlwaysEncrypted)
   at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async, Int32 timeout, Task& task, Boolean asyncWrite, Boolean inRetry, SqlDataReader ds, Boolean describeParameterEncryptionRequest)
   at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, TaskCompletionSource`1 completion, Int32 timeout, Task& task, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry)
   at System.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(TaskCompletionSource`1 completion, String methodName, Boolean sendToPipe, Int32 timeout, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry)
   at System.Data.SqlClient.SqlCommand.ExecuteNonQuery()
   at EPiServer.Data.Providers.SqlTransientErrorsRetryPolicy.Execute[TResult](Func`1 method)
   at Mediachase.Data.Provider.SqlDataProvider.ExecuteNonExec(DataCommand command)
   at Mediachase.MetaDataPlus.Common.DBHelper.ExecuteNonQuery(String connectionString, CommandType commandType, String commandText, Int32 commandTimeout, DataParameter[] commandParameters)
   at EPiServer.Commerce.Catalog.DataAccess.CatalogContentVersionDB.UpdateContentVersion(List`1 mappingData, DataTable workIdMapping, Boolean publishAction)
   at EPiServer.Commerce.Catalog.Provider.CatalogContentVersionStore.CreateContentVersion(CatalogContentBase content, String currentUser, Boolean publishAction, Boolean skipSetCommonDraft)
   at EPiServer.Commerce.Catalog.Provider.CatalogContentVersionStore.EnsureDraftsInAllLanguages(VersionCollection versionCollection, ContentReference contentLink)
   at EPiServer.Commerce.Catalog.Provider.CatalogContentVersionStore.GetListFromDb(ContentReference contentLink)
   at EPiServer.Commerce.Catalog.Provider.CatalogContentVersionStore.<>c__DisplayClass36_0.<GetContentVersions>b__0()
   at EPiServer.Framework.Cache.ObjectInstanceCacheExtensions.ReadThroughWithWait[T](IObjectInstanceCache cache, String cacheKey, Func`1 readValue, Func`2 evictionPolicy)
   at EPiServer.Commerce.Catalog.Provider.CatalogContentVersionStore.GetContentVersions(ContentReference contentLink)
   at EPiServer.Commerce.Catalog.Provider.CatalogContentVersionStore.<>c__DisplayClass23_0.<List>b__0()
   at EPiServer.Framework.Cache.ObjectInstanceCacheExtensions.ReadThroughWithWait[T](IObjectInstanceCache cache, String cacheKey, Func`1 readValue, Func`2 evictionPolicy)
   at EPiServer.Commerce.Catalog.Provider.CatalogContentVersionStore.List(VersionFilter filter, Int32 startIndex, Int32 maxRows, Int32& totalCount)
   at EPiServer.Core.IContentVersionRepositoryExtensions.List(IContentVersionRepository contentVersionRepository, ContentReference contentLink)
   at EPiServer.Find.Commerce.CatalogEventIndexer.GetAllLanguageVersions(IContent content)
   at EPiServer.Find.Commerce.CatalogEventIndexer.IndexContentInAllLanguages(IContent content)
   at EPiServer.Find.Commerce.CatalogContentEventListener.IndexContentsIfNeeded(IEnumerable`1 contents, Action`1 indexAction, IDictionary`2 cachedReindexContentOnEventForType, Func`1 isReindexingContentOnUpdates)
   at EPiServer.Find.Commerce.CatalogContentEventListener.IndexContentsIfNeeded(IEnumerable`1 contentLinks, Action`1 indexAction)
   at EPiServer.Find.Commerce.CatalogContentEventListener.CatalogEventUpdated(Object sender, EventNotificationEventArgs e)
   at EPiServer.Events.Clients.Event.Raise(Guid raiserId, Object param, EventRaiseOption raiseOption)
   at Mediachase.Commerce.Catalog.Events.CatalogEventBroadcaster.RaiseEvent(CatalogContentUpdateEventArgs e)
   at Mediachase.Commerce.Catalog.Events.CatalogEventBroadcaster.SendEntryUpdateEvent(EntryEventArgs args)
   at Mediachase.Commerce.Catalog.EventContext.EntryEventHandler.Invoke(Object sender, EntryEventArgs e)
   at Mediachase.Commerce.Catalog.EventContext.RaiseEntryUpdatedEvent(CatalogEntryDto sender, EntryEventArgs args)
   at Mediachase.Data.Provider.TransactionScope.ExecuteActions(IEnumerable`1 actions)
   --- End of inner exception stack trace ---
   at Mediachase.Data.Provider.TransactionScope.ExecuteActions(IEnumerable`1 actions)
   at Mediachase.Data.Provider.TransactionScope.ThreadStaticTransactionScope.Commit()
   at Mediachase.Data.Provider.TransactionScope.Complete()
   at EPiServer.Commerce.Catalog.Provider.CatalogContentCommitterHandler.SaveVersionInternal(CatalogContentBase content, SaveAction action, String currentUser)
   at EPiServer.Commerce.Catalog.Provider.CatalogContentCommitterHandler.Save(CatalogContentBase content, SaveAction action, String currentUser)
   at EPiServer.Commerce.Catalog.Provider.CatalogContentProvider.Save(IContent content, SaveAction action)
   at EPiServer.Core.Internal.DefaultContentRepository.Save(IContent content, SaveAction action, AccessLevel access)
#202229
Mar 20, 2019 9:56
Quan Mai
Quan Mai
Vote:
 

The one you should be looking at is 

Execution Timeout Expired. The timeout period elapsed prior to completion of the operation or the server is not responding. ---> System.ComponentModel.Win32Exception (0x80004005): The wait operation timed out

As you said you have 24 threads running in parallel, I'd suspect that is too much for SQL Server to handle, causing it to slow down and even timeout for some queries. Check your DTU percentage. Lowering your level of parallelism might help 

#202230
Mar 20, 2019 10:01
Sanjay Kumar
Sanjay Kumar
Vote:
 

Hi Mari Jørgensen

Did you remembered how you fixed that error?

I am getting similar error when trying to browse the scheduler URL.

2024-10-29T14:14:37 You are now connected to the log stream...
2024-10-29T14:14:43,Information,sch-abco01mstr1c52wprep,c2aae2,638658080830154290,0,2408,22,"EPiServer.ServiceApi.IntegrationInitialization : Configuring Services in EPiServer.ServiceApi.IntegrationInitialization, EPiServer.ServiceApi, Version=5.4.4.0, Culture=neutral, PublicKeyToken=8fe83dea738b45b7.",
2024-10-29T14:14:43,Information,sch-abco01mstr1c52wprep,c2aae2,638658080832185556,0,2408,22,"EPiServer.ServiceApi.Commerce.IntegrationInitialization : Configuring Services in EPiServer.ServiceApi.Commerce.IntegrationInitialization, EPiServer.ServiceApi.Commerce, Version=5.4.4.0, Culture=neutral, PublicKeyToken=8fe83dea738b45b7.",
2024-10-29T14:14:43,Error,sch-abco01mstr1c52wprep,c2aae2,638658080839998116,0,2408,22,"EPiServer.Framework.Cache.ObjectInstanceCacheExtensions : Failed to Read cacheKey = 'EP:ECF:MC:N_CatalogEntry'
System.ArgumentException: Keyword not supported: '@microsoft.keyvault(secreturi'.
   at System.Data.Common.DbConnectionOptions.ParseInternal(Hashtable parsetable, String connectionString, Boolean buildChain, Hashtable synonyms, Boolean firstKey)
   at System.Data.Common.DbConnectionOptions..ctor(String connectionString, Hashtable synonyms, Boolean useOdbcRules)
   at System.Data.SqlClient.SqlConnectionString..ctor(String connectionString)
   at System.Data.SqlClient.SqlConnectionFactory.CreateConnectionOptions(String connectionString, DbConnectionOptions previous)
   at System.Data.ProviderBase.DbConnectionFactory.GetConnectionPoolGroup(DbConnectionPoolKey key, DbConnectionPoolGroupOptions poolOptions, DbConnectionOptions& userConnectionOptions)
   at System.Data.SqlClient.SqlConnection.ConnectionString_Set(DbConnectionPoolKey key)
   at System.Data.SqlClient.SqlConnection.set_ConnectionString(String value)
   at Mediachase.Data.Provider.TransactionScope.OpenConnection(IDbCommand cmd, String connectionString, ConnectionDelegate connectionFactory)
   at Mediachase.Data.Provider.SqlDataProvider.LoadTable(DataCommand command)
   at Mediachase.MetaDataPlus.Common.DBHelper.ExecuteDataTable(String connectionString, CommandType commandType, String commandText, Int32 commandTimeout, DataParameter[] commandParameters)
   at Mediachase.MetaDataPlus.Configurator.MetaDataPlusDatabase.StoredProcedure.ExecuteDataTable(MetaDataContext context)
   at Mediachase.MetaDataPlus.Configurator.MetaClass.LoadFromDb(MetaDataContext context, Func`2 dbLoader)
   at EPiServer.Framework.Cache.ObjectInstanceCacheExtensions.ReadThroughWithWait[T](IObjectInstanceCache cache, String cacheKey, Func`1 readValue, Func`2 evictionPolicy)",
2024-10-29T14:14:44,Error,sch-abco01mstr1c52wprep,c2aae2,638658080840154429,0,2408,22,"EPiServer.Framework.Initialization.InitializationEngine : Initialize action failed for 'Initialize on class Mediachase.Commerce.Initialization.CatalogInitialization, Mediachase.Commerce, Version=13.33.0.0, Culture=neutral, PublicKeyToken=6e58b501b34abce3'
System.ArgumentException: Keyword not supported: '@microsoft.keyvault(secreturi'.
   at System.Data.Common.DbConnectionOptions.ParseInternal(Hashtable parsetable, String connectionString, Boolean buildChain, Hashtable synonyms, Boolean firstKey)
   at System.Data.Common.DbConnectionOptions..ctor(String connectionString, Hashtable synonyms, Boolean useOdbcRules)
   at System.Data.SqlClient.SqlConnectionString..ctor(String connectionString)
   at System.Data.SqlClient.SqlConnectionFactory.CreateConnectionOptions(String connectionString, DbConnectionOptions previous)
   at System.Data.ProviderBase.DbConnectionFactory.GetConnectionPoolGroup(DbConnectionPoolKey key, DbConnectionPoolGroupOptions poolOptions, DbConnectionOptions& userConnectionOptions)
   at System.Data.SqlClient.SqlConnection.ConnectionString_Set(DbConnectionPoolKey key)
   at System.Data.SqlClient.SqlConnection.set_ConnectionString(String value)
   at Mediachase.Data.Provider.TransactionScope.OpenConnection(IDbCommand cmd, String connectionString, ConnectionDelegate connectionFactory)
   at Mediachase.Data.Provider.SqlDataProvider.LoadTable(DataCommand command)
   at Mediachase.MetaDataPlus.Common.DBHelper.ExecuteDataTable(String connectionString, CommandType commandType, String commandText, Int32 commandTimeout, DataParameter[] commandParameters)
   at Mediachase.MetaDataPlus.Configurator.MetaDataPlusDatabase.StoredProcedure.ExecuteDataTable(MetaDataContext context)
   at Mediachase.MetaDataPlus.Configurator.MetaClass.LoadFromDb(MetaDataContext context, Func`2 dbLoader)
   at EPiServer.Framework.Cache.ObjectInstanceCacheExtensions.ReadThroughWithWait[T](IObjectInstanceCache cache, String cacheKey, Func`1 readValue, Func`2 evictionPolicy)
   at Mediachase.MetaDataPlus.Configurator.MetaClass.ReadThroughCache(String cacheKey, MetaDataContext context, Func`2 dbLoader, Func`2 additionalCacheKeyCreator)
   at Mediachase.Commerce.Catalog.DefaultCatalogMetaDataModule.ConfigureMetaData()
   at Mediachase.Commerce.Catalog.DefaultCatalogMetaDataModule.EnsureDefaultMetaData()
   at EPiServer.Framework.Initialization.Internal.ModuleNode.Execute(Action a, String key)
   at EPiServer.Framework.Initialization.Internal.ModuleNode.Initialize(InitializationEngine context)
   at EPiServer.Framework.Initialization.InitializationEngine.InitializeModules()",
#332138
Oct 29, 2024 14:24
Quan Mai
Quan Mai
Vote:
 

@Sanjay - it seems you are having a different issue. the underlying problem in your case is 

Keyword not supported: '@microsoft.keyvault(secreturi'.

so it is likely it is a configuration error. the connection string was put to keyvault but the app was not configured to read that and just assume it's normal connection string 

#332139
Oct 29, 2024 14:32
Sanjay Kumar - Oct 29, 2024 14:42
Thanks Quan- I already raised a ticket to support to look into this, looks this is DXP related issue right?
Quan Mai - Oct 29, 2024 15:06
yes could be
Sanjay Kumar - Oct 30, 2024 5:36
Thanks! After correcting the 'keyvault' value by support jobs start working.
* You are NOT allowed to include any hyperlinks in the post because your account hasn't associated to your company. User profile should be updated.