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

umbracoLock timeout exceeded frequently for members #8433

Closed
TimZander opened this issue Jul 13, 2020 · 57 comments · Fixed by #8525
Closed

umbracoLock timeout exceeded frequently for members #8433

TimZander opened this issue Jul 13, 2020 · 57 comments · Fixed by #8525
Labels

Comments

@TimZander
Copy link

umbracoLock table timing out frequently

Umbraco version

I am seeing this issue on Umbraco version: 8.5.5

Reproduction

If you're filing a bug, please describe how to reproduce it. Include as much
relevant information as possible, such as:

Bug summary

I am seeing many cases of Lock request time out period exceeded.
Up to 2000/day which is causing significant issues using our site.

Looking at database statistics I observed that we are exceeding the hard coded 1800ms timeout on many days.

Specifics

Umbraco is running on Windows Server 2019 on premises
The database is running on Azure, P2 scale.

Steps to reproduce

Any time we have relatively high activity. This often occurs when logging a member in, but it may happen in other instances as that is the most visible scenario

Expected result

umbracoLock performs quickly with no timeouts

Actual result

Exception

System.Data.SqlClient.SqlException (0x80131904): Lock request time out period exceeded.

The statement has been terminated.

   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 Umbraco.Core.Persistence.FaultHandling.RetryPolicy.ExecuteAction[TResult](Func`1 func) in D:\a\1\s\src\Umbraco.Core\Persistence\FaultHandling\RetryPolicy.cs:line 172

   at NPoco.Database.ExecuteNonQueryHelper(DbCommand cmd)

   at NPoco.Database.Execute(String sql, CommandType commandType, Object[] args)

   at Umbraco.Core.Persistence.SqlSyntax.SqlServerSyntaxProvider.WriteLock(IDatabase db, Int32[] lockIds) in D:\a\1\s\src\Umbraco.Core\Persistence\SqlSyntax\SqlServerSyntaxProvider.cs:line 264

   at Umbraco.Core.Services.Implement.MemberService.Save(IMember member, Boolean raiseEvents) in D:\a\1\s\src\Umbraco.Core\Services\Implement\MemberService.cs:line 837

   at Umbraco.Web.Security.Providers.UmbracoMembershipProvider`2.GetUser(String username, Boolean userIsOnline) in D:\a\1\s\src\Umbraco.Web\Security\Providers\UmbracoMembershipProvider.cs:line 362

   at UmbracoGC.Libs.CustomerMembership.BGVMemberMembershipProvider.ValidateUser(String username, String password) in C:\agent\vsts-agent-win-x64-2.159.2\_work\5\s\UmbracoGC\Libs\CustomMembership\BGVMemberMembershipProvider.cs:line 14

   at Umbraco.Web.Security.MembershipHelper.Login(String username, String password) in D:\a\1\s\src\Umbraco.Web\Security\MembershipHelper.cs:line 260

   at UmbracoGC.Services.Member.GrandCentralMemberService.LogIn(LoginViewModel LoginModel) in C:\agent\vsts-agent-win-x64-2.159.2\_work\5\s\UmbracoGC\Services\Member\GrandCentralMemberService.cs:line 63

ClientConnectionId:aec38c8b-5401-4758-8e72-ff2e093b8ae1

Error Number:1222,State:51,Class:16
System.Data.SqlClient.SqlException (0x80131904): Lock request time out period exceeded.

The statement has been terminated.

   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 Umbraco.Core.Persistence.FaultHandling.RetryPolicy.ExecuteAction[TResult](Func`1 func) in D:\a\1\s\src\Umbraco.Core\Persistence\FaultHandling\RetryPolicy.cs:line 172

   at NPoco.Database.ExecuteNonQueryHelper(DbCommand cmd)

   at NPoco.Database.Execute(String sql, CommandType commandType, Object[] args)

ClientConnectionId:b70e4664-8d20-4ad8-b31e-221227eede13

Error Number:1222,State:51,Class:16
@Shazwazza
Copy link
Contributor

Thanks for the report. 8.6.4 will have some fixes directly relating to this https://github.com/umbraco/Umbraco-CMS/issues?q=label%3Arelease%2F8.6.4+is%3Aclosed

But it's great you've provided a stack trace as we'll need to investigate further with the member logins

@nul800sebastiaan nul800sebastiaan added state/needs-investigation This requires input from HQ or community to proceed type/bug labels Jul 14, 2020
@TimZander
Copy link
Author

TimZander commented Jul 14, 2020

Thank you. Looking at this PR #8398 I'm not sure it addresses this problem specifically.

Please let me know what other information I can provide to assist identifying a solution.

One thing we are doing to reduce the number of ReadLocks on Members is to now internally cache members so we will reduce our calls to read members from the database significantly. Prior we were accessing Members directly from the Member Service on the scale of 10s of times per session.

Services.MemberService.GetByUsername(User.Identity.Name).GetValue<int>(CredentialIDAlias);

@nul800sebastiaan
Copy link
Member

Hi @TimZander - we would love it if you could give the upcoming 8.6.4 release a spin, we think it will fix your issue and a few other ones as well.

The 8.6.4 build we intend to release is now available from the Artifacts on this build (where it says 3 published): https://dev.azure.com/umbraco/Umbraco%20Cms/_build/results?buildId=43999&view=results

We need to await test results from real-life usage to actually test this on your environments to make sure we have now eliminated the problems even in setups that might have different configurations on what we've tested it on. This needs to happen before we can release this build, so the sooner that happens, the sooner we can release! 😄

Please give it a spin and let us know how it goes!

@nul800sebastiaan
Copy link
Member

In your case, I'd recommend first upgrading to 8.6.3 and from 8.6.3 to 8.6.4, the only differences are the dlls so you can drop in the new dlls on your target test environment.

@TimZander
Copy link
Author

Thank you, I will try this today

@TimZander
Copy link
Author

I have tried replacing the dlls after upgrading to 8.6.3, but it is now asking me to run an upgrade from 8.6.4 from 8.6.3.

Does this make any changes to the database, or can I just change the web.config value to 8.6.4 to skip this?

@Shazwazza
Copy link
Contributor

You can just run the installer it doesn't modify your database for patch releases.

@TimZander
Copy link
Author

Thanks, this has been fine in our testing environment, but we have been unable to replicate the lock timeout in anything but production, so I will be applying these changes to production in a few hours and will see if it makes a difference

@TimZander
Copy link
Author

Initially the number of theses errors seem to be reduced today, but not gone entirely. I would say they are roughly 1/3 of what they were previously. So far this quantity is not causing issues with stability or operation of the site, but I will continue monitoring

@cleversolutions
Copy link
Contributor

We have a site with over 26000 content items (at least that many rows in umbracoContent), and are having problems with lock request time outs as well and the content tree won't render in the backoffice. The SQL ActivityMonitor shows a lot of lock waits.

image

System.Data.SqlClient.SqlException (0x80131904): Lock request time out period exceeded.
The statement has been terminated.
   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 Umbraco.Core.Persistence.FaultHandling.RetryPolicy.ExecuteAction[TResult](Func`1 func) in d:\a\1\s\src\Umbraco.Core\Persistence\FaultHandling\RetryPolicy.cs:line 172
   at NPoco.Database.ExecuteNonQueryHelper(DbCommand cmd)
   at NPoco.Database.Execute(String sql, CommandType commandType, Object[] args)
   at Umbraco.Core.Persistence.SqlSyntax.SqlServerSyntaxProvider.WriteLock(IDatabase db, TimeSpan timeout, Int32[] lockIds) in d:\a\1\s\src\Umbraco.Core\Persistence\SqlSyntax\SqlServerSyntaxProvider.cs:line 269
   at Umbraco.Core.Services.Implement.ContentService.<PerformScheduledPublishInternal>d__59.MoveNext() in d:\a\1\s\src\Umbraco.Core\Services\Implement\ContentService.cs:line 1376
   at System.Collections.Generic.List`1..ctor(IEnumerable`1 collection)
   at System.Linq.Enumerable.ToList[TSource](IEnumerable`1 source)
   at Umbraco.Core.Services.Implement.ContentService.PerformScheduledPublish(DateTime date) in d:\a\1\s\src\Umbraco.Core\Services\Implement\ContentService.cs:line 1363
   at Umbraco.Web.Scheduling.ScheduledPublishing.PerformRun() in d:\a\1\s\src\Umbraco.Web\Scheduling\ScheduledPublishing.cs:line 72
ClientConnectionId:575dc644-6feb-41c0-a8f1-e668803a4970
Error Number:1222,State:51,Class:16

That Exception happened shortly after an editor tried to move some content nodes which errored out

System.Data.SqlClient.SqlException (0x80131904): Cannot continue the execution because the session is in the kill state.
   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.SqlDataReader.TryCloseInternal(Boolean closeReader)
   at System.Data.SqlClient.SqlDataReader.Close()
   at System.Data.Common.DbDataReader.Dispose(Boolean disposing)
   at NPoco.Database.<Read>d__156`1.System.IDisposable.Dispose()
   at NPoco.Database.<Read>d__156`1.MoveNext()
   at NPoco.Database.<QueryImp>d__164`1.MoveNext()
   at System.Collections.Generic.List`1..ctor(IEnumerable`1 collection)
   at System.Linq.Enumerable.ToList[TSource](IEnumerable`1 source)
   at NPoco.Database.<Page>b__170_0[T](Page`1 paged, Sql thesql)
   at NPoco.Database.PageImp[T,TRet](Int64 page, Int64 itemsPerPage, String sql, Object[] args, Func`3 executeQueryFunc)
   at NPoco.Database.Page[T](Int64 page, Int64 itemsPerPage, String sql, Object[] args)
   at NPoco.Database.Page[T](Int64 page, Int64 itemsPerPage, Sql sql)
   at Umbraco.Core.Persistence.Repositories.Implement.ContentRepositoryBase`3.GetPage[TDto](IQuery`1 query, Int64 pageIndex, Int32 pageSize, Int64& totalRecords, Func`2 mapDtos, Sql`1 filter, Ordering ordering) in d:\a\1\s\src\Umbraco.Core\Persistence\Repositories\Implement\ContentRepositoryBase.cs:line 494
   at Umbraco.Core.Persistence.Repositories.Implement.DocumentRepository.GetPage(IQuery`1 query, Int64 pageIndex, Int32 pageSize, Int64& totalRecords, IQuery`1 filter, Ordering ordering) in d:\a\1\s\src\Umbraco.Core\Persistence\Repositories\Implement\DocumentRepository.cs:line 870
   at Umbraco.Core.Services.Implement.ContentService.PerformMoveLocked(IContent content, Int32 parentId, IContent parent, Int32 userId, ICollection`1 moves, Nullable`1 trash) in d:\a\1\s\src\Umbraco.Core\Services\Implement\ContentService.cs:line 2013
   at Umbraco.Core.Services.Implement.ContentService.Move(IContent content, Int32 parentId, Int32 userId) in d:\a\1\s\src\Umbraco.Core\Services\Implement\ContentService.cs:line 1963
   at Umbraco.Web.Editors.ContentController.PostMove(MoveOrCopy move) in d:\a\1\s\src\Umbraco.Web\Editors\ContentController.cs:line 1548
   at lambda_method(Closure , Object , Object[] )
   at System.Web.Http.Controllers.ReflectedHttpActionDescriptor.ActionExecutor.<>c__DisplayClass6_2.<GetExecutor>b__2(Object instance, Object[] methodParameters)
   at System.Web.Http.Controllers.ReflectedHttpActionDescriptor.ExecuteAsync(HttpControllerContext controllerContext, IDictionary`2 arguments, CancellationToken cancellationToken)
--- 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 System.Web.Http.Controllers.ApiControllerActionInvoker.<InvokeActionAsyncCore>d__1.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 System.Web.Http.Filters.ActionFilterAttribute.<CallOnActionExecutedAsync>d__6.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Web.Http.Filters.ActionFilterAttribute.<CallOnActionExecutedAsync>d__6.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 System.Web.Http.Filters.ActionFilterAttribute.<ExecuteActionFilterAsyncCore>d__5.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 System.Web.Http.Filters.ActionFilterAttribute.<CallOnActionExecutedAsync>d__6.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Web.Http.Filters.ActionFilterAttribute.<CallOnActionExecutedAsync>d__6.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 System.Web.Http.Filters.ActionFilterAttribute.<ExecuteActionFilterAsyncCore>d__5.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 System.Web.Http.Filters.ActionFilterAttribute.<CallOnActionExecutedAsync>d__6.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Web.Http.Filters.ActionFilterAttribute.<CallOnActionExecutedAsync>d__6.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 System.Web.Http.Filters.ActionFilterAttribute.<ExecuteActionFilterAsyncCore>d__5.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 System.Web.Http.Filters.ActionFilterAttribute.<CallOnActionExecutedAsync>d__6.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Web.Http.Filters.ActionFilterAttribute.<CallOnActionExecutedAsync>d__6.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 System.Web.Http.Filters.ActionFilterAttribute.<ExecuteActionFilterAsyncCore>d__5.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 System.Web.Http.Filters.ActionFilterAttribute.<CallOnActionExecutedAsync>d__6.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Web.Http.Filters.ActionFilterAttribute.<CallOnActionExecutedAsync>d__6.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 System.Web.Http.Filters.ActionFilterAttribute.<ExecuteActionFilterAsyncCore>d__5.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 System.Web.Http.Filters.ActionFilterAttribute.<CallOnActionExecutedAsync>d__6.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Web.Http.Filters.ActionFilterAttribute.<CallOnActionExecutedAsync>d__6.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 System.Web.Http.Filters.ActionFilterAttribute.<ExecuteActionFilterAsyncCore>d__5.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 System.Web.Http.Filters.ActionFilterAttribute.<CallOnActionExecutedAsync>d__6.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Web.Http.Filters.ActionFilterAttribute.<CallOnActionExecutedAsync>d__6.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 System.Web.Http.Filters.ActionFilterAttribute.<ExecuteActionFilterAsyncCore>d__5.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 System.Web.Http.Controllers.ActionFilterResult.<ExecuteAsync>d__5.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 System.Web.Http.Filters.AuthorizationFilterAttribute.<ExecuteAuthorizationFilterAsyncCore>d__3.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 System.Web.Http.Filters.AuthorizationFilterAttribute.<ExecuteAuthorizationFilterAsyncCore>d__3.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 System.Web.Http.Filters.AuthorizationFilterAttribute.<ExecuteAuthorizationFilterAsyncCore>d__3.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 System.Web.Http.Filters.AuthorizationFilterAttribute.<ExecuteAuthorizationFilterAsyncCore>d__3.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 System.Web.Http.Controllers.ExceptionFilterResult.<ExecuteAsync>d__6.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Web.Http.Controllers.ExceptionFilterResult.<ExecuteAsync>d__6.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 System.Web.Http.Dispatcher.HttpControllerDispatcher.<SendAsync>d__15.MoveNext()
ClientConnectionId:d74b1eed-112c-4882-bd92-da8704028153
Error Number:596,State:1,Class:21

Which happend shortly after something went really wrong with the move

System.Data.SqlClient.SqlException (0x80131904): A severe error occurred on the current command.  The results, if any, should be discarded.
   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.SqlDataReader.TryHasMoreRows(Boolean& moreRows)
   at System.Data.SqlClient.SqlDataReader.TryReadInternal(Boolean setTimeout, Boolean& more)
   at System.Data.SqlClient.SqlDataReader.Read()
   at NPoco.Database.<Read>d__156`1.MoveNext()
   at NPoco.Database.<QueryImp>d__164`1.MoveNext()
   at System.Collections.Generic.List`1..ctor(IEnumerable`1 collection)
   at System.Linq.Enumerable.ToList[TSource](IEnumerable`1 source)
   at NPoco.Database.<Page>b__170_0[T](Page`1 paged, Sql thesql)
   at NPoco.Database.PageImp[T,TRet](Int64 page, Int64 itemsPerPage, String sql, Object[] args, Func`3 executeQueryFunc)
   at NPoco.Database.Page[T](Int64 page, Int64 itemsPerPage, String sql, Object[] args)
   at NPoco.Database.Page[T](Int64 page, Int64 itemsPerPage, Sql sql)
   at Umbraco.Core.Persistence.Repositories.Implement.ContentRepositoryBase`3.GetPage[TDto](IQuery`1 query, Int64 pageIndex, Int32 pageSize, Int64& totalRecords, Func`2 mapDtos, Sql`1 filter, Ordering ordering) in d:\a\1\s\src\Umbraco.Core\Persistence\Repositories\Implement\ContentRepositoryBase.cs:line 494
   at Umbraco.Core.Persistence.Repositories.Implement.DocumentRepository.GetPage(IQuery`1 query, Int64 pageIndex, Int32 pageSize, Int64& totalRecords, IQuery`1 filter, Ordering ordering) in d:\a\1\s\src\Umbraco.Core\Persistence\Repositories\Implement\DocumentRepository.cs:line 870
   at Umbraco.Core.Services.Implement.ContentService.PerformMoveLocked(IContent content, Int32 parentId, IContent parent, Int32 userId, ICollection`1 moves, Nullable`1 trash) in d:\a\1\s\src\Umbraco.Core\Services\Implement\ContentService.cs:line 2013
   at Umbraco.Core.Services.Implement.ContentService.Move(IContent content, Int32 parentId, Int32 userId) in d:\a\1\s\src\Umbraco.Core\Services\Implement\ContentService.cs:line 1963
   at Umbraco.Web.Editors.ContentController.PostMove(MoveOrCopy move) in d:\a\1\s\src\Umbraco.Web\Editors\ContentController.cs:line 1548
   at lambda_method(Closure , Object , Object[] )
   at System.Web.Http.Controllers.ReflectedHttpActionDescriptor.ActionExecutor.<>c__DisplayClass6_2.<GetExecutor>b__2(Object instance, Object[] methodParameters)
   at System.Web.Http.Controllers.ReflectedHttpActionDescriptor.ExecuteAsync(HttpControllerContext controllerContext, IDictionary`2 arguments, CancellationToken cancellationToken)
ClientConnectionId:d74b1eed-112c-4882-bd92-da8704028153

I'm throwing this up here in case it helps or is even related. It's also quite possible I'm doing something I shouldn'. I have a number of events on Published/Saving/transformingIndexValues content to do various things such as send push notices, store some computed data in the ExternalIndex etc. I'll keep reviewing the code I've put into this site, if this sounds related, i'm happy to try 8.6.4.

@Shazwazza
Copy link
Contributor

@cleversolutions yes 8.6.4 will improve what you are seeing with the fixes to scheduled publishing. It may not fix everything entirely, it just depends on what's happening in your project. I would highly recommend you try the 8.6.4 build, it will definitely improve the lock contention for content. Please let us know any results

@Shazwazza
Copy link
Contributor

For long running operations like Move, lets say you are moving a huge amount of data, we cannot avoid SQL lock timeouts. We use SQL locks as the distributed locking mechanism. For long running operations the best we could do in the future would be to improve the handling of these errors and the UI so that we could detect long running operations and tell the user what is going on. There's certainly improvements in parts of the code that probably don't need to take a distributed lock or just not eagerly take one (like scheduled publishing was doing) which will all go a long way to improving this.

@Shazwazza
Copy link
Contributor

Hi @TimZander I've created a PR that you can find here #8525
This change should alleviate the issue you are seeing as we will no longer take a write lock during member login (in the membership provider GetUser(string username, bool userIsOnline) call). This is the issue displayed in the stack traces you posted above initially. Read locks aren't an issue unless a corresponding write lock is being attempted.

And other good news is that you can see in the PR that I've fixed a long outstanding TODO in the code to ensure that members are cached by their username and not just by their ID so you can remove your own caches for that. Since you were already caching members this way you would have already seen the performance improvements but perhaps you'll see more I'm unsure. For others that haven't added their own caches and have member heavy sites this will reduce queries tremendously since calls are made to get a member by username on each request.

I'll wait until tomorrow for the build to finish since it's late here but if you are around, the latest build for this is here https://dev.azure.com/umbraco/Umbraco%20Cms/_build/results?buildId=45100&view=results If it's successful you will be able to get the artifacts for that build and test it out. If you do let me know how it goes, else i'll respond tomorrow once the build is complete.

@TimZander
Copy link
Author

@Shazwazza Awesome! Thank you, I will review and apply the artifact ASAP.

Would this be expected to be rolled into 8.6.4 when that is released?

@Shazwazza
Copy link
Contributor

@TimZander unfortunately no we've missed that deadline window so this will be an 8.6.5 release

@Shazwazza Shazwazza changed the title umbracoLock timeout exceeded frequently umbracoLock timeout exceeded frequently for members Jul 30, 2020
@TimZander
Copy link
Author

@Shazwazza OK, thanks.

@Shazwazza
Copy link
Contributor

@TimZander
Copy link
Author

Thanks @Shazwazza I downloaded the artifacts yesterday as soon as the build completed and have been running them in our staging env. Early next week I'll apply to production and hope for the best!

@clausjensen
Copy link
Contributor

@TimZander Hi Tim,
Have you been able to test this in your production setup yet?

@TimZander
Copy link
Author

@clausjensen I will be applying to production in 9-10 hours. I will follow up in 24 hours with observed results

Thanks!

@TimZander
Copy link
Author

TimZander commented Aug 4, 2020

As of this morning we are no longer seeing many of this issue with umbracoLock timeout, however now I am seeing a number of other new exceptions.

System.Data.SqlClient.SqlException (0x80131904): Cannot insert duplicate key row in object 'dbo.umbracoPropertyData' with unique index 'IX_umbracoPropertyData_VersionId'. The duplicate key value is (3240, 312, <NULL>, <NULL>).
The statement has been terminated.
   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.SqlDataReader.TryConsumeMetaData()
   at System.Data.SqlClient.SqlDataReader.get_MetaData()
   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.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method)
   at System.Data.SqlClient.SqlCommand.ExecuteScalar()
   at Umbraco.Core.Persistence.FaultHandling.RetryPolicy.ExecuteAction[TResult](Func`1 func) in d:\a\1\s\src\Umbraco.Core\Persistence\FaultHandling\RetryPolicy.cs:line 172
   at NPoco.Database.ExecuteScalarHelper(DbCommand cmd)
   at NPoco.Database.InsertImp[T](PocoData pocoData, String tableName, String primaryKeyName, Boolean autoIncrement, T poco)
ClientConnectionId:21907364-5e16-4f42-937c-a4e835fd5bc9
Error Number:2601,State:1,Class:14

and

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.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)
   at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)
   at System.Data.SqlClient.TdsParserStateObject.ReadSniError(TdsParserStateObject stateObj, UInt32 error)
   at System.Data.SqlClient.TdsParserStateObject.ReadSniSyncOverAsync()
   at System.Data.SqlClient.TdsParserStateObject.TryReadNetworkPacket()
   at System.Data.SqlClient.TdsParserStateObject.TryPrepareBuffer()
   at System.Data.SqlClient.TdsParserStateObject.TryReadByte(Byte& value)
   at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)
   at System.Data.SqlClient.SqlDataReader.TryConsumeMetaData()
   at System.Data.SqlClient.SqlDataReader.get_MetaData()
   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.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method)
   at System.Data.SqlClient.SqlCommand.ExecuteScalar()
   at Umbraco.Core.Persistence.FaultHandling.RetryPolicy.ExecuteAction[TResult](Func`1 func) in d:\a\1\s\src\Umbraco.Core\Persistence\FaultHandling\RetryPolicy.cs:line 172
   at NPoco.Database.ExecuteScalarHelper(DbCommand cmd)
   at NPoco.Database.InsertImp[T](PocoData pocoData, String tableName, String primaryKeyName, Boolean autoIncrement, T poco)
ClientConnectionId:92e6e568-3603-4c50-945b-1e75a924c7f4
Error Number:-2,State:0,Class:11

and still a few of these

System.Data.SqlClient.SqlException (0x80131904): Lock request time out period exceeded.
The statement has been terminated.
   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 Umbraco.Core.Persistence.FaultHandling.RetryPolicy.ExecuteAction[TResult](Func`1 func) in d:\a\1\s\src\Umbraco.Core\Persistence\FaultHandling\RetryPolicy.cs:line 172
   at NPoco.Database.ExecuteNonQueryHelper(DbCommand cmd)
   at NPoco.Database.Execute(String sql, CommandType commandType, Object[] args)
ClientConnectionId:e1f55d80-5f65-45ca-88db-dbe97a0b5fa3
Error Number:1222,State:51,Class:16

@nul800sebastiaan
Copy link
Member

@unaligned We are depending on people trying out these updates on their environments as they are impossible for us to replicate. We're doing everything we can to make this a safe update, there's additional unit tests, etc. But before we put it into a release we'd love to know if it has the intended effect.

As to your question, not to be flippant but.. we expect to see them in a NuGet release as soon as we can get some real-life testing done. 🙂

@unaligned
Copy link

@nul800sebastiaan
I figured that might be the case, just figured I'd ask the question.

@Shazwazza
I've been testing this in a staging environment, and no longer see the errors present or other issues. However, I was not able to replicate the errors in the staging environment previously so that doesn't tell me anything. I'll look into promoting the build to our production server.

@unaligned
Copy link

@Shazwazza

I just released this in our production environment because we were seeing significant numbers of errors this morning, and it was affecting the backoffice. Things seem be be working more smoothly, but I have another error to report. See stack trace below.


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.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)
   at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)
   at System.Data.SqlClient.TdsParserStateObject.ReadSniError(TdsParserStateObject stateObj, UInt32 error)
   at System.Data.SqlClient.TdsParserStateObject.ReadSniSyncOverAsync()
   at System.Data.SqlClient.TdsParserStateObject.TryReadNetworkPacket()
   at System.Data.SqlClient.TdsParserStateObject.TryPrepareBuffer()
   at System.Data.SqlClient.TdsParserStateObject.TryReadByte(Byte& value)
   at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)
   at System.Data.SqlClient.TdsParser.Run(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj)
   at System.Data.SqlClient.TdsParser.TdsExecuteTransactionManagerRequest(Byte[] buffer, TransactionManagerRequestType request, String transactionName, TransactionManagerIsolationLevel isoLevel, Int32 timeout, SqlInternalTransaction transaction, TdsParserStateObject stateObj, Boolean isDelegateControlRequest)
   at System.Data.SqlClient.SqlInternalConnectionTds.ExecuteTransactionYukon(TransactionRequest transactionRequest, String transactionName, IsolationLevel iso, SqlInternalTransaction internalTransaction, Boolean isDelegateControlRequest)
   at System.Data.SqlClient.SqlInternalConnection.BeginSqlTransaction(IsolationLevel iso, String transactionName, Boolean shouldReconnect)
   at System.Data.SqlClient.SqlConnection.BeginTransaction(IsolationLevel iso, String transactionName)
   at System.Data.SqlClient.SqlConnection.BeginDbTransaction(IsolationLevel isolationLevel)
   at StackExchange.Profiling.Data.ProfiledDbConnection.BeginDbTransaction(IsolationLevel isolationLevel) in C:\projects\dotnet\src\MiniProfiler.Shared\Data\ProfiledDbConnection.cs:line 138
   at NPoco.Database.BeginTransaction(IsolationLevel isolationLevel)
   at Umbraco.Core.Scoping.Scope.get_Database() in d:\a\1\s\src\Umbraco.Core\Scoping\Scope.cs:line 242
   at Umbraco.Core.Persistence.Repositories.Implement.UserRepository.ValidateLoginSession(Int32 userId, Guid sessionId) in d:\a\1\s\src\Umbraco.Core\Persistence\Repositories\Implement\UserRepository.cs:line 202
   at Umbraco.Core.Services.Implement.UserService.ValidateLoginSession(Int32 userId, Guid sessionId) in d:\a\1\s\src\Umbraco.Core\Services\Implement\UserService.cs:line 549
   at Umbraco.Core.Security.BackOfficeUserStore.ValidateSessionIdAsync(Int32 userId, String sessionId) in d:\a\1\s\src\Umbraco.Core\Security\BackOfficeUserStore.cs:line 780
   at Umbraco.Web.Security.BackOfficeUserManager`1.<ValidateSessionIdAsync>d__11.MoveNext() in d:\a\1\s\src\Umbraco.Web\Security\BackOfficeUserManager.cs:line 246
--- 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 Umbraco.Web.Security.SessionIdValidator.<ValidateSessionAsync>d__2.MoveNext() in d:\a\1\s\src\Umbraco.Web\Security\SessionIdValidator.cs:line 100
--- 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 Umbraco.Web.Security.SessionIdValidator.<ValidateSessionAsync>d__1.MoveNext() in d:\a\1\s\src\Umbraco.Web\Security\SessionIdValidator.cs:line 36
--- 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 Umbraco.Web.Security.BackOfficeCookieAuthenticationProvider.<EnsureValidSessionId>d__7.MoveNext() in d:\a\1\s\src\Umbraco.Web\Security\BackOfficeCookieAuthenticationProvider.cs:line 119
--- 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 Umbraco.Web.Security.BackOfficeCookieAuthenticationProvider.<ValidateIdentity>d__6.MoveNext() in d:\a\1\s\src\Umbraco.Web\Security\BackOfficeCookieAuthenticationProvider.cs:line 102
--- 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.Owin.Security.Cookies.CookieAuthenticationHandler.<AuthenticateCoreAsync>d__12.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.Owin.Security.Infrastructure.AuthenticationHandler.<BaseInitializeAsync>d__31.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.Owin.Security.Infrastructure.AuthenticationMiddleware`1.<Invoke>d__5.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.Owin.Security.Infrastructure.AuthenticationMiddleware`1.<Invoke>d__5.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 Kentor.OwinCookieSaver.KentorOwinCookieSaverMiddleware.<Invoke>d__2.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.Identity.Owin.IdentityFactoryMiddleware`2.<Invoke>d__5.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.Identity.Owin.IdentityFactoryMiddleware`2.<Invoke>d__5.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.Owin.Host.SystemWeb.IntegratedPipeline.IntegratedPipelineContextStage.<RunApp>d__7.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.Owin.Host.SystemWeb.IntegratedPi
```peline.IntegratedPipelineContext.<DoFinalWork>d__12.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at Microsoft.Owin.Host.SystemWeb.IntegratedPipeline.StageAsyncResult.End(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)
ClientConnectionId:4d8e33b9-e3ba-4c7b-b529-56c462d2f851
Error Number:-2,State:0,Class:11

@unaligned
Copy link

unaligned commented Aug 18, 2020

And I'm also still getting some lock request timeouts:


System.Data.SqlClient.SqlException (0x80131904): Lock request time out period exceeded.
The statement has been terminated.
   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 Umbraco.Core.Persistence.FaultHandling.RetryPolicy.ExecuteAction[TResult](Func`1 func) in d:\a\1\s\src\Umbraco.Core\Persistence\FaultHandling\RetryPolicy.cs:line 172
   at NPoco.Database.ExecuteNonQueryHelper(DbCommand cmd)
   at NPoco.Database.Execute(String sql, CommandType commandType, Object[] args)
ClientConnectionId:491eeb73-6557-4859-8e7b-3f7c873883e8
Error Number:1222,State:51,Class:16


@Shazwazza
Copy link
Contributor

Thanks @unaligned, that is fairly good news

regarding these errors:

Things seem be be working more smoothly, but I have another error to report. See stack trace below.

This one is strange since this isn't a lock timeout, this is an query SQL timeout originating from user lookups

 at Umbraco.Core.Persistence.Repositories.Implement.UserRepository.ValidateLoginSession(Int32 userId, Guid sessionId) in d:\a\1\s\src\Umbraco.Core\Persistence\Repositories\Implement\UserRepository.cs:line 202
   at Umbraco.Core.Services.Implement.UserService.ValidateLoginSession(Int32 userId, Guid sessionId) in d:\a\1\s\src\Umbraco.Core\Services\Implement\UserService.cs:line 549

Are you able to tell me how many rows you have in your umbracoUserLogin table?

And I'm also still getting some lock request timeouts:

Do you have the full stack trace of where this query is originating? I mentioned before above (#8433 (comment)) that the lock timeouts in some cases won't be preventable. These SQL locks are used as distributed locks (like c# locks but distributed and with timeouts as to not lock indefinitely). There's probably more places to reduce the contention for these locks like I've been doing with all of the above changes which will help but to do that I need to know where the lock contentions are originating.

@unaligned
Copy link

unaligned commented Aug 19, 2020

@Shazwazza We have 9313 records in the umbracoUserLogin table. That is backoffice users, correct? That seems strange to me. We definitely do not have that many employees we've given backoffice access.

Edit: Oh I see, they're sessions, not user records.

@Shazwazza
Copy link
Contributor

@unaligned those are use login sessions, they are kept for 15 days. Anytime a new user login session is created old ones are purged that are 15 days old. You could double check that is occurring and see if all records in that table aren't older than 15 days? That isn't an enormous amount of records to do a query against and the query is done against the PK so the query is fast, I was just wondering if there was somehow an enormous amount of records in there resulting in a query timeout. I've debugged this query locally and there's no real way to improve the query performance since it's a very simple query against the PK of the table.

@Shazwazza
Copy link
Contributor

Hi @unaligned + @TimZander,

Do you have any updates on how your site is working with all of these fixes applied? Are you continually seeing the same errors and if so do you have any info on replication steps and stack traces?

Thanks!

@TimZander
Copy link
Author

Hi @Shazwazza we are still seeing some issues with lock request time out exceeded. I am including the most verbose logs we have of those exceptions

{"@t":"2020-08-31T15:34:08.0496669Z","@mt":"Exception ({InstanceId}).","@l":"Error","@x":"System.Data.SqlClient.SqlException (0x80131904): Lock request time out period exceeded.\r\nThe statement has been terminated.\r\n   at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)\r\n   at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)\r\n   at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)\r\n   at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString, Boolean isInternal, Boolean forDescribeParameterEncryption, Boolean shouldCacheForAlwaysEncrypted)\r\n   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)\r\n   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)\r\n   at System.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(TaskCompletionSource`1 completion, String methodName, Boolean sendToPipe, Int32 timeout, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry)\r\n   at System.Data.SqlClient.SqlCommand.ExecuteNonQuery()\r\n   at Umbraco.Core.Persistence.FaultHandling.RetryPolicy.ExecuteAction[TResult](Func`1 func) in d:\\a\\1\\s\\src\\Umbraco.Core\\Persistence\\FaultHandling\\RetryPolicy.cs:line 172\r\n   at NPoco.Database.ExecuteNonQueryHelper(DbCommand cmd)\r\n   at NPoco.Database.Execute(String sql, CommandType commandType, Object[] args)\r\nClientConnectionId:77132367-34ca-4846-8088-1c844d5de18b\r\nError Number:1222,State:51,Class:16","InstanceId":"b64576be","SourceContext":"Umbraco.Core.Persistence.UmbracoDatabase","ProcessId":10636,"ProcessName":"w3wp","ThreadId":46,"AppDomainId":2,"AppDomainAppId":"LMW3SVC1ROOT","MachineName":"GRANDCENTRAL01","Log4NetLevel":"ERROR","HttpSessionId":"33uby3rcymz1ekch5tbznsae","HttpRequestNumber":53,"HttpRequestId":"884f84c6-f174-434e-a41d-c958889ab4a4"}

Also the issue with duplicate key insert

{"@t":"2020-08-31T15:34:52.5922740Z","@mt":"Exception ({InstanceId}).","@l":"Error","@x":"System.Data.SqlClient.SqlException (0x80131904): Cannot insert duplicate key row in object 'dbo.umbracoPropertyData' with unique index 'IX_umbracoPropertyData_VersionId'. The duplicate key value is (9922, 46, <NULL>, <NULL>).\r\nThe statement has been terminated.\r\n   at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)\r\n   at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)\r\n   at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)\r\n   at System.Data.SqlClient.SqlDataReader.TryConsumeMetaData()\r\n   at System.Data.SqlClient.SqlDataReader.get_MetaData()\r\n   at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString, Boolean isInternal, Boolean forDescribeParameterEncryption, Boolean shouldCacheForAlwaysEncrypted)\r\n   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)\r\n   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)\r\n   at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method)\r\n   at System.Data.SqlClient.SqlCommand.ExecuteScalar()\r\n   at Umbraco.Core.Persistence.FaultHandling.RetryPolicy.ExecuteAction[TResult](Func`1 func) in d:\\a\\1\\s\\src\\Umbraco.Core\\Persistence\\FaultHandling\\RetryPolicy.cs:line 172\r\n   at NPoco.Database.ExecuteScalarHelper(DbCommand cmd)\r\n   at NPoco.Database.InsertImp[T](PocoData pocoData, String tableName, String primaryKeyName, Boolean autoIncrement, T poco)\r\nClientConnectionId:5c390dfc-c81f-40c3-bcb6-befb2445f97e\r\nError Number:2601,State:1,Class:14","InstanceId":"2e24c5c7","SourceContext":"Umbraco.Core.Persistence.UmbracoDatabase","ProcessId":10636,"ProcessName":"w3wp","ThreadId":39,"AppDomainId":2,"AppDomainAppId":"LMW3SVC1ROOT","MachineName":"GRANDCENTRAL01","Log4NetLevel":"ERROR","HttpSessionId":"33uby3rcymz1ekch5tbznsae","HttpRequestNumber":58,"HttpRequestId":"31fbb6cd-21f2-4603-83ab-c010142849df"}
{"@t":"2020-08-31T16:00:23.0356256Z","@mt":"Exception ({InstanceId}).","@l":"Error","@x":"System.Data.SqlClient.SqlException (0x80131904): Lock request time out period exceeded.\r\nThe statement has been terminated.\r\n   at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)\r\n   at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)\r\n   at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)\r\n   at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString, Boolean isInternal, Boolean forDescribeParameterEncryption, Boolean shouldCacheForAlwaysEncrypted)\r\n   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)\r\n   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)\r\n   at System.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(TaskCompletionSource`1 completion, String methodName, Boolean sendToPipe, Int32 timeout, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry)\r\n   at System.Data.SqlClient.SqlCommand.ExecuteNonQuery()\r\n   at Umbraco.Core.Persistence.FaultHandling.RetryPolicy.ExecuteAction[TResult](Func`1 func) in d:\\a\\1\\s\\src\\Umbraco.Core\\Persistence\\FaultHandling\\RetryPolicy.cs:line 172\r\n   at NPoco.Database.ExecuteNonQueryHelper(DbCommand cmd)\r\n   at NPoco.Database.Execute(String sql, CommandType commandType, Object[] args)\r\nClientConnectionId:fbcab53c-4a0a-4b73-8102-baa45fbe9cd4\r\nError Number:1222,State:51,Class:16","InstanceId":"28732756","SourceContext":"Umbraco.Core.Persistence.UmbracoDatabase","ProcessId":10636,"ProcessName":"w3wp","ThreadId":72,"AppDomainId":2,"AppDomainAppId":"LMW3SVC1ROOT","MachineName":"GRANDCENTRAL01","Log4NetLevel":"ERROR","HttpSessionId":"ycbcpw5lqxigckhstxc1ugyz","HttpRequestNumber":164,"HttpRequestId":"25d187fc-091c-4ae5-8854-d5d2ce8f8bd0"}
{"@t":"2020-08-31T16:02:09.1579859Z","@mt":"Exception ({InstanceId}).","@l":"Error","@x":"System.Data.SqlClient.SqlException (0x80131904): Lock request time out period exceeded.\r\nThe statement has been terminated.\r\n   at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)\r\n   at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)\r\n   at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)\r\n   at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString, Boolean isInternal, Boolean forDescribeParameterEncryption, Boolean shouldCacheForAlwaysEncrypted)\r\n   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)\r\n   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)\r\n   at System.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(TaskCompletionSource`1 completion, String methodName, Boolean sendToPipe, Int32 timeout, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry)\r\n   at System.Data.SqlClient.SqlCommand.ExecuteNonQuery()\r\n   at Umbraco.Core.Persistence.FaultHandling.RetryPolicy.ExecuteAction[TResult](Func`1 func) in d:\\a\\1\\s\\src\\Umbraco.Core\\Persistence\\FaultHandling\\RetryPolicy.cs:line 172\r\n   at NPoco.Database.ExecuteNonQueryHelper(DbCommand cmd)\r\n   at NPoco.Database.Execute(String sql, CommandType commandType, Object[] args)\r\nClientConnectionId:34f88ce1-b7cb-4e0b-9101-6b706fce8c27\r\nError Number:1222,State:51,Class:16","InstanceId":"50264da6","SourceContext":"Umbraco.Core.Persistence.UmbracoDatabase","ProcessId":10636,"ProcessName":"w3wp","ThreadId":49,"AppDomainId":2,"AppDomainAppId":"LMW3SVC1ROOT","MachineName":"GRANDCENTRAL01","Log4NetLevel":"ERROR","HttpSessionId":"2writq0wdl3zpqeykeus33ff","HttpRequestNumber":172,"HttpRequestId":"01a8cae7-b04f-4ad3-b08e-95e748f1d98f"}

At times it is from where we are calling member.save()

{"@t":"2020-08-31T16:03:07.4940758Z","@mt":"Exception ({InstanceId}).","@l":"Error","@x":"System.Data.SqlClient.SqlException (0x80131904): Lock request time out period exceeded.\r\nThe statement has been terminated.\r\n   at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)\r\n   at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)\r\n   at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)\r\n   at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString, Boolean isInternal, Boolean forDescribeParameterEncryption, Boolean shouldCacheForAlwaysEncrypted)\r\n   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)\r\n   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)\r\n   at System.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(TaskCompletionSource`1 completion, String methodName, Boolean sendToPipe, Int32 timeout, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry)\r\n   at System.Data.SqlClient.SqlCommand.ExecuteNonQuery()\r\n   at Umbraco.Core.Persistence.FaultHandling.RetryPolicy.ExecuteAction[TResult](Func`1 func) in d:\\a\\1\\s\\src\\Umbraco.Core\\Persistence\\FaultHandling\\RetryPolicy.cs:line 172\r\n   at NPoco.Database.ExecuteNonQueryHelper(DbCommand cmd)\r\n   at NPoco.Database.Execute(String sql, CommandType commandType, Object[] args)\r\n   at Umbraco.Core.Persistence.SqlSyntax.SqlServerSyntaxProvider.WriteLock(IDatabase db, TimeSpan timeout, Int32[] lockIds) in d:\\a\\1\\s\\src\\Umbraco.Core\\Persistence\\SqlSyntax\\SqlServerSyntaxProvider.cs:line 269\r\n   at Umbraco.Core.Services.Implement.MemberService.Save(IMember member, Boolean raiseEvents) in d:\\a\\1\\s\\src\\Umbraco.Core\\Services\\Implement\\MemberService.cs:line 837\r\n   at UmbracoGC.Services.Member.GrandCentralMemberService.SavePreferredResort(IMember Member, Site Site) in C:\\agent\\_work\\5\\s\\UmbracoGC\\Services\\Member\\GrandCentralMemberService.cs:line 176\r\nClientConnectionId:e3996513-6ec4-4eff-bc82-33de7fe3992d\r\nError Number:1222,State:51,Class:16","InstanceId":"4b3d6b98","SourceContext":"Umbraco.Core.Persistence.UmbracoDatabase","ProcessId":10636,"ProcessName":"w3wp","ThreadId":55,"AppDomainId":2,"AppDomainAppId":"LMW3SVC1ROOT","MachineName":"GRANDCENTRAL01","Log4NetLevel":"ERROR","HttpSessionId":"gdmrzssr10mkjb3431wzxy1c","HttpRequestNumber":180,"HttpRequestId":"7eb83bbf-2806-4bab-a69a-6464bd7349de"}

The offending code from above is as follows:

                var jsonResort = JsonConvert.SerializeObject(new List<string>() { Site.ToString() });
                Member.SetValue(siteValues.PreferredResortMemberPropertyAlias, jsonResort);
                serviceContext.MemberService.Save(Member);

@Shazwazza
Copy link
Contributor

Thanks @TimZander ,

Are you getting less errors with the changes done so far?

Some additional questions:

  • When you say "At times it is from where we are calling member.save()" How often are you saving members?
  • Are you performing member saving multiple times in single operations in your code? I'm asking this because it's possible to wrap multiple service Save calls in a single transaction which can be done with explicit Scopes which may make sense for you depending on your needs

I will re-visit the duplicate key issue and will look to change the lock timeout period (configurable) since it is quite low.

@TimZander
Copy link
Author

@Shazwazza good suggestion, I'm going to take a deeper look at where and under what circumstances we are saving members.

As a general rule we are rarely(but sometimes) saving members automatically, more often we are saving members when a user changes a property on the member such as contact phone number.

And yes, we are getting significantly less error counts than prior to the changes

@TimZander
Copy link
Author

* Are you performing member saving multiple times in single operations in your code? I'm asking this because it's possible to wrap multiple service Save calls in a single transaction which can be done with explicit Scopes which may make sense for you depending on your needs

Yes, when we are updating contact info we may be updating phone and email addresses, and currently we handle those with two unique memberservice.save(member) calls. This will likely be making our code more chatty than necessary. Since we are using the same member object to do those saves I have reduced it to one save at the end of the work.

Also we have been assigning roles within a foreach, I have changed that to now assign roles in bulk

                foreach (var ownerPriv in ownerPrivs)
                {
                    serviceContext.MemberService.AssignRole(member.Id, ownerPriv);
                }

changed to

                serviceContext.MemberService.AssignRoles(new int[] { member.Id }, ownerPrivs.Distinct().ToArray());

Another potential pain point is in saving passwords. We are currently using the member service to save passwords like so

                memberService.SavePassword(member, Password);

But I see that is depreciated. It seems the preferred way is using your UmbracoIdentity package https://github.com/Shazwazza/UmbracoIdentity/wiki
Is that an accurate assumption that we should migrate all our code that saves passwords from the MemberService to UmbracoIdentity?

@Shazwazza
Copy link
Contributor

@TimZander great stuff, reducing any DB calls will make a big difference. Also keep in mind that you can wrap multiple service calls in a custom Scope which means they will all execute in the same transaction which will be faster too so if you are still requiring multiple service calls in the same method that is an option.

MemberService.SavePassword is obsolete the because the Service layer is purely for working with the Database it was never intended to perform any Security/Member/User related logic. In v8 and earlier versions, that responsibility has always been with the ASP.Net membership providers. Those membership providers wrap the MemberService. Unfortunately the deprecated MemberService.SavePassword wrapped the Membership provider ... so now you see there's a circular dependency and no clear separation of responsibility which is why its deprecated (shouldn't have been there in the first place). It's also deprecated because it doesn't support the default password policies which require the old password to change the member's password.

My UmbracoIdentity is to change the entire membership security layer to use ASP.NET Identity instead of the old membership providers. This is entirely optional and is up to you if you need/want that and have any use for ASP.NET Identity like if you needed external login/OAuth support. If you don't need ASP.NET Identity then you don't need that package.

To change a members password in v8 (and previous versions) you should use the Membership Provider, or you can use Umbraco's MembershipHelper object which is exposed on most base Umbraco classes as Members. See https://github.com/umbraco/Umbraco-CMS/blob/v8/contrib/src/Umbraco.Web/Security/MembershipHelper.cs#L744 ... this is typically meant to be used in conjunction with the back office password changing logic of members and users and the ChangingPasswordModel is something used in an angular view but you are welcome to use this method manually however you want. At the end of the day it just wraps the Membership provider but offers a bunch of validation checks along the way.

@nul800sebastiaan
Copy link
Member

We'll mark this specific issue as fixed in #8525 - it will be a part of the upcoming versions 8.6.5, 8.7.1 and then all versions higher than that.

@vladicaivanovski
Copy link

vladicaivanovski commented Dec 8, 2020

Still getting lots of "Lock request time out period exceeded" issues running on 8.9 version. It is happening randomly all across the application including both front end and the backoffice.
It's causing our production site to perform poorly by forcing us constantly to restart the site. The site is running in Azure as App Service using the recommended configuration by the official umbraco documentation.
"Umbraco.ModelsBuilder.ModelsMode" value="PureLive"
"Umbraco.Core.MainDom.Lock" value="SqlMainDomLock"
"Umbraco.Core.LocalTempStorage" value="EnvironmentTemp"
Having these settings doesn't make any difference.

Please help...

Here are few stack traces:

{"@t":"2020-12-08T08:21:33.6409996Z","@mt":"Exception ({InstanceId}).","@l":"Error","@x":"System.Data.SqlClient.SqlException (0x80131904): The service has encountered an error processing your request. Please try again. Error code 40549.\r\nThe service has encountered an error processing your request. Please try again. Error code 40549.\r\nA severe error occurred on the current command. The results, if any, should be discarded.\r\n at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action1 wrapCloseInAction)\r\n at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)\r\n at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)\r\n at System.Data.SqlClient.SqlDataReader.TryHasMoreRows(Boolean& moreRows)\r\n at System.Data.SqlClient.SqlDataReader.TryReadInternal(Boolean setTimeout, Boolean& more)\r\n at System.Data.SqlClient.SqlDataReader.Read()\r\n at NPoco.Database.<Read>d__1561.MoveNext()\r\nClientConnectionId:9bdb859b-a761-432a-849b-35ae91155687\r\nError Number:40197,State:1,Class:20\r\nClientConnectionId before routing:616394e8-a846-4db8-a8b0-09a0b8ac74b7\r\nRouting Destination:f9e11cad1562.tr30.westeurope1-a.worker.database.windows.net,11132","InstanceId":"82e147e6","SourceContext":"Umbraco.Core.Persistence.UmbracoDatabase","ProcessId":4172,"ProcessName":"w3wp","ThreadId":1,"AppDomainId":2,"AppDomainAppId":"LMW3SVC998348641ROOT","MachineName":"RD0003FF1C95C0","Log4NetLevel":"ERROR","HttpRequestNumber":1,"HttpRequestId":"e8adab2a-0dba-4400-a965-9d5595022cba"}

{"@t":"2020-12-08T08:22:50.2511498Z","@mt":"An unhandled exception occurred","@l":"Error","@x":"Umbraco.Core.Exceptions.BootFailedException: Boot failed: Umbraco cannot run. See Umbraco's log file for more details.\n\n-> Umbraco.Core.Exceptions.BootFailedException: Boot failed.\n\n-> System.Data.SqlClient.SqlException: A severe error occurred on the current command. The results, if any, should be discarded.\r\nA severe error occurred on the current command. The results, if any, should be discarded.\n at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action1 wrapCloseInAction)\r\n at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)\r\n at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)\r\n at System.Data.SqlClient.SqlDataReader.TryHasMoreRows(Boolean& moreRows)\r\n at System.Data.SqlClient.SqlDataReader.TryReadInternal(Boolean setTimeout, Boolean& more)\r\n at System.Data.SqlClient.SqlDataReader.Read()\r\n at System.Data.SqlClient.SqlCommand.CompleteExecuteScalar(SqlDataReader ds, Boolean returnSqlValue)\r\n at System.Data.SqlClient.SqlCommand.ExecuteScalar()\r\n at Umbraco.Core.Persistence.FaultHandling.RetryPolicy.ExecuteAction[TResult](Func1 func) in D:\a\1\s\src\Umbraco.Core\Persistence\FaultHandling\RetryPolicy.cs:line 172\r\n at NPoco.Database.ExecuteScalarHelper(DbCommand cmd)\r\n at NPoco.Database.ExecuteScalar[T](String sql, CommandType commandType, Object[] args)\r\n at Umbraco.Core.Persistence.NPocoDatabaseExtensions.d__81.MoveNext() in D:\\a\\1\\s\\src\\Umbraco.Core\\Persistence\\NPocoDatabaseExtensions.cs:line 50\r\n at Umbraco.Web.PublishedCache.NuCache.DataSource.DatabaseDataSource.<GetAllMediaSources>d__8.MoveNext() in D:\\a\\1\\s\\src\\Umbraco.Web\\PublishedCache\\NuCache\\DataSource\\DatabaseDataSource.cs:line 165\r\n at Umbraco.Web.PublishedCache.NuCache.ContentStore.SetAllFastSortedLocked(IEnumerable1 kits, Boolean fromDb) in D:\a\1\s\src\Umbraco.Web\PublishedCache\NuCache\ContentStore.cs:line 696\r\n at Umbraco.Web.PublishedCache.NuCache.PublishedSnapshotService.LoadMediaFromDatabaseLocked(IScope scope, Boolean onStartup) in D:\a\1\s\src\Umbraco.Web\PublishedCache\NuCache\PublishedSnapshotService.cs:line 471\r\n at Umbraco.Web.PublishedCache.NuCache.PublishedSnapshotService.LockAndLoadMedia(Func2 action) in D:\\a\\1\\s\\src\\Umbraco.Web\\PublishedCache\\NuCache\\PublishedSnapshotService.cs:line 447\r\n at Umbraco.Web.PublishedCache.NuCache.PublishedSnapshotService.LoadCachesOnStartup() in D:\\a\\1\\s\\src\\Umbraco.Web\\PublishedCache\\NuCache\\PublishedSnapshotService.cs:line 248\r\n at Umbraco.Web.PublishedCache.NuCache.PublishedSnapshotService..ctor(PublishedSnapshotServiceOptions options, IMainDom mainDom, IRuntimeState runtime, ServiceContext serviceContext, IPublishedContentTypeFactory publishedContentTypeFactory, IdkMap idkMap, IPublishedSnapshotAccessor publishedSnapshotAccessor, IVariationContextAccessor variationContextAccessor, IProfilingLogger logger, IScopeProvider scopeProvider, IDocumentRepository documentRepository, IMediaRepository mediaRepository, IMemberRepository memberRepository, IDefaultCultureAccessor defaultCultureAccessor, IDataSource dataSource, IGlobalSettings globalSettings, IEntityXmlSerializer entitySerializer, IPublishedModelFactory publishedModelFactory, UrlSegmentProviderCollection urlSegmentProviders) in D:\\a\\1\\s\\src\\Umbraco.Web\\PublishedCache\\NuCache\\PublishedSnapshotService.cs:line 149\r\n at DynamicMethod(Object[] )\r\n at LightInject.PerContainerLifetime.GetInstance(Func1 createInstance, Scope scope) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 6169\r\n at LightInject.ServiceContainer.EmitLifetime(ServiceRegistration serviceRegistration, Action1 emitMethod, IEmitter emitter) in C:\\projects\\lightinject\\src\\LightInject\\LightInject.cs:line 4656\r\n at LightInject.ServiceContainer.<>c__DisplayClass153_0.<CreateEmitMethodWrapper>b__0(IEmitter ms) in C:\\projects\\lightinject\\src\\LightInject\\LightInject.cs:line 3856\r\n at LightInject.ServiceContainer.EmitConstructorDependency(IEmitter emitter, Dependency dependency) in C:\\projects\\lightinject\\src\\LightInject\\LightInject.cs:line 4158\r\n at LightInject.ServiceContainer.EmitConstructorDependencies(ConstructionInfo constructionInfo, IEmitter emitter, Action1 decoratorTargetEmitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4120\r\n at LightInject.ServiceContainer.EmitNewInstanceUsingImplementingType(IEmitter emitter, ConstructionInfo constructionInfo, Action1 decoratorTargetEmitMethod) in C:\\projects\\lightinject\\src\\LightInject\\LightInject.cs:line 4081\r\n at LightInject.ServiceContainer.EmitNewInstance(ServiceRegistration serviceRegistration, IEmitter emitter) in C:\\projects\\lightinject\\src\\LightInject\\LightInject.cs:line 4038\r\n at LightInject.ServiceContainer.CreateDynamicMethodDelegate(Action1 serviceEmitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3777\r\n at LightInject.ServiceContainer.<>c__DisplayClass198_0.b__1() in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4657\r\n at LightInject.PerContainerLifetime.GetInstance(Func1 createInstance, Scope scope) in C:\\projects\\lightinject\\src\\LightInject\\LightInject.cs:line 6169\r\n at LightInject.ServiceContainer.EmitLifetime(ServiceRegistration serviceRegistration, Action1 emitMethod, IEmitter emitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4656\r\n at LightInject.ServiceContainer.<>c__DisplayClass153_0.b__0(IEmitter ms) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3856\r\n at LightInject.ServiceContainer.EmitConstructorDependency(IEmitter emitter, Dependency dependency) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4158\r\n at LightInject.ServiceContainer.EmitConstructorDependencies(ConstructionInfo constructionInfo, IEmitter emitter, Action1 decoratorTargetEmitter) in C:\\projects\\lightinject\\src\\LightInject\\LightInject.cs:line 4120\r\n at LightInject.ServiceContainer.EmitNewInstanceUsingImplementingType(IEmitter emitter, ConstructionInfo constructionInfo, Action1 decoratorTargetEmitMethod) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4081\r\n at LightInject.ServiceContainer.EmitNewInstance(ServiceRegistration serviceRegistration, IEmitter emitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4038\r\n at LightInject.ServiceContainer.CreateDynamicMethodDelegate(Action1 serviceEmitter) in C:\\projects\\lightinject\\src\\LightInject\\LightInject.cs:line 3777\r\n at LightInject.ServiceContainer.<>c__DisplayClass198_0.<EmitLifetime>b__1() in C:\\projects\\lightinject\\src\\LightInject\\LightInject.cs:line 4657\r\n at LightInject.PerContainerLifetime.GetInstance(Func1 createInstance, Scope scope) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 6169\r\n at LightInject.ServiceContainer.EmitLifetime(ServiceRegistration serviceRegistration, Action1 emitMethod, IEmitter emitter) in C:\\projects\\lightinject\\src\\LightInject\\LightInject.cs:line 4656\r\n at LightInject.ServiceContainer.<>c__DisplayClass153_0.<CreateEmitMethodWrapper>b__0(IEmitter ms) in C:\\projects\\lightinject\\src\\LightInject\\LightInject.cs:line 3856\r\n at LightInject.ServiceContainer.EmitConstructorDependency(IEmitter emitter, Dependency dependency) in C:\\projects\\lightinject\\src\\LightInject\\LightInject.cs:line 4158\r\n at LightInject.ServiceContainer.EmitConstructorDependencies(ConstructionInfo constructionInfo, IEmitter emitter, Action1 decoratorTargetEmitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4120\r\n at LightInject.ServiceContainer.EmitNewInstanceUsingImplementingType(IEmitter emitter, ConstructionInfo constructionInfo, Action1 decoratorTargetEmitMethod) in C:\\projects\\lightinject\\src\\LightInject\\LightInject.cs:line 4081\r\n at LightInject.ServiceContainer.EmitNewInstance(ServiceRegistration serviceRegistration, IEmitter emitter) in C:\\projects\\lightinject\\src\\LightInject\\LightInject.cs:line 4038\r\n at LightInject.ServiceContainer.CreateDynamicMethodDelegate(Action1 serviceEmitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3777\r\n at LightInject.ServiceContainer.<>c__DisplayClass198_0.b__1() in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4657\r\n at LightInject.PerContainerLifetime.GetInstance(Func1 createInstance, Scope scope) in C:\\projects\\lightinject\\src\\LightInject\\LightInject.cs:line 6169\r\n at LightInject.ServiceContainer.EmitLifetime(ServiceRegistration serviceRegistration, Action1 emitMethod, IEmitter emitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4656\r\n at LightInject.ServiceContainer.<>c__DisplayClass153_0.b__0(IEmitter ms) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3856\r\n at LightInject.ServiceContainer.CreateDynamicMethodDelegate(Action1 serviceEmitter) in C:\\projects\\lightinject\\src\\LightInject\\LightInject.cs:line 3777\r\n at LightInject.ServiceContainer.CreateDelegate(Type serviceType, String serviceName, Boolean throwError) in C:\\projects\\lightinject\\src\\LightInject\\LightInject.cs:line 4743\r\n at LightInject.ServiceContainer.CreateDefaultDelegate(Type serviceType, Boolean throwError) in C:\\projects\\lightinject\\src\\LightInject\\LightInject.cs:line 4705\r\n at LightInject.ServiceContainer.GetInstance(Type serviceType) in C:\\projects\\lightinject\\src\\LightInject\\LightInject.cs:line 3437\r\n at Umbraco.Core.Composing.ComponentCollectionBuilder.CreateItem(IFactory factory, Type itemType) in D:\\a\\1\\s\\src\\Umbraco.Core\\Composing\\ComponentCollectionBuilder.cs:line 33\r\n at System.Linq.Enumerable.WhereSelectArrayIterator2.MoveNext()\r\n at System.Linq.Buffer1..ctor(IEnumerable1 source)\r\n at System.Linq.Enumerable.ToArray[TSource](IEnumerable1 source)\r\n at Umbraco.Core.Composing.ComponentCollectionBuilder.CreateItems(IFactory factory) in D:\\a\\1\\s\\src\\Umbraco.Core\\Composing\\ComponentCollectionBuilder.cs:line 25\r\n at Umbraco.Core.Composing.CollectionBuilderBase3.CreateCollection(IFactory factory) in D:\a\1\s\src\Umbraco.Core\Composing\CollectionBuilderBase.cs:line 120\r\n at LightInject.PerContainerLifetime.GetInstance(Func1 createInstance, Scope scope) in C:\\projects\\lightinject\\src\\LightInject\\LightInject.cs:line 6169\r\n at LightInject.ServiceContainer.EmitLifetime(ServiceRegistration serviceRegistration, Action1 emitMethod, IEmitter emitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4656\r\n at LightInject.ServiceContainer.<>c__DisplayClass153_0.b__0(IEmitter ms) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3856\r\n at LightInject.ServiceContainer.CreateDynamicMethodDelegate(Action`1 serviceEmitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3777\r\n at LightInject.ServiceContainer.CreateDelegate(Type serviceType, String serviceName, Boolean throwError) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4743\r\n at LightInject.ServiceContainer.CreateDefaultDelegate(Type serviceType, Boolean throwError) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4705\r\n at LightInject.ServiceContainer.GetInstance(Type serviceType) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3437\r\n at Umbraco.Core.FactoryExtensions.GetInstance[T](IFactory factory) in D:\a\1\s\src\Umbraco.Core\FactoryExtensions.cs:line 23\r\n at Umbraco.Core.Runtime.CoreRuntime.Boot(IRegister register, DisposableTimer timer) in D:\a\1\s\src\Umbraco.Core\Runtime\CoreRuntime.cs:line 187\r\n at Umbraco.Core.Exceptions.BootFailedException.Rethrow(BootFailedException bootFailedException) in D:\a\1\s\src\Umbraco.Core\Exceptions\BootFailedException.cs:line 64\r\n at System.Web.HttpApplication.SyncEventExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()\r\n at System.Web.HttpApplication.ExecuteStepImpl(IExecutionStep step)\r\n at System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean& completedSynchronously)","SourceContext":"Umbraco.Web.UmbracoApplicationBase","ProcessId":4172,"ProcessName":"w3wp","ThreadId":6,"AppDomainId":3,"AppDomainAppId":"LMW3SVC998348641ROOT","MachineName":"RD0003FF1C95C0","Log4NetLevel":"ERROR","HttpRequestNumber":152,"HttpRequestId":"8b34f820-a5d6-41c9-b481-157499fadb6e"}

@deekoulos
Copy link

deekoulos commented Jan 23, 2021

In our case (Umbraco 8.10.1) we get the "Lock request time out period exceeded" whenever bots are crawling the site and causing a lot of load...

System.Data.SqlClient.SqlException
Lock request time out period exceeded. The statement has been terminated.

at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action1 wrapCloseInAction) at System.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection, Action1 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, TaskCompletionSource1 completion, Int32 timeout, Task& task, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry) at System.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(TaskCompletionSource1 completion, String methodName, Boolean sendToPipe, Int32 timeout, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry) at System.Data.SqlClient.SqlCommand.ExecuteNonQuery() at StackExchange.Profiling.Data.ProfiledDbCommand.ExecuteNonQuery() in C:\projects\dotnet\src\MiniProfiler.Shared\Data\ProfiledDbCommand.cs:line 272 at Umbraco.Core.Persistence.FaultHandling.FaultHandlingDbCommand.b__31_0() at Umbraco.Core.Persistence.FaultHandling.FaultHandlingDbCommand.<>c__DisplayClass33_01.b__0() at Umbraco.Core.Persistence.FaultHandling.RetryPolicy.ExecuteAction[TResult](Func1 func) at Umbraco.Core.Persistence.FaultHandling.FaultHandlingDbCommand.Execute[T](Func1 f) at Umbraco.Core.Persistence.FaultHandling.FaultHandlingDbCommand.ExecuteNonQuery() at NPoco.Database.ExecuteNonQueryHelper(DbCommand cmd) at NPoco.Database.NPoco.IDatabaseHelpers.ExecuteNonQueryHelper(DbCommand cmd) at NPoco.Database.Execute(String sql, CommandType commandType, Object[] args) at NPoco.Database.Execute(Sql Sql) at NPoco.Database.Execute(String sql, Object[] args) at Umbraco.Core.Persistence.SqlSyntax.SqlServerSyntaxProvider.WriteLock(IDatabase db, TimeSpan timeout, Int32[] lockIds) at Umbraco.Core.Persistence.SqlSyntax.SqlServerSyntaxProvider.WriteLock(IDatabase db, Int32[] lockIds) at Umbraco.Core.Scoping.Scope.WriteLock(Int32[] lockIds) at Umbraco.Core.Services.Implement.MemberService.Save(IMember member, Boolean raiseEvents) at Feedbax.Core.Controllers.RenderMvc.ProfileController.Index(ContentModel model) at lambda_method(Closure , ControllerBase , Object[] ) at System.Web.Mvc.ActionMethodDispatcher.Execute(ControllerBase controller, Object[] parameters) at System.Web.Mvc.ReflectedActionDescriptor.Execute(ControllerContext controllerContext, IDictionary2 parameters) at System.Web.Mvc.ControllerActionInvoker.InvokeActionMethod(ControllerContext controllerContext, ActionDescriptor actionDescriptor, IDictionary2 parameters) at System.Web.Mvc.Async.AsyncControllerActionInvoker.<>c.b__9_0(IAsyncResult asyncResult, ActionInvocation innerInvokeState) at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncResult2.CallEndDelegate(IAsyncResult asyncResult) at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncResultBase1.End() at System.Web.Mvc.Async.AsyncControllerActionInvoker.EndInvokeActionMethod(IAsyncResult asyncResult) at System.Web.Mvc.Async.AsyncControllerActionInvoker.AsyncInvocationWithFilters.<>c__DisplayClass11_0.b__0() at System.Web.Mvc.Async.AsyncControllerActionInvoker.AsyncInvocationWithFilters.<>c__DisplayClass11_2.b__2() at System.Web.Mvc.Async.AsyncControllerActionInvoker.AsyncInvocationWithFilters.<>c__DisplayClass11_2.b__2() at System.Web.Mvc.Async.AsyncControllerActionInvoker.AsyncInvocationWithFilters.<>c__DisplayClass11_2.b__2() at System.Web.Mvc.Async.AsyncControllerActionInvoker.<>c__DisplayClass7_0.b__1(IAsyncResult asyncResult) at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncResult1.CallEndDelegate(IAsyncResult asyncResult) at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncResultBase1.End() at System.Web.Mvc.Async.AsyncControllerActionInvoker.EndInvokeActionMethodWithFilters(IAsyncResult asyncResult) at System.Web.Mvc.Async.AsyncControllerActionInvoker.<>c__DisplayClass3_6.b__4() at System.Web.Mvc.Async.AsyncControllerActionInvoker.<>c__DisplayClass3_1.b__1(IAsyncResult asyncResult) at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncResult1.CallEndDelegate(IAsyncResult asyncResult) at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncResultBase1.End() at System.Web.Mvc.Async.AsyncControllerActionInvoker.EndInvokeAction(IAsyncResult asyncResult) at System.Web.Mvc.Controller.<>c.b__152_1(IAsyncResult asyncResult, ExecuteCoreState innerState) at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncVoid1.CallEndDelegate(IAsyncResult asyncResult) at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncResultBase1.End() at System.Web.Mvc.Controller.EndExecuteCore(IAsyncResult asyncResult) at System.Web.Mvc.Controller.<>c.b__151_2(IAsyncResult asyncResult, Controller controller) at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncVoid1.CallEndDelegate(IAsyncResult asyncResult) at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncResultBase1.End() at System.Web.Mvc.Controller.EndExecute(IAsyncResult asyncResult) at System.Web.Mvc.Controller.System.Web.Mvc.Async.IAsyncController.EndExecute(IAsyncResult asyncResult) at System.Web.Mvc.MvcHandler.<>c.b__20_1(IAsyncResult asyncResult, ProcessRequestState innerState) at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncVoid1.CallEndDelegate(IAsyncResult asyncResult) at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncResultBase1.End() at System.Web.Mvc.MvcHandler.EndProcessRequest(IAsyncResult asyncResult) at System.Web.Mvc.MvcHandler.System.Web.IHttpAsyncHandler.EndProcessRequest(IAsyncResult result) at System.Web.HttpApplication.CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute() at System.Web.HttpApplication.ExecuteStepImpl(IExecutionStep step) at System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean& completedSynchronously)`

Does anyone know any workarounds for this? This is really business critical. We need a solution or any kind of workarounds here.

@vladicaivanovski is your website running on Azure?

@SimonAntony
Copy link

I've been getting this more and more since 8.9 and it's progressively getting worse (even after upgrading to 8.11 today). Setup is Dedicated server running SQL Server 2017 (so no azure).

Always happens after doing a few publish events (updating content) - only way to fix it is to restart SQL Server which is far from ideal, god knows how i'd do this if it was Azure.

Log entry:

2021-01-28 11:49:02,112 [P15776/D2/T17] ERROR Umbraco.Web.Editors.ContentController - Unhandled controller exception occurred for request 'http://site.com.local/umbraco/backoffice/UmbracoApi/Content/PostSave'
System.Data.SqlClient.SqlException (0x80131904): Lock request time out period exceeded.
The statement has been terminated.
at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action1 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, TaskCompletionSource1 completion, Int32 timeout, Task& task, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry)
at System.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(TaskCompletionSource1 completion, String methodName, Boolean sendToPipe, Int32 timeout, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry) at System.Data.SqlClient.SqlCommand.ExecuteNonQuery() at Umbraco.Core.Persistence.FaultHandling.RetryPolicy.ExecuteAction[TResult](Func1 func) in D:\a\1\s\src\Umbraco.Core\Persistence\FaultHandling\RetryPolicy.cs:line 172
at NPoco.Database.ExecuteNonQueryHelper(DbCommand cmd)
at NPoco.Database.Execute(String sql, CommandType commandType, Object[] args)
at Umbraco.Core.Persistence.SqlSyntax.SqlServerSyntaxProvider.WriteLock(IDatabase db, TimeSpan timeout, Int32[] lockIds) in D:\a\1\s\src\Umbraco.Core\Persistence\SqlSyntax\SqlServerSyntaxProvider.cs:line 272
at Umbraco.Core.Services.Implement.ContentService.Save(IContent content, Int32 userId, Boolean raiseEvents) in D:\a\1\s\src\Umbraco.Core\Services\Implement\ContentService.cs:line 782
at Umbraco.Web.Editors.ContentController.SaveAndNotify(ContentItemSave contentItem, Func2 saveMethod, Int32 variantCount, Dictionary2 notifications, SimpleNotificationModel globalNotifications, String invariantSavedLocalizationKey, String variantSavedLocalizationKey, String cultureForInvariantErrors, Boolean& wasCancelled) in D:\a\1\s\src\Umbraco.Web\Editors\ContentController.cs:line 924
at Umbraco.Web.Editors.ContentController.PostSaveInternal(ContentItemSave contentItem, Func2 saveMethod, Func2 mapToDisplay) in D:\a\1\s\src\Umbraco.Web\Editors\ContentController.cs:line 712
at lambda_method(Closure , Object , Object[] )
at System.Web.Http.Controllers.ReflectedHttpActionDescriptor.ActionExecutor.<>c__DisplayClass6_2.b__2(Object instance, Object[] methodParameters)
at System.Web.Http.Controllers.ReflectedHttpActionDescriptor.ExecuteAsync(HttpControllerContext controllerContext, IDictionary`2 arguments, CancellationToken cancellationToken)
--- 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 System.Web.Http.Controllers.ApiControllerActionInvoker.d__1.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 System.Web.Http.Filters.ActionFilterAttribute.d__6.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Web.Http.Filters.ActionFilterAttribute.d__6.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 System.Web.Http.Filters.ActionFilterAttribute.d__5.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 System.Web.Http.Filters.ActionFilterAttribute.d__6.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Web.Http.Filters.ActionFilterAttribute.d__6.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 System.Web.Http.Filters.ActionFilterAttribute.d__5.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 System.Web.Http.Filters.ActionFilterAttribute.d__6.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Web.Http.Filters.ActionFilterAttribute.d__6.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 System.Web.Http.Filters.ActionFilterAttribute.d__5.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 System.Web.Http.Filters.ActionFilterAttribute.d__6.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Web.Http.Filters.ActionFilterAttribute.d__6.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 System.Web.Http.Filters.ActionFilterAttribute.d__5.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 System.Web.Http.Filters.ActionFilterAttribute.d__6.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Web.Http.Filters.ActionFilterAttribute.d__6.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 System.Web.Http.Filters.ActionFilterAttribute.d__5.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 System.Web.Http.Filters.ActionFilterAttribute.d__6.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Web.Http.Filters.ActionFilterAttribute.d__6.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 System.Web.Http.Filters.ActionFilterAttribute.d__5.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 System.Web.Http.Filters.ActionFilterAttribute.d__6.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Web.Http.Filters.ActionFilterAttribute.d__6.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 System.Web.Http.Filters.ActionFilterAttribute.d__5.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 System.Web.Http.Filters.ActionFilterAttribute.d__6.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Web.Http.Filters.ActionFilterAttribute.d__6.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 System.Web.Http.Filters.ActionFilterAttribute.d__5.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 System.Web.Http.Filters.ActionFilterAttribute.d__6.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Web.Http.Filters.ActionFilterAttribute.d__6.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 System.Web.Http.Filters.ActionFilterAttribute.d__5.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 System.Web.Http.Controllers.ActionFilterResult.d__5.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 System.Web.Http.Filters.AuthorizationFilterAttribute.d__3.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 System.Web.Http.Filters.AuthorizationFilterAttribute.d__3.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 System.Web.Http.Filters.AuthorizationFilterAttribute.d__3.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 System.Web.Http.Filters.AuthorizationFilterAttribute.d__3.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 System.Web.Http.Controllers.ExceptionFilterResult.d__6.MoveNext()
ClientConnectionId:9df42156-ac71-4e50-91b4-e78a159e0483
Error Number:1222,State:51,Class:16

@vladicaivanovski
Copy link

In our case (Umbraco 8.10.1) we get the "Lock request time out period exceeded" whenever bots are crawling the site and causing a lot of load...

System.Data.SqlClient.SqlException
Lock request time out period exceeded. The statement has been terminated.

at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action1 wrapCloseInAction) at System.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection, Action1 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, TaskCompletionSource1 completion, Int32 timeout, Task& task, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry) at System.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(TaskCompletionSource1 completion, String methodName, Boolean sendToPipe, Int32 timeout, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry) at System.Data.SqlClient.SqlCommand.ExecuteNonQuery() at StackExchange.Profiling.Data.ProfiledDbCommand.ExecuteNonQuery() in C:\projects\dotnet\src\MiniProfiler.Shared\Data\ProfiledDbCommand.cs:line 272 at Umbraco.Core.Persistence.FaultHandling.FaultHandlingDbCommand.b__31_0() at Umbraco.Core.Persistence.FaultHandling.FaultHandlingDbCommand.<>c__DisplayClass33_01.b__0() at Umbraco.Core.Persistence.FaultHandling.RetryPolicy.ExecuteAction[TResult](Func1 func) at Umbraco.Core.Persistence.FaultHandling.FaultHandlingDbCommand.Execute[T](Func1 f) at Umbraco.Core.Persistence.FaultHandling.FaultHandlingDbCommand.ExecuteNonQuery() at NPoco.Database.ExecuteNonQueryHelper(DbCommand cmd) at NPoco.Database.NPoco.IDatabaseHelpers.ExecuteNonQueryHelper(DbCommand cmd) at NPoco.Database.Execute(String sql, CommandType commandType, Object[] args) at NPoco.Database.Execute(Sql Sql) at NPoco.Database.Execute(String sql, Object[] args) at Umbraco.Core.Persistence.SqlSyntax.SqlServerSyntaxProvider.WriteLock(IDatabase db, TimeSpan timeout, Int32[] lockIds) at Umbraco.Core.Persistence.SqlSyntax.SqlServerSyntaxProvider.WriteLock(IDatabase db, Int32[] lockIds) at Umbraco.Core.Scoping.Scope.WriteLock(Int32[] lockIds) at Umbraco.Core.Services.Implement.MemberService.Save(IMember member, Boolean raiseEvents) at Feedbax.Core.Controllers.RenderMvc.ProfileController.Index(ContentModel model) at lambda_method(Closure , ControllerBase , Object[] ) at System.Web.Mvc.ActionMethodDispatcher.Execute(ControllerBase controller, Object[] parameters) at System.Web.Mvc.ReflectedActionDescriptor.Execute(ControllerContext controllerContext, IDictionary2 parameters) at System.Web.Mvc.ControllerActionInvoker.InvokeActionMethod(ControllerContext controllerContext, ActionDescriptor actionDescriptor, IDictionary2 parameters) at System.Web.Mvc.Async.AsyncControllerActionInvoker.<>c.b__9_0(IAsyncResult asyncResult, ActionInvocation innerInvokeState) at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncResult2.CallEndDelegate(IAsyncResult asyncResult) at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncResultBase1.End() at System.Web.Mvc.Async.AsyncControllerActionInvoker.EndInvokeActionMethod(IAsyncResult asyncResult) at System.Web.Mvc.Async.AsyncControllerActionInvoker.AsyncInvocationWithFilters.<>c__DisplayClass11_0.b__0() at System.Web.Mvc.Async.AsyncControllerActionInvoker.AsyncInvocationWithFilters.<>c__DisplayClass11_2.b__2() at System.Web.Mvc.Async.AsyncControllerActionInvoker.AsyncInvocationWithFilters.<>c__DisplayClass11_2.b__2() at System.Web.Mvc.Async.AsyncControllerActionInvoker.AsyncInvocationWithFilters.<>c__DisplayClass11_2.b__2() at System.Web.Mvc.Async.AsyncControllerActionInvoker.<>c__DisplayClass7_0.b__1(IAsyncResult asyncResult) at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncResult1.CallEndDelegate(IAsyncResult asyncResult) at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncResultBase1.End() at System.Web.Mvc.Async.AsyncControllerActionInvoker.EndInvokeActionMethodWithFilters(IAsyncResult asyncResult) at System.Web.Mvc.Async.AsyncControllerActionInvoker.<>c__DisplayClass3_6.b__4() at System.Web.Mvc.Async.AsyncControllerActionInvoker.<>c__DisplayClass3_1.b__1(IAsyncResult asyncResult) at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncResult1.CallEndDelegate(IAsyncResult asyncResult) at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncResultBase1.End() at System.Web.Mvc.Async.AsyncControllerActionInvoker.EndInvokeAction(IAsyncResult asyncResult) at System.Web.Mvc.Controller.<>c.b__152_1(IAsyncResult asyncResult, ExecuteCoreState innerState) at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncVoid1.CallEndDelegate(IAsyncResult asyncResult) at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncResultBase1.End() at System.Web.Mvc.Controller.EndExecuteCore(IAsyncResult asyncResult) at System.Web.Mvc.Controller.<>c.b__151_2(IAsyncResult asyncResult, Controller controller) at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncVoid1.CallEndDelegate(IAsyncResult asyncResult) at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncResultBase1.End() at System.Web.Mvc.Controller.EndExecute(IAsyncResult asyncResult) at System.Web.Mvc.Controller.System.Web.Mvc.Async.IAsyncController.EndExecute(IAsyncResult asyncResult) at System.Web.Mvc.MvcHandler.<>c.b__20_1(IAsyncResult asyncResult, ProcessRequestState innerState) at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncVoid1.CallEndDelegate(IAsyncResult asyncResult) at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncResultBase1.End() at System.Web.Mvc.MvcHandler.EndProcessRequest(IAsyncResult asyncResult) at System.Web.Mvc.MvcHandler.System.Web.IHttpAsyncHandler.EndProcessRequest(IAsyncResult result) at System.Web.HttpApplication.CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute() at System.Web.HttpApplication.ExecuteStepImpl(IExecutionStep step) at System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean& completedSynchronously)`

Does anyone know any workarounds for this? This is really business critical. We need a solution or any kind of workarounds here.

@vladicaivanovski is your website running on Azure?

Yes.

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

Successfully merging a pull request may close this issue.

10 participants