Deadlocking on insert under load testing

[BazzaPreece]

We've been load testing against Umbraco forms this week and we've come across a lot of deadlocks which looks to have come from the insert command of the forms.

Looking into it a bit further, it looks like you are inserting records in Umbraco.Forms.Data.Storage with the method InsertRecord. This method seems to be performing the insert, but it's then also looping through the record to build a dictionary for a RecordFields property that is ignored as far as the database goes. Following the looping I presume that the database connection is closed as there is a call to scope.Complete().

Would it be possible to review this code please as if I am reading it correctly, it appears that the database connection is being held open longer than necessary. It feels to me that it should be possible to move the scope.Complete(); to be directly after the scope.get_Database().Insert(record); and then the more "internal" stuff of creating the dictionary of field guids/values could be done afterwards. Obviously you guys will know a lot better than me about this, but it was just a thought while picking through our load test results.

By the way, we're currently running with Umbraco 7.14 and Umbraco forms 7.1.1.

[nul800sebastiaan]

Sure, updating that code might alleviate the problem somewhat, we'll have a look.

[umbrabot]

Hiya @BazzaPreece,

Just wanted to let you know that we noticed that this issue got a bit stale and might not be relevant any more.

We will close this issue for now but we're happy to open it up again if you think it's still relevant (for example: it's a feature request that's not yet implemented, or it's a bug that's not yet been fixed).

To open it this issue up again, you can write @umbrabot still relevant in a new comment as the first line. It would be super helpful for us if on the next line you could let us know why you think it's still relevant.

For example:

@umbrabot still relevant This bug can still be reproduced in version x.y.z

This will reopen the issue in the next few hours.

Thanks, from your friendly Umbraco GitHub bot :robot: :slightly_smiling_face:

[electricsheep]

@umbrabot still relevant

We are seeing this issue occasionally on Umbraco Forms 7.4.2 with a form being submitted under heavy load. Error message logged:

Umbraco.Core.UmbracoApplicationBase - An unhandled exception occurred System.Data.SqlClient.SqlException (0x80131904): Transaction (Process ID 101) 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.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.PetaPocoCommandExtensions.<>c__DisplayClass2_0.b__0() at Umbraco.Core.Persistence.FaultHandling.RetryPolicy.ExecuteAction[TResult](Func1 func) at Umbraco.Core.Persistence.Database.Execute(String sql, Object[] args) at Umbraco.Forms.Data.Storage.RecordStorage.InsertRecord(Record record, Form form) at Umbraco.Forms.Web.Services.RecordService.StoreRecord(Record record, Form form) at Umbraco.Forms.Web.Services.RecordService.Approve(Record record, Form form) at Umbraco.Forms.Web.Services.RecordService.Submit(Record record, Form form) at Umbraco.Forms.Web.Controllers.UmbracoFormsController.SubmitForm(Form form, FormViewModel model, Dictionary2 state, ControllerContext context) at Umbraco.Forms.Web.Controllers.UmbracoFormsController.GoForward(Form form, FormViewModel model, Dictionary2 state) at Umbraco.Forms.Web.Controllers.UmbracoFormsController.HandleForm(FormViewModel model, Boolean captchaIsValid)

I will upgrade to the latest v7 of Forms although I didn't see anything in the release notes that mentions any fix around this.

[umbrabot]

Hiya @BazzaPreece,

Just wanted to let you know that we noticed that this issue got a bit stale and might not be relevant any more.

We will close this issue for now but we're happy to open it up again if you think it's still relevant (for example: it's a feature request that's not yet implemented, or it's a bug that's not yet been fixed).

To open it this issue up again, you can write @umbrabot still relevant in a new comment as the first line. It would be super helpful for us if on the next line you could let us know why you think it's still relevant.

For example:

@umbrabot still relevant This bug can still be reproduced in version x.y.z

This will reopen the issue in the next few hours.

Thanks, from your friendly Umbraco GitHub bot :robot: :slightly_smiling_face:

[robertjf]

@umbrabot still relevant

We're seeing this on a new build - Umbraco 10.4.2 and Forms 10.3.1 - this is a load balanced site, and we're currently performing load testing on the forms.

We have currently two azure app instances - one SchedulePublisher and the other a Subscriber. The Subscriber is the only one being tested currently, and we've only got one instance for initial testing/benchmarking.

Reported error is as follows:

Connection id ""0HMPRQ6PRPGU9"", Request id ""0HMPRQ6PRPGU9:0000001C"": An unhandled exception was thrown by the application.
--
Microsoft.Data.SqlClient.SqlException (0x80131904): Transaction (Process ID 85) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction.
    at Microsoft.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)    at Microsoft.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)
    at Microsoft.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)
    at Microsoft.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString, Boolean isInternal, Boolean forDescribeParameterEncryption, Boolean shouldCacheForAlwaysEncrypted)
    at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean isAsync, Int32 timeout, Task& task, Boolean asyncWrite, Boolean inRetry, SqlDataReader ds, Boolean describeParameterEncryptionRequest)
    at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, TaskCompletionSource`1 completion, Int32 timeout, Task& task, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry, String method)
    at Microsoft.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(TaskCompletionSource`1 completion, Boolean sendToPipe, Int32 timeout, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry, String methodName)
    at Microsoft.Data.SqlClient.SqlCommand.ExecuteNonQuery()
    at Umbraco.Cms.Infrastructure.Persistence.FaultHandling.RetryPolicy.ExecuteAction[TResult](Func`1 func)
    at NPoco.Database.ExecuteNonQueryHelper(DbCommand cmd)    at NPoco.Database.Execute(String sql, CommandType commandType, Object[] args)
    at Umbraco.Forms.Core.Data.Storage.RecordFieldValueStorage.DeleteAllRecordFieldValues(IList`1 recordIds)
    at Umbraco.Forms.Core.Data.Storage.RecordStorage.UpdateRecord(Record record, Form form, Nullable`1 userId)
    at Umbraco.Forms.Core.Data.Storage.RecordStorage.UpdateRecord(Record record, Form form)
    at Umbraco.Forms.Core.Services.RecordService.StoreRecord(Record record, Form form)
    at Umbraco.Forms.Core.Services.RecordService.Approve(Record record, Form form, Boolean editingRecord)
    at Umbraco.Forms.Core.Services.RecordService.Submit(Record record, Form form)
    at Umbraco.Forms.Web.Controllers.UmbracoFormsController.SubmitForm(Form form, FormViewModel model, IDictionary`2 formFieldValuesForConditions)
    at Umbraco.Forms.Web.Controllers.UmbracoFormsController.HandleForm(FormViewModel model)

...

[AndyButland]

There'll be an optimization in the next minor releases of Forms 10+ that will provide some improvement here. There are cases where we were resaving the form submission after the approval workflows run, in case those workflows have made any changes to the record. However, if there are no approval workflows, we can skip this second save, so will be doing that moving forward.

[robertjf]

@AndyButland a little more information from the client:

I think the issues with Umbraco Forms are concerning even under low load. We triggered deadlocks, 500 errors and the application becoming unavailable with just three human users each submitting a form concurrently (with SMTP workflows turned off). This is not happening just with fake users in heavy load tests or with SMTP bottlenecks.