HOME DOCUMENTATION DOWNLOADS

Workflow invoked automatically from work queue ends up with timeout

Build 2021.1.0.2248.

I have following setup - work queue automatically invokes a workflow. This workflow loads an entity, updates a record, stores it and invokes sub workflow that tries to load same record to do further modifications. When invoked automatically from the work queue, it fails with database access timeout. The workflow log looks like this:

2021-10-05 16:25:45,040 [15] DEBUG Origam.Workflow.WorkflowEngine - ---------------------------------------------------------------------------------------
2021-10-05 16:25:45,040 [15] DEBUG Origam.Workflow.WorkflowEngine - ------------------- Starting workflow: Order_CheckParsingProgress
2021-10-05 16:25:45,040 [15] DEBUG Origam.Workflow.WorkflowEngine - ------------------- Transaction ID: 82f759ea-7dcd-4e22-a240-58afb19343d4
2021-10-05 16:25:45,040 [15] DEBUG Origam.Workflow.WorkflowEngine - ---------------------------------------------------------------------------------------
2021-10-05 16:25:45,040 [15] DEBUG Origam.Workflow.WorkflowEngine - Initializing data store: PartnerOrder_Overview
2021-10-05 16:25:45,041 [15] DEBUG Origam.Workflow.WorkflowEngine - Initializing data store: WorkQueueEntry
2021-10-05 16:25:45,042 [15] DEBUG Origam.Workflow.WorkflowEngine - Passing input context
2021-10-05 16:25:45,042 [15] INFO Origam.Workflow.WorkflowEngine - Merging context 'WorkQueueEntry'
2021-10-05 16:25:45,042 [15] INFO Origam.Workflow.WorkflowEngine - Finished merging context 'WorkQueueEntry'
2021-10-05 16:25:45,042 [15] DEBUG Origam.Workflow.WorkflowEngine - ---------------------------------------------------------------------------------------
2021-10-05 16:25:45,042 [15] DEBUG Origam.Workflow.WorkflowEngine - Starting ServiceMethodCallEngineTask: 0100_LoadOrder
2021-10-05 16:25:45,046 [15] INFO Origam.Workflow.WorkflowEngine - Merging context 'PartnerOrder_Overview', Step 'Order_CheckParsingProgress/0100_LoadOrder'
2021-10-05 16:25:45,047 [15] INFO Origam.Workflow.WorkflowEngine - Finished merging context 'PartnerOrder_Overview', Step 'Order_CheckParsingProgress/0100_LoadOrder'
2021-10-05 16:25:45,047 [15] DEBUG Origam.Workflow.WorkflowEngine - ServiceMethodCallEngineTask 0100_LoadOrder finished successfully.
2021-10-05 16:25:45,047 [15] DEBUG Origam.Workflow.WorkflowEngine - ---------------------------------------------------------------------------------------
2021-10-05 16:25:45,047 [15] DEBUG Origam.Workflow.WorkflowEngine - Starting ServiceMethodCallEngineTask: 0200_CheckStatus
2021-10-05 16:25:45,058 [15] INFO Origam.Workflow.WorkflowEngine - Merging context 'PartnerOrder_Overview', Step 'Order_CheckParsingProgress/0200_CheckStatus'
2021-10-05 16:25:45,058 [15] INFO Origam.Workflow.WorkflowEngine - Finished merging context 'PartnerOrder_Overview', Step 'Order_CheckParsingProgress/0200_CheckStatus'
2021-10-05 16:25:45,058 [15] DEBUG Origam.Workflow.WorkflowEngine - ServiceMethodCallEngineTask 0200_CheckStatus finished successfully.
2021-10-05 16:25:45,058 [15] DEBUG Origam.Workflow.WorkflowEngine - ---------------------------------------------------------------------------------------
2021-10-05 16:25:45,058 [15] DEBUG Origam.Workflow.WorkflowEngine - Starting ServiceMethodCallEngineTask: 0300_SaveOrder
2021-10-05 16:25:45,095 [15] INFO Origam.Workflow.WorkflowEngine - Merging context 'PartnerOrder_Overview', Step 'Order_CheckParsingProgress/0300_SaveOrder'
2021-10-05 16:25:45,095 [15] INFO Origam.Workflow.WorkflowEngine - Finished merging context 'PartnerOrder_Overview', Step 'Order_CheckParsingProgress/0300_SaveOrder'
2021-10-05 16:25:45,095 [15] DEBUG Origam.Workflow.WorkflowEngine - ServiceMethodCallEngineTask 0300_SaveOrder finished successfully.
2021-10-05 16:25:45,095 [15] DEBUG Origam.Workflow.WorkflowEngine - ---------------------------------------------------------------------------------------
2021-10-05 16:25:45,096 [15] DEBUG Origam.Workflow.WorkflowEngine - Starting WorkflowCallEngineTask: 0400_UpdateReportData
2021-10-05 16:25:45,096 [15] DEBUG Origam.Workflow.WorkflowEngine - ---------------------------------------------------------------------------------------
2021-10-05 16:25:45,096 [15] DEBUG Origam.Workflow.WorkflowEngine - ------------------- Starting workflow: Order_UpdateReportData
2021-10-05 16:25:45,096 [15] DEBUG Origam.Workflow.WorkflowEngine - ------------------- Transaction ID: 
2021-10-05 16:25:45,096 [15] DEBUG Origam.Workflow.WorkflowEngine - ---------------------------------------------------------------------------------------
2021-10-05 16:25:45,096 [15] DEBUG Origam.Workflow.WorkflowEngine - Initializing data store: ReportOrderConfirmation
2021-10-05 16:25:45,097 [15] DEBUG Origam.Workflow.WorkflowEngine - Initializing data store: Order_SendConfirmationEmail
2021-10-05 16:25:45,097 [15] DEBUG Origam.Workflow.WorkflowEngine - Initializing data store: orderId
2021-10-05 16:25:45,097 [15] DEBUG Origam.Workflow.WorkflowEngine - Passing input context
2021-10-05 16:25:45,097 [15] INFO Origam.Workflow.WorkflowEngine - Merging context 'orderId'
2021-10-05 16:25:45,097 [15] INFO Origam.Workflow.WorkflowEngine - Finished merging context 'orderId'
2021-10-05 16:25:45,097 [15] DEBUG Origam.Workflow.WorkflowEngine - ---------------------------------------------------------------------------------------
2021-10-05 16:25:45,097 [15] DEBUG Origam.Workflow.WorkflowEngine - Starting ServiceMethodCallEngineTask: 01_LoadOrder
2021-10-05 16:26:45,095 [15] ERROR Origam.DA.Service.DataLoader - Timeout expired.  The timeout period elapsed prior to completion of the operation or the server is not responding., SQL: SELECT [PartnerOrder].[refPartnerId] AS [refPartnerId], (SELECT TOP 1 [BusinessPartner].[Name] AS [Name] FROM [BusinessPartner] AS [BusinessPartner] WHERE  (  ([BusinessPartner].[Id] = [PartnerOrder].[refBusinessPartnerId])) ) AS [BusinessPartner], (SELECT TOP 1 [BusinessPartner].[refLanguageId] AS [refLanguageId] FROM [BusinessPartner] AS [BusinessPartner] WHERE  (  ([BusinessPartner].[Id] = [PartnerOrder].[refBusinessPartnerId])) ) AS [BusinessPartner_refLanguageId], [PartnerOrder].[RecordUpdated] AS [RecordUpdated], [PartnerOrder].[RecordCreated] AS [RecordCreated], [PartnerOrder].[Id] AS [Id], [PartnerOrder].[RecordUpdatedBy] AS [RecordUpdatedBy], [PartnerOrder].[RecordCreatedBy] AS [RecordCreatedBy], [PartnerOrder].[refCompensationId] AS [refCompensationId], [PartnerOrder].[refOrderingStatusId] AS [refOrderingStatusId], [PartnerOrder].[refOrderStatusId] AS [refOrderStatusId], [PartnerOrder].[refBusinessPartnerDeliveryAddress1Id] AS [refBusinessPartnerDeliveryAddress1Id], (SELECT TOP 1 [BusinessPartner].[Title] AS [Title] FROM [BusinessPartner] AS [BusinessPartner] WHERE  (  ([BusinessPartner].[Id] = [PartnerOrder].[refBusinessPartnerId])) ) AS [BusinessPartner_Title], [PartnerOrder].[refProducerId] AS [refProducerId], [PartnerOrder].[ProducerCompensationDate] AS [ProducerCompensationDate], [PartnerOrder].[refBusinessPartnerDeliveryAddress4Id] AS [refBusinessPartnerDeliveryAddress4Id], [PartnerOrder].[OrderingTimestamp] AS [OrderingTimestamp], [PartnerOrder].[ErrorMessage] AS [ErrorMessage], [PartnerOrder].[refBusinessPartnerDeliveryAddress3Id] AS [refBusinessPartnerDeliveryAddress3Id], [PartnerOrder].[refBusinessPartnerId] AS [refBusinessPartnerId], [PartnerOrder].[refBusinessPartnerDeliveryAddress2Id] AS [refBusinessPartnerDeliveryAddress2Id], [PartnerOrder].[Timestamp] AS [Timestamp], [PartnerOrder].[ProductionTimestamp] AS [ProductionTimestamp], [PartnerOrder].[refPartnerProjectId] AS [refPartnerProjectId], [PartnerOrder].[Number] AS [Number], [PartnerOrder].[refBusinessPartnerDeliveryAddress5Id] AS [refBusinessPartnerDeliveryAddress5Id], [PartnerOrder].[Remarks] AS [Remarks], (SELECT TOP 1 [BusinessPartner].[UserEmail] AS [UserEmail] FROM [BusinessPartner] AS [BusinessPartner] WHERE  (  ([BusinessPartner].[Id] = [PartnerOrder].[refBusinessPartnerId])) ) AS [UserEmail] FROM [PartnerOrder] AS [PartnerOrder] WHERE  (  (@PartnerOrder_parId = [PartnerOrder].[Id]))
System.Data.SqlClient.SqlException (0x80131904): Timeout expired.  The timeout period elapsed prior to completion of the operation or the server is not responding.
 ---> System.ComponentModel.Win32Exception (258): The wait operation timed out.
   at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)
   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.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)
   at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async, Int32 timeout, Task& task, Boolean asyncWrite, SqlDataReader ds)
   at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method)
   at System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior)
   at System.Data.SqlClient.SqlCommand.ExecuteDbDataReader(CommandBehavior behavior)
   at System.Data.Common.DbCommand.System.Data.IDbCommand.ExecuteReader(CommandBehavior behavior)
   at System.Data.Common.DbDataAdapter.FillInternal(DataSet dataset, DataTable[] datatables, Int32 startRecord, Int32 maxRecords, String srcTable, IDbCommand command, CommandBehavior behavior)
   at System.Data.Common.DbDataAdapter.Fill(DataSet dataSet, Int32 startRecord, Int32 maxRecords, String srcTable, IDbCommand command, CommandBehavior behavior)
   at System.Data.Common.DbDataAdapter.Fill(DataSet dataSet)
   at Origam.DA.Service.DataLoader.Fill() in D:\a\1\s\origam-source\Origam.DA.Service\AbstractSqlDataService.cs:line 118
ClientConnectionId:2181a611-66fe-4b9c-87c6-19f43e4a3996
Error Number:-2,State:0,Class:11
2021-10-05 16:26:45,102 [15] ERROR Origam.Workflow.WorkflowEngine - ServiceMethodCallTask 01_LoadOrder failed.
2021-10-05 16:26:45,106 [15] ERROR Origam.Workflow.WorkflowEngine - Fehler beim Laden der Daten von der Tabelle 'PartnerOrder' in die Instanz 'PartnerOrder'
. Nachricht: Timeout expired.  The timeout period elapsed prior to completion of the operation or the server is not responding. Beim Aktualisieren der Daten ist ein Ausnahmefall aufgetreten.
Origam.OrigamException: Fehler beim Laden der Daten von der Tabelle 'PartnerOrder' in die Instanz 'PartnerOrder'
. Nachricht: Timeout expired.  The timeout period elapsed prior to completion of the operation or the server is not responding. Beim Aktualisieren der Daten ist ein Ausnahmefall aufgetreten.
 ---> Origam.UserOrigamException: Fehler beim Laden der Daten von der Tabelle 'PartnerOrder' in die Instanz 'PartnerOrder'
. Nachricht: Timeout expired.  The timeout period elapsed prior to completion of the operation or the server is not responding. Beim Aktualisieren der Daten ist ein Ausnahmefall aufgetreten.
 ---> System.Data.SqlClient.SqlException (0x80131904): Timeout expired.  The timeout period elapsed prior to completion of the operation or the server is not responding.
 ---> System.ComponentModel.Win32Exception (258): The wait operation timed out.
   at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)
   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.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)
   at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async, Int32 timeout, Task& task, Boolean asyncWrite, SqlDataReader ds)
   at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method)
   at System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior)
   at System.Data.SqlClient.SqlCommand.ExecuteDbDataReader(CommandBehavior behavior)
   at System.Data.Common.DbCommand.System.Data.IDbCommand.ExecuteReader(CommandBehavior behavior)
   at System.Data.Common.DbDataAdapter.FillInternal(DataSet dataset, DataTable[] datatables, Int32 startRecord, Int32 maxRecords, String srcTable, IDbCommand command, CommandBehavior behavior)
   at System.Data.Common.DbDataAdapter.Fill(DataSet dataSet, Int32 startRecord, Int32 maxRecords, String srcTable, IDbCommand command, CommandBehavior behavior)
   at System.Data.Common.DbDataAdapter.Fill(DataSet dataSet)
   at Origam.DA.Service.DataLoader.Fill() in D:\a\1\s\origam-source\Origam.DA.Service\AbstractSqlDataService.cs:line 118
ClientConnectionId:2181a611-66fe-4b9c-87c6-19f43e4a3996
Error Number:-2,State:0,Class:11
   --- End of inner exception stack trace ---

But when the workflow is invoked manually via action button, it works correctly:

2021-10-05 16:30:04,429 [30] DEBUG Origam.Workflow.WorkflowEngine - ---------------------------------------------------------------------------------------
2021-10-05 16:30:04,429 [30] DEBUG Origam.Workflow.WorkflowEngine - ------------------- Starting workflow: Order_CheckParsingProgress
2021-10-05 16:30:04,429 [30] DEBUG Origam.Workflow.WorkflowEngine - ------------------- Transaction ID: 
2021-10-05 16:30:04,429 [30] DEBUG Origam.Workflow.WorkflowEngine - ---------------------------------------------------------------------------------------
2021-10-05 16:30:04,431 [30] DEBUG Origam.Workflow.WorkflowEngine - Initializing data store: PartnerOrder_Overview
2021-10-05 16:30:04,436 [30] DEBUG Origam.Workflow.WorkflowEngine - Initializing data store: WorkQueueEntry
2021-10-05 16:30:04,442 [30] DEBUG Origam.Workflow.WorkflowEngine - Passing input context
2021-10-05 16:30:04,442 [30] INFO Origam.Workflow.WorkflowEngine - Merging context 'WorkQueueEntry'
2021-10-05 16:30:04,442 [30] INFO Origam.Workflow.WorkflowEngine - Finished merging context 'WorkQueueEntry'
2021-10-05 16:30:04,443 [30] DEBUG Origam.Workflow.WorkflowEngine - ---------------------------------------------------------------------------------------
2021-10-05 16:30:04,443 [30] DEBUG Origam.Workflow.WorkflowEngine - Starting ServiceMethodCallEngineTask: 0100_LoadOrder
2021-10-05 16:30:04,449 [30] INFO Origam.Workflow.WorkflowEngine - Merging context 'PartnerOrder_Overview', Step 'Order_CheckParsingProgress/0100_LoadOrder'
2021-10-05 16:30:04,449 [30] INFO Origam.Workflow.WorkflowEngine - Finished merging context 'PartnerOrder_Overview', Step 'Order_CheckParsingProgress/0100_LoadOrder'
2021-10-05 16:30:04,449 [30] DEBUG Origam.Workflow.WorkflowEngine - ServiceMethodCallEngineTask 0100_LoadOrder finished successfully.
2021-10-05 16:30:04,449 [30] DEBUG Origam.Workflow.WorkflowEngine - ---------------------------------------------------------------------------------------
2021-10-05 16:30:04,449 [30] DEBUG Origam.Workflow.WorkflowEngine - Starting ServiceMethodCallEngineTask: 0200_CheckStatus
2021-10-05 16:30:04,452 [30] INFO Origam.Workflow.WorkflowEngine - Merging context 'PartnerOrder_Overview', Step 'Order_CheckParsingProgress/0200_CheckStatus'
2021-10-05 16:30:04,452 [30] INFO Origam.Workflow.WorkflowEngine - Finished merging context 'PartnerOrder_Overview', Step 'Order_CheckParsingProgress/0200_CheckStatus'
2021-10-05 16:30:04,452 [30] DEBUG Origam.Workflow.WorkflowEngine - ServiceMethodCallEngineTask 0200_CheckStatus finished successfully.
2021-10-05 16:30:04,452 [30] DEBUG Origam.Workflow.WorkflowEngine - ---------------------------------------------------------------------------------------
2021-10-05 16:30:04,452 [30] DEBUG Origam.Workflow.WorkflowEngine - Starting ServiceMethodCallEngineTask: 0300_SaveOrder
2021-10-05 16:30:04,499 [30] INFO Origam.Workflow.WorkflowEngine - Merging context 'PartnerOrder_Overview', Step 'Order_CheckParsingProgress/0300_SaveOrder'
2021-10-05 16:30:04,499 [30] INFO Origam.Workflow.WorkflowEngine - Finished merging context 'PartnerOrder_Overview', Step 'Order_CheckParsingProgress/0300_SaveOrder'
2021-10-05 16:30:04,499 [30] DEBUG Origam.Workflow.WorkflowEngine - ServiceMethodCallEngineTask 0300_SaveOrder finished successfully.
2021-10-05 16:30:04,499 [30] DEBUG Origam.Workflow.WorkflowEngine - ---------------------------------------------------------------------------------------
2021-10-05 16:30:04,499 [30] DEBUG Origam.Workflow.WorkflowEngine - Starting WorkflowCallEngineTask: 0400_UpdateReportData
2021-10-05 16:30:04,500 [30] DEBUG Origam.Workflow.WorkflowEngine - ---------------------------------------------------------------------------------------
2021-10-05 16:30:04,500 [30] DEBUG Origam.Workflow.WorkflowEngine - ------------------- Starting workflow: Order_UpdateReportData
2021-10-05 16:30:04,500 [30] DEBUG Origam.Workflow.WorkflowEngine - ------------------- Transaction ID: 
2021-10-05 16:30:04,500 [30] DEBUG Origam.Workflow.WorkflowEngine - ---------------------------------------------------------------------------------------
2021-10-05 16:30:04,500 [30] DEBUG Origam.Workflow.WorkflowEngine - Initializing data store: ReportOrderConfirmation
2021-10-05 16:30:04,513 [30] DEBUG Origam.Workflow.WorkflowEngine - Initializing data store: Order_SendConfirmationEmail
2021-10-05 16:30:04,523 [30] DEBUG Origam.Workflow.WorkflowEngine - Initializing data store: orderId
2021-10-05 16:30:04,523 [30] DEBUG Origam.Workflow.WorkflowEngine - Passing input context
2021-10-05 16:30:04,523 [30] INFO Origam.Workflow.WorkflowEngine - Merging context 'orderId'
2021-10-05 16:30:04,523 [30] INFO Origam.Workflow.WorkflowEngine - Finished merging context 'orderId'
2021-10-05 16:30:04,523 [30] DEBUG Origam.Workflow.WorkflowEngine - ---------------------------------------------------------------------------------------
2021-10-05 16:30:04,523 [30] DEBUG Origam.Workflow.WorkflowEngine - Starting ServiceMethodCallEngineTask: 01_LoadOrder
2021-10-05 16:30:04,529 [30] INFO Origam.Workflow.WorkflowEngine - Merging context 'Order_SendConfirmationEmail', Step 'Order_UpdateReportData/01_LoadOrder'
2021-10-05 16:30:04,530 [30] INFO Origam.Workflow.WorkflowEngine - Finished merging context 'Order_SendConfirmationEmail', Step 'Order_UpdateReportData/01_LoadOrder'
2021-10-05 16:30:04,530 [30] DEBUG Origam.Workflow.WorkflowEngine - ServiceMethodCallEngineTask 01_LoadOrder finished successfully.
2021-10-05 16:30:04,530 [30] DEBUG Origam.Workflow.WorkflowEngine - ---------------------------------------------------------------------------------------
2021-10-05 16:30:04,530 [30] DEBUG Origam.Workflow.WorkflowEngine - Starting ServiceMethodCallEngineTask: 02_LoadPreviousReportData
2021-10-05 16:30:04,545 [30] INFO Origam.Workflow.WorkflowEngine - Merging context 'ReportOrderConfirmation', Step 'Order_UpdateReportData/02_LoadPreviousReportData'
2021-10-05 16:30:04,545 [30] INFO Origam.Workflow.WorkflowEngine - Finished merging context 'ReportOrderConfirmation', Step 'Order_UpdateReportData/02_LoadPreviousReportData'
2021-10-05 16:30:04,545 [30] DEBUG Origam.Workflow.WorkflowEngine - ServiceMethodCallEngineTask 02_LoadPreviousReportData finished successfully.
2021-10-05 16:30:04,545 [30] DEBUG Origam.Workflow.WorkflowEngine - ---------------------------------------------------------------------------------------
2021-10-05 16:30:04,545 [30] DEBUG Origam.Workflow.WorkflowEngine - Starting ServiceMethodCallEngineTask: 03_DeletePreviousReportData
2021-10-05 16:30:04,548 [30] INFO Origam.Workflow.WorkflowEngine - Merging context 'ReportOrderConfirmation', Step 'Order_UpdateReportData/03_DeletePreviousReportData'
2021-10-05 16:30:04,548 [30] INFO Origam.Workflow.WorkflowEngine - Finished merging context 'ReportOrderConfirmation', Step 'Order_UpdateReportData/03_DeletePreviousReportData'
2021-10-05 16:30:04,548 [30] DEBUG Origam.Workflow.WorkflowEngine - ServiceMethodCallEngineTask 03_DeletePreviousReportData finished successfully.
2021-10-05 16:30:04,548 [30] DEBUG Origam.Workflow.WorkflowEngine - ---------------------------------------------------------------------------------------
2021-10-05 16:30:04,548 [30] DEBUG Origam.Workflow.WorkflowEngine - Starting ServiceMethodCallEngineTask: 04_CreateReportData
2021-10-05 16:30:04,558 [30] INFO Origam.Workflow.WorkflowEngine - Merging context 'ReportOrderConfirmation', Step 'Order_UpdateReportData/04_CreateReportData'
2021-10-05 16:30:04,558 [30] INFO Origam.Workflow.WorkflowEngine - Finished merging context 'ReportOrderConfirmation', Step 'Order_UpdateReportData/04_CreateReportData'
2021-10-05 16:30:04,558 [30] DEBUG Origam.Workflow.WorkflowEngine - ServiceMethodCallEngineTask 04_CreateReportData finished successfully.
2021-10-05 16:30:04,558 [30] DEBUG Origam.Workflow.WorkflowEngine - ---------------------------------------------------------------------------------------
2021-10-05 16:30:04,558 [30] DEBUG Origam.Workflow.WorkflowEngine - Starting ServiceMethodCallEngineTask: 05_StoreReportData
2021-10-05 16:30:04,572 [30] INFO Origam.Workflow.WorkflowEngine - Merging context 'ReportOrderConfirmation', Step 'Order_UpdateReportData/05_StoreReportData'
2021-10-05 16:30:04,572 [30] INFO Origam.Workflow.WorkflowEngine - Finished merging context 'ReportOrderConfirmation', Step 'Order_UpdateReportData/05_StoreReportData'
2021-10-05 16:30:04,572 [30] DEBUG Origam.Workflow.WorkflowEngine - ServiceMethodCallEngineTask 05_StoreReportData finished successfully.
2021-10-05 16:30:04,572 [30] DEBUG Origam.Workflow.WorkflowEngine - Block 'Order_UpdateReportData' completed
2021-10-05 16:30:04,572 [30] DEBUG Origam.Workflow.WorkflowEngine - WorkflowCallEngineTask 0400_UpdateReportData finished successfully.
2021-10-05 16:30:04,572 [30] DEBUG Origam.Workflow.WorkflowEngine - Block 'Order_CheckParsingProgress' completed
2021-10-05 16:30:04,572 [30] DEBUG Origam.Workflow.WorkflowEngine - Workflow completed

The visible difference is that the workflow starts with defined transaction id when invoked via work queue and without it when invoked via action button. In both case the transaction id is not transferred to the sub workflow.

The problem seems to be related to the change of behaviour by FIX: Atomic transaction set on a workflow block was ignored by JindrichSusen · Pull Request #146 · origam/origam-source · GitHub, which improves transaction handling by workflow blocks and subworkflows.

The subworkflow is modelled to Ignore transactions. The work queue processor initializes workflow with transaction and it is not passed to subworkflow. Curiously, I tried to remodel the main workflow to use atomic transaction block to force save into database, but the transaction block uses the same transaction as the one that was passed by the work queue processor and it is not closed at the end of the transaction block, so the the subworkflow ends in timeout.

I’ve solved this issue by changing transaction behaviour to InheritExisting.

This topic was automatically closed 2 days after the last reply. New replies are no longer allowed.