umbraco / Umbraco.Workflow.Issues

Public issue tracker for Umbraco Workflow
1 stars 0 forks source link

Error thrown when using Request publish on a content node #79

Closed bruceanewton closed 1 month ago

bruceanewton commented 2 months ago

Bug Summary

We are in the process of converting our Umbraco V8 site to V13, which is nearing completion. However, we have an issue when trying to use workflows on the new site. When using 'Request publish...' on a content node, the Workflow approval request dialog is displayed; I then enter a change comment and use the dialogue 'Request publish' button - and an error is displayed 'Error: An error occurred initiating the workflow on node 5472'. At this point a record has been created in the database WorkflowTaskInstance table, but nothing in the WorkflowInstance table, and the content item does not indicate that it is in a workflow.

image

image

Reproduction

Specifics

Umbraco version: 13.3.2 Umbraco.Workflow version: 13.1.0 Chrome browser version 122.0.6261.129, site running under IIS on Windows 10 (although the same issues occur when running directly from the Visual Studio IDE)

This is the corresponding detailed error written to the Umbraco trace log:

{
    "@t": "2024-08-26T10:59:52.9763405Z",
    "@mt": "Exception ({InstanceId}).",
    "@l": "Error",
    "@x": "System.InvalidOperationException: There is already an open DataReader associated with this Connection which must be closed first.\r\n   
    at Microsoft.Data.SqlClient.SqlCommand.ValidateCommand(Boolean isAsync, String method)\r\n   
    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)\r\n   
    at Microsoft.Data.SqlClient.SqlCommand.ExecuteScalar()\r\n   at Umbraco.Cms.Infrastructure.Persistence.FaultHandling.RetryPolicy.ExecuteAction[TResult](Func`1 func)\r\n   
    at System.Data.Common.DbCommand.ExecuteScalarAsync(CancellationToken cancellationToken)\r\n--- End of stack trace from previous location ---\r\n   
    at NPoco.Database.ExecutionHookAsync[T](Func`1 action)\r\n   at NPoco.Database.ExecuteScalarHelperAsync(DbCommand cmd)\r\n   
    at NPoco.Database.InsertAsyncImp[T](PocoData pocoData, String tableName, String primaryKeyName, Boolean autoIncrement, T poco, Boolean sync)\r\n   
    at Umbraco.Workflow.Core.Repositories.Implement.Database.Insert[T](Object model)\r\n   
    at Umbraco.Workflow.Core.Repositories.Implement.BaseWorkflowRepository`1.Insert(TEntity entity)\r\n   
    at Umbraco.Workflow.Core.Services.Implement.InstancesService.Insert(WorkflowInstancePoco instance)\r\n   
    at Umbraco.Workflow.Core.Processes.WorkflowProcess.InitiateWorkflow(InitiateWorkflowRequestModel model)\r\n   
    at Umbraco.Workflow.Web.Controllers.ActionsController.Initiate(InitiateWorkflowRequestModel model)",
    "@tr": "8a339877f883ca314b67c52a2ffa3081",
    "@sp": "2f5eb07a25ff2ab6",
    "InstanceId": "a7b9c069",
    "SourceContext": "Umbraco.Cms.Infrastructure.Persistence.UmbracoDatabase",
    "ActionId": "03529417-b2cb-442f-bdff-05fdcc450500",
    "ActionName": "Umbraco.Workflow.Web.Controllers.ActionsController.Initiate (Umbraco.Workflow.Web)",
    "RequestId": "8000000a-000a-f300-b63f-84710c7967bb",
    "RequestPath": "/umbraco/backoffice/workflow/actions/initiate",
    "ProcessId": 57324,
    "ProcessName": "w3wp",
    "ThreadId": 73,
    "ApplicationId": "6b5d00dc72ce5284e0f562842f9308a3cff85b97",
    "MachineName": "65CP373",
    "Log4NetLevel": "ERROR",
    "HttpRequestId": "2564d4e3-d21e-4a29-8869-a2621a01c89d",
    "HttpRequestNumber": 4,
    "HttpSessionId": "e6392383-0f56-bd41-f82f-059af8bafcdd"
}

The site currently has around 60,000 content nodes. We currently have 167 workflow user groups, one of which is the 'Final Approvers' group that has workflow configured on 415 nodes. All other groups have 40 or less workflow nodes. I have tried many permutations of workflow config and our website code to try to find the source of the issue, but to no avail. One of the scenarios I have tried is as follows:

I removed all workflow configuration and history (via sql script in the database), then created a single group (through the workflow back-office UI) which i then applied to a single node. Request publish on this node then completed successfully. I then used a sql script to set up workflow on this single group, to the same 415 nodes as the existing 'Final Approvers' group. Then, tried to request publish on one of the nodes, and received the same error as above. I gradually reduced the number of workflow nodes until i got to around 60 nodes, when the workflow began completing successfully again.

Thinking that this may be the failing scenario, i tried to reproduce this in a vanilla Umbraco 13 site - used the ContentService to create over 30,000 content items and set up workflow (via UI and sql script) on increasing numbers of nodes, up to the point where workflow was set for every content node - but unfortunately i have not been able to reproduce the issue in the vanilla site.

So at this point I am still not completely sure whether the problem lies within the workflow code, or perhaps something that is happening specific to our site (although i have commented out anything that i thought may affect this, but without success), but hoping you may be able to give some assistance.

Steps to reproduce

As above, I haven't been able to reproduce the issue on a base Umbraco v13 site - not for lack of trying! Not sure where to go next since diagnosing this without source code is proving difficult.

On our site:

Expected result

The expected result is achieved when i remove all of the existing workflow from the site and set up a single workflow group applied on a single node with a stage 1 workflow : when the 'Request publish' button is used, the following appears, and the node is enrolled into workflow:

image

Actual result

As above, the current workflow configuration is failing.

Thanks!


This item has been added to our backlog AB#43580

nathanwoulfe commented 2 months ago

Hey @bruceanewton, long time no chat, hope you're doing well.

I'll pick this up and start digging, let me know if you make any progress in your investigations. Thanks for the detailed repro steps, will let you know if I'm able to reproduce.

bruceanewton commented 2 months ago

Hi @nathanwoulfe, yes longer than it seems! Doing well thanks, hope you are too. Thanks heaps for that, I would have liked to repro on a vanilla site but it's hard to reproduce the complexity of our site, without just reproducing our site! If you need anything further please let me know, otherwise I'll let you know if i make any further discoveries.

nathanwoulfe commented 2 months ago

@bruceanewton I haven't (yet) been able to reproduce this - similar to your example, I've populated a v13 site with thousands of nodes, everything works as expected.

Error suggests another process is not correctly disposing the DataReader, which then results in the error from the Workflow action, rather than the error being directly caused by Workflow. Persistence in Workflow is via Umbraco's database abstraction, so there's no direct references to SQL commands, connections, readers etc. Database access takes place only in the various repositories, where I've checked scopes are managed correctly, so I'm fairly confident Workflow isn't leaving a reader open, directly or indirectly.

Curious as to what happens if you turn email notifications off. Emails are sent before the new workflow is saved (which in hindsight probably shouldn't be the case and needs to be revisited), and despite being async, is not awaited in the calling scope, so could possibly be responsible for this issue...

bruceanewton commented 2 months ago

@nathanwoulfe thanks for the feedback, and I think you've nailed it ... when I turn off 'Send notifications', 'Request publish' initiation of workflow on changed documents is working fine; as soon as I turn notifications back on, they fail as above. So yeah, may need to revisit that, and really appreciate your efforts with getting to the bottom of this :-)

nathanwoulfe commented 2 months ago

@bruceanewton that's a partial win at least, now need to work out how to fix it...

nathanwoulfe commented 1 month ago

Hey @bruceanewton in case you aren't watching the Nuget feed (why would anyone?), this was released last week and should resolve the issue. Longer term plan is to move email to a proper queue, but for now I think it's ok.

bruceanewton commented 1 month ago

Hey thanks for that @nathanwoulfe, I saw the updated documentation in the Umbraco Workflow release notes (not watching the nuget feed!). It was certainly working well in pre-release testing and I should get to the official release shortly. Thanks for all of your help.