Copied to clipboard

Flag this post as spam?

This post will be reported to the moderators as potential spam to be looked at


  • Trevor Husseini 20 posts 151 karma points
    Feb 16, 2023 @ 20:02
    Trevor Husseini
    0

    SQL Deadlocks when Publishing All

    Aloha,

    I understand that v7 is marching towards its EOL in 09/2023. Regardless, I recently upgraded a v7.6.5 installation to v7.15.10 because there have been improvements to how the app manages memory between those versions and the target installation was consuming more RAM than I could justify.

    After the upgrade, a new environment (fresh copy of the codebase + new, upgraded DB) was setup on a shared Staging server. Saving & publishing the home node and its children from this environment is consistently failing. My investigation shows that the error is being thrown from the persistence layer. In my logs, I see:

    2023-02-16 09:29:04,303 [P3392/D2/T25] INFO Umbraco.Core.Publishing.PublishingStrategy - Content 'Landing Content' with Id '8380' will not be published because it's parent's publishing action failed or was cancelled. 2023-02-16 09:29:04,304 [P3392/D2/T25] INFO Umbraco.Core.Publishing.PublishingStrategy - Content 'Landing Content' with Id '8267' will not be published because it's parent's publishing action failed or was cancelled. 2023-02-16 09:29:04,304 [P3392/D2/T25] INFO Umbraco.Core.Publishing.PublishingStrategy - Content 'Landing Content' with Id '8265' will not be published because it's parent's publishing action failed or was cancelled. 2023-02-16 09:29:04,305 [P3392/D2/T25] INFO Umbraco.Core.Publishing.PublishingStrategy - Content 'Landing Content' with Id '8110' will not be published because it's parent's publishing action failed or was cancelled. 2023-02-16 09:29:04,305 [P3392/D2/T25] INFO Umbraco.Core.Publishing.PublishingStrategy - Content 'Landing Content' with Id '8077' will not be published because it's parent's publishing action failed or was cancelled. 2023-02-16 09:29:04,306 [P3392/D2/T25] INFO Umbraco.Core.Publishing.PublishingStrategy - Content 'Landing Content' with Id '8075' will not be published because it's parent's publishing action failed or was cancelled. 2023-02-16 09:29:04,306 [P3392/D2/T25] INFO Umbraco.Core.Publishing.PublishingStrategy - Content 'Landing Content' with Id '8062' will not be published because it's parent's publishing action failed or was cancelled. 2023-02-16 09:29:04,307 [P3392/D2/T25] INFO Umbraco.Core.Publishing.PublishingStrategy - Content 'Landing Content' with Id '8060' will not be published because it's parent's publishing action failed or was cancelled. 2023-02-16 09:29:04,307 [P3392/D2/T25] INFO Umbraco.Core.Publishing.PublishingStrategy - Content 'Landing Content' with Id '8058' will not be published because it's parent's publishing action failed or was cancelled. 2023-02-16 09:29:04,308 [P3392/D2/T25] INFO Umbraco.Core.Publishing.PublishingStrategy - Content 'Landing Content' with Id '7026' will not be published because it's parent's publishing action failed or was cancelled. 2023-02-16 09:29:04,308 [P3392/D2/T25] INFO Umbraco.Core.Publishing.PublishingStrategy - Content 'Landing Content' with Id '7024' will not be published because it's parent's publishing action failed or was cancelled. 2023-02-16 09:29:04,308 [P3392/D2/T25] INFO Umbraco.Core.Publishing.PublishingStrategy - Content 'Landing Content' with Id '4931' will not be published because it's parent's publishing action failed or was cancelled. 2023-02-16 09:29:04,309 [P3392/D2/T25] INFO Umbraco.Core.Publishing.PublishingStrategy - Content 'Landing Content' with Id '4935' will not be published because it's parent's publishing action failed or was cancelled. 2023-02-16 09:29:04,309 [P3392/D2/T25] INFO Umbraco.Core.Publishing.PublishingStrategy - Content 'Landing Content' with Id '4933' will not be published because it's parent's publishing action failed or was cancelled. 2023-02-16 09:29:04,310 [P3392/D2/T25] INFO Umbraco.Core.Publishing.PublishingStrategy - Content 'Landing Content' with Id '4532' will not be published because it's parent's publishing action failed or was cancelled. 2023-02-16 09:29:04,310 [P3392/D2/T25] INFO Umbraco.Core.Publishing.PublishingStrategy - Content 'Landing Content' with Id '4530' will not be published because it's parent's publishing action failed or was cancelled. 2023-02-16 09:29:04,311 [P3392/D2/T25] INFO Umbraco.Core.Publishing.PublishingStrategy - Content 'Landing Content' with Id '4508' will not be published because it's parent's publishing action failed or was cancelled. 2023-02-16 09:29:04,311 [P3392/D2/T25] INFO Umbraco.Core.Publishing.PublishingStrategy - Content 'Landing Content' with Id '4506' will not be published because it's parent's publishing action failed or was cancelled. 2023-02-16 09:29:04,312 [P3392/D2/T25] INFO Umbraco.Core.Publishing.PublishingStrategy - Content 'Landing Content' with Id '4469' will not be published because it's parent's publishing action failed or was cancelled. 2023-02-16 09:29:04,312 [P3392/D2/T25] INFO Umbraco.Core.Publishing.PublishingStrategy - Content 'Landing Content' with Id '4470' will not be published because it's parent's publishing action failed or was cancelled. 2023-02-16 09:29:59,023 [P3392/D2/T28] ERROR Umbraco.Core.Persistence.UmbracoDatabase - Exception (f518a643). System.Data.SqlClient.SqlException (0x80131904): Execution Timeout Expired. The timeout period elapsed prior to completion of the operation or the server is not responding. ---> System.ComponentModel.Win32Exception (0x80004005): The wait operation timed out at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, 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.SqlDataReader.TrySetMetaData(_SqlMetaDataSet metaData, Boolean moreInfo) 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, TaskCompletionSource1 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.ExecuteReader(CommandBehavior behavior, String method) at Umbraco.Core.Persistence.PetaPocoCommandExtensions.<>cDisplayClass50.0() at Umbraco.Core.Persistence.FaultHandling.RetryPolicy.ExecuteAction[TResult](Func1 func) at Umbraco.Core.Persistence.Database.<Query>d__1151.MoveNext() ClientConnectionId:b49b17e9-552c-4e05-a6f3-3bdbe77113ef Error Number:-2,State:0,Class:11 2023-02-16 09:29:59,051 [P3392/D2/T28] ERROR Umbraco.Web.Scheduling.ScheduledPublishing - Failed (see exception). System.Data.SqlClient.SqlException (0x80131904): Execution Timeout Expired. The timeout period elapsed prior to completion of the operation or the server is not responding. ---> System.ComponentModel.Win32Exception (0x80004005): The wait operation timed out at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, 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.SqlDataReader.TrySetMetaData(_SqlMetaDataSet metaData, Boolean moreInfo) 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, TaskCompletionSource1 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.ExecuteReader(CommandBehavior behavior, String method) at Umbraco.Core.Persistence.PetaPocoCommandExtensions.<>cDisplayClass50.0() at Umbraco.Core.Persistence.FaultHandling.RetryPolicy.ExecuteAction[TResult](Func1 func) at Umbraco.Core.Persistence.Database.<Query>d__1151.MoveNext() at System.Collections.Generic.List1..ctor(IEnumerable1 collection)
    at System.Linq.Enumerable.ToList[TSource](IEnumerable1 source) at Umbraco.Core.Persistence.Repositories.ContentRepository.ProcessQuery(Sql sqlFull, PagingSqlQuery pagingSqlQuery, Boolean withCache, Boolean includeAllVersions) at Umbraco.Core.Persistence.Repositories.ContentRepository.PerformGetByQuery(IQuery1 query) at Umbraco.Core.Persistence.Repositories.RepositoryBase2.GetByQuery(IQuery1 query) at Umbraco.Core.Services.ContentService.GetContentForRelease() at Umbraco.Core.Publishing.ScheduledPublisher.CheckPendingAndProcess()
    at Umbraco.Web.Scheduling.ScheduledPublishing.PerformRun() ClientConnectionId:b49b17e9-552c-4e05-a6f3-3bdbe77113ef Error Number:-2,State:0,Class:11 2023-02-16 09:31:29,252 [P3392/D2/T47] ERROR Umbraco.Core.Persistence.UmbracoDatabase - Exception (a61037b0). System.Data.SqlClient.SqlException (0x80131904): Execution Timeout Expired. The timeout period elapsed prior to completion of the operation or the server is not responding. ---> System.ComponentModel.Win32Exception (0x80004005): The wait operation timed out at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, 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.SqlDataReader.TrySetMetaData(_SqlMetaDataSet metaData, Boolean moreInfo) 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, TaskCompletionSource1 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.ExecuteReader(CommandBehavior behavior, String method) at Umbraco.Core.Persistence.PetaPocoCommandExtensions.<>cDisplayClass50.0() at Umbraco.Core.Persistence.FaultHandling.RetryPolicy.ExecuteAction[TResult](Func1 func) at Umbraco.Core.Persistence.Database.<Query>d__1151.MoveNext() ClientConnectionId:853f2365-cb99-4cda-b72f-c4a34f5ad0ec Error Number:-2,State:0,Class:11 2023-02-16 09:31:29,276 [P3392/D2/T47] ERROR Umbraco.Web.Scheduling.ScheduledPublishing - Failed (see exception). System.Data.SqlClient.SqlException (0x80131904): Execution Timeout Expired. The timeout period elapsed prior to completion of the operation or the server is not responding. ---> System.ComponentModel.Win32Exception (0x80004005): The wait operation timed out at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, 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.SqlDataReader.TrySetMetaData(_SqlMetaDataSet metaData, Boolean moreInfo) 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, TaskCompletionSource1 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.ExecuteReader(CommandBehavior behavior, String method) at Umbraco.Core.Persistence.PetaPocoCommandExtensions.<>cDisplayClass50.0() at Umbraco.Core.Persistence.FaultHandling.RetryPolicy.ExecuteAction[TResult](Func1 func) at Umbraco.Core.Persistence.Database.<Query>d__1151.MoveNext() at System.Collections.Generic.List1..ctor(IEnumerable1 collection)
    at System.Linq.Enumerable.ToList[TSource](IEnumerable1 source) at Umbraco.Core.Persistence.Repositories.ContentRepository.ProcessQuery(Sql sqlFull, PagingSqlQuery pagingSqlQuery, Boolean withCache, Boolean includeAllVersions) at Umbraco.Core.Persistence.Repositories.ContentRepository.PerformGetByQuery(IQuery1 query) at Umbraco.Core.Persistence.Repositories.RepositoryBase2.GetByQuery(IQuery1 query) at Umbraco.Core.Services.ContentService.GetContentForRelease() at Umbraco.Core.Publishing.ScheduledPublisher.CheckPendingAndProcess()
    at Umbraco.Web.Scheduling.ScheduledPublishing.PerformRun() ClientConnectionId:853f2365-cb99-4cda-b72f-c4a34f5ad0ec Error Number:-2,State:0,Class:11

    I ran the Activity Monitor on the SQL server and here's the query that's causing the lock:

    (@0 nvarchar(40),@1 int,@2 datetime,@3 int)SELECT *
    FROM [cmsDocument]
    INNER JOIN [cmsContentVersion]
    ON [cmsDocument].[versionId] = [cmsContentVersion].[VersionId]
    INNER JOIN [cmsContent]
    ON [cmsContentVersion].[ContentId] = [cmsContent].[nodeId]
    INNER JOIN [umbracoNode]
    ON [cmsContent].[nodeId] = [umbracoNode].[id]
    INNER JOIN [cmsContentType]
    ON [cmsContentType].[nodeId] = [cmsContent].[contentType]
    WHERE (([umbracoNode].[nodeObjectType] = @0))
    AND ((NOT ([cmsDocument].[published] = @1) AND ([cmsDocument].[releaseDate] <= @2)))
    AND ([cmsDocument].[newest] = @3)
    ORDER BY ([cmsContentVersion].[VersionDate]) DESC
    , ([umbracoNode].[sortOrder])
    

    All attempts to mitigate the lock have failed. I've tried increasing the connection timeout in the connection string to 3600 seconds, but doing so just causes the query to be the victim of the deadlock. If I save and publish with this connection string, right after the lines about not publishing a node because it's parent's publishing action failed or were cancelled, I see:

    2023-02-15 17:12:47,785 [P6608/D2/T31] ERROR Umbraco.Core.Persistence.UmbracoDatabase - Exception (7746c8e8). System.Data.SqlClient.SqlException (0x80131904): Transaction (Process ID 53) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction. 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.SqlDataReader.TryHasMoreRows(Boolean& moreRows) at System.Data.SqlClient.SqlDataReader.TryReadInternal(Boolean setTimeout, Boolean& more) at System.Data.SqlClient.SqlDataReader.Read() at Umbraco.Core.Persistence.Database.<Query>d__1151.MoveNext() ClientConnectionId:ed553270-fa56-4554-945e-c0678bac9671 Error Number:1205,State:52,Class:13 2023-02-15 17:12:47,787 [P6608/D2/T31] ERROR Umbraco.Web.Scheduling.ScheduledPublishing - Failed (see exception). System.InvalidOperationException: This SqlTransaction has completed; it is no longer usable. at System.Data.SqlClient.SqlTransaction.ZombieCheck() at System.Data.SqlClient.SqlTransaction.Commit() at Umbraco.Core.Persistence.Database.CleanupTransaction() at Umbraco.Core.Persistence.Database.CompleteTransaction() at Umbraco.Core.Scoping.Scope.DisposeLastScope() at Umbraco.Core.Scoping.Scope.Dispose() at Umbraco.Core.Persistence.UnitOfWork.ScopeUnitOfWork.DisposeResources() at Umbraco.Core.DisposableObjectSlim.Dispose(Boolean disposing) at Umbraco.Core.DisposableObjectSlim.Dispose() at Umbraco.Core.Services.ContentService.GetContentForRelease() at Umbraco.Core.Publishing.ScheduledPublisher.CheckPendingAndProcess()
    at Umbraco.Web.Scheduling.ScheduledPublishing.PerformRun() 2023-02-15 17:19:22,192 [P6608/D2/T95] INFO umbraco.content - Save Xml to file... 2023-02-15 17:19:22,217 [P6608/D2/T95] INFO umbraco.content - Saved Xml to file. 2023-02-15 17:38:50,000 [P6608/D2/T260] INFO Umbraco.Core.Logging.OwinLogger - Event Id: 0, state: User logged will be logged out due to timeout: [email protected], IP Address: 75.85.55.168 2023-02-15 18:19:18,410 [P6608/D2/T141] INFO Umbraco.Core.Security.BackOfficeSignInManager - Event Id: 0, state: Login attempt succeeded for username [email protected] from IP address 75.85.55.168

    The application logs me out due to the session timing out before I can even see if the job completes in the UI.

    After noticing multiple DB connections being opened despite being the only active user on the site, I tried adding "Pooling=false" into the connection string. While that did limit the number of processes tied to our DB user, the issue still persists.

    It's important to note that this behavior cannot be reproduced on my local installation. Figures, right? Aside from certain configurations, the only difference between the 2 environments is the content, particularly the volume of content. Staging has significantly more content nodes than my installation but not nearly enough that I'd expect the DB to get locked up during publication.

    Has anyone else experienced this issue? If so, how did you resolve it?

Please Sign in or register to post replies

Write your reply to:

Draft