views:

239

answers:

1

I have a custom workflow activity with an EventHandlingScopeActivity (UpdateListenerScope).

Inside the EventHandlingScopeActivity is a main SequenceActivity (UpdateListenerSequenceActivity) and an EventHandlersActivity (UpdateHandlers).

When the main SequenceActivity completes, sometimes the EventHandlersActivity will not complete and allow the EventHandlingScopeActivity to complete so that the workflow continues on to the next activity.

The odd thing is that sometimes UpdateHandlers completes and other times it does not. I cannot predict or control when UpdateHandlers will stay hung.

Here is the typical workflow tracing log (everything completes normally, critical step in bold):

System.Workflow.Runtime Information: 1 : Workflow Runtime: Scheduler: InstanceId: 78f436b4-9f97-4d2b-a3dc-add8acf15c79 : Running scheduled entry: SubscriptionEvent((1)serviceQueueActivity1.UpdateListenerSequenceActivity, ActivityStatusChange('(1)serviceQueueActivity1.UpdateListenerSequenceActivity', Executing, Succeeded)) System.Workflow.Runtime Information: 0 : Activity Status Change - Activity: serviceQueueActivity1.UpdateListenerSequenceActivity Old:Executing; New:Closed System.Workflow.Runtime Information: 1 : Workflow Runtime: Scheduler: InstanceId: 78f436b4-9f97-4d2b-a3dc-add8acf15c79 : Scheduling entry: SubscriptionEvent((1)serviceQueueActivity1.UpdateListenerScope, ActivityStatusChange('(1)serviceQueueActivity1.UpdateListenerSequenceActivity', Closed, Succeeded)) System.Workflow.Runtime Information: 1 : Workflow Runtime: Scheduler: InstanceId: 78f436b4-9f97-4d2b-a3dc-add8acf15c79 : Done with running scheduled entry: SubscriptionEvent((1)serviceQueueActivity1.UpdateListenerSequenceActivity, ActivityStatusChange('(1)serviceQueueActivity1.UpdateListenerSequenceActivity', Executing, Succeeded)) System.Workflow.Runtime Information: 1 : Workflow Runtime: Scheduler: InstanceId: 78f436b4-9f97-4d2b-a3dc-add8acf15c79 : Running scheduled entry: SubscriptionEvent((1)serviceQueueActivity1.UpdateListenerScope, ActivityStatusChange('(1)serviceQueueActivity1.UpdateListenerSequenceActivity', Closed, Succeeded)) System.Workflow.Runtime Information: 1 : Workflow Runtime: Scheduler: InstanceId: 78f436b4-9f97-4d2b-a3dc-add8acf15c79 : Scheduling entry: SubscriptionEvent((1)serviceQueueActivity1.UpdateHandlers, System.EventArgs) System.Workflow.Runtime Information: 1 : Workflow Runtime: Scheduler: InstanceId: 78f436b4-9f97-4d2b-a3dc-add8acf15c79 : Done with running scheduled entry: SubscriptionEvent((1)serviceQueueActivity1.UpdateListenerScope, ActivityStatusChange('(1)serviceQueueActivity1.UpdateListenerSequenceActivity', Closed, Succeeded)) System.Workflow.Runtime Information: 1 : Workflow Runtime: Scheduler: InstanceId: 78f436b4-9f97-4d2b-a3dc-add8acf15c79 : Running scheduled entry: SubscriptionEvent((1)serviceQueueActivity1.UpdateHandlers, System.EventArgs) System.Workflow.Runtime Information: 1 : Workflow Runtime: Scheduler: InstanceId: 78f436b4-9f97-4d2b-a3dc-add8acf15c79 : Scheduling entry: SubscriptionEvent((1)serviceQueueActivity1.UpdateHandlers, ActivityStatusChange('(1)serviceQueueActivity1.UpdateHandlers', Executing, Succeeded)) System.Workflow.Runtime Information: 1 : Workflow Runtime: Scheduler: InstanceId: 78f436b4-9f97-4d2b-a3dc-add8acf15c79 : Done with running scheduled entry: SubscriptionEvent((1)serviceQueueActivity1.UpdateHandlers, System.EventArgs) System.Workflow.Runtime Information: 1 : Workflow Runtime: Scheduler: InstanceId: 78f436b4-9f97-4d2b-a3dc-add8acf15c79 : Running scheduled entry: SubscriptionEvent((1)serviceQueueActivity1.UpdateHandlers, ActivityStatusChange('(1)serviceQueueActivity1.UpdateHandlers', Executing, Succeeded)) System.Workflow.Runtime Information: 0 : Activity Status Change - Activity: serviceQueueActivity1.UpdateHandlers Old:Executing; New:Closed System.Workflow.Runtime Information: 1 : Workflow Runtime: Scheduler: InstanceId: 78f436b4-9f97-4d2b-a3dc-add8acf15c79 : Scheduling entry: SubscriptionEvent((1)serviceQueueActivity1.UpdateListenerScope, ActivityStatusChange('(1)serviceQueueActivity1.UpdateHandlers', Closed, Succeeded)) System.Workflow.Runtime Information: 1 : Workflow Runtime: Scheduler: InstanceId: 78f436b4-9f97-4d2b-a3dc-add8acf15c79 : Done with running scheduled entry: SubscriptionEvent((1)serviceQueueActivity1.UpdateHandlers, ActivityStatusChange('(1)serviceQueueActivity1.UpdateHandlers', Executing, Succeeded)) System.Workflow.Runtime Information: 1 : Workflow Runtime: Scheduler: InstanceId: 78f436b4-9f97-4d2b-a3dc-add8acf15c79 : Running scheduled entry: SubscriptionEvent((1)serviceQueueActivity1.UpdateListenerScope, ActivityStatusChange('(1)serviceQueueActivity1.UpdateHandlers', Closed, Succeeded)) System.Workflow.Runtime Information: 1 : Workflow Runtime: Scheduler: InstanceId: 78f436b4-9f97-4d2b-a3dc-add8acf15c79 : Scheduling entry: SubscriptionEvent((1)serviceQueueActivity1.UpdateListenerScope, ActivityStatusChange('(1)serviceQueueActivity1.UpdateListenerScope', Executing, Succeeded)) System.Workflow.Runtime Information: 1 : Workflow Runtime: Scheduler: InstanceId: 78f436b4-9f97-4d2b-a3dc-add8acf15c79 : Done with running scheduled entry: SubscriptionEvent((1)serviceQueueActivity1.UpdateListenerScope, ActivityStatusChange('(1)serviceQueueActivity1.UpdateHandlers', Closed, Succeeded)) System.Workflow.Runtime Information: 1 : Workflow Runtime: Scheduler: InstanceId: 78f436b4-9f97-4d2b-a3dc-add8acf15c79 : Running scheduled entry: SubscriptionEvent((1)serviceQueueActivity1.UpdateListenerScope, ActivityStatusChange('(1)serviceQueueActivity1.UpdateListenerScope', Executing, Succeeded)) System.Workflow.Runtime Information: 0 : Activity Status Change - Activity: serviceQueueActivity1.UpdateListenerScope Old:Executing; New:Closed

Here is the workflow tracing log UpdateHandlers does not complete:

System.Workflow.Runtime Information: 1 : Workflow Runtime: Scheduler: InstanceId: 6602768f-f043-4382-9d29-0be944f0d390 : Running scheduled entry: SubscriptionEvent((1)serviceQueueActivity1.UpdateListenerSequenceActivity, ActivityStatusChange('(1)serviceQueueActivity1.UpdateListenerSequenceActivity', Executing, Succeeded)) System.Workflow.Runtime Information: 0 : Activity Status Change - Activity: serviceQueueActivity1.UpdateListenerSequenceActivity Old:Executing; New:Closed System.Workflow.Runtime Information: 1 : Workflow Runtime: Scheduler: InstanceId: 6602768f-f043-4382-9d29-0be944f0d390 : Scheduling entry: SubscriptionEvent((1)serviceQueueActivity1.UpdateListenerScope, ActivityStatusChange('(1)serviceQueueActivity1.UpdateListenerSequenceActivity', Closed, Succeeded)) System.Workflow.Runtime Information: 1 : Workflow Runtime: Scheduler: InstanceId: 6602768f-f043-4382-9d29-0be944f0d390 : Done with running scheduled entry: SubscriptionEvent((1)serviceQueueActivity1.UpdateListenerSequenceActivity, ActivityStatusChange('(1)serviceQueueActivity1.UpdateListenerSequenceActivity', Executing, Succeeded)) System.Workflow.Runtime Information: 1 : Workflow Runtime: Scheduler: InstanceId: 6602768f-f043-4382-9d29-0be944f0d390 : Running scheduled entry: SubscriptionEvent((1)serviceQueueActivity1.UpdateListenerScope, ActivityStatusChange('(1)serviceQueueActivity1.UpdateListenerSequenceActivity', Closed, Succeeded)) System.Workflow.Runtime Information: 1 : Workflow Runtime: Scheduler: InstanceId: 6602768f-f043-4382-9d29-0be944f0d390 : Scheduling entry: SubscriptionEvent((1)serviceQueueActivity1.UpdateHandlers, System.EventArgs) System.Workflow.Runtime Information: 1 : Workflow Runtime: Scheduler: InstanceId: 6602768f-f043-4382-9d29-0be944f0d390 : Done with running scheduled entry: SubscriptionEvent((1)serviceQueueActivity1.UpdateListenerScope, ActivityStatusChange('(1)serviceQueueActivity1.UpdateListenerSequenceActivity', Closed, Succeeded)) System.Workflow.Runtime Information: 1 : Workflow Runtime: Scheduler: InstanceId: 6602768f-f043-4382-9d29-0be944f0d390 : Running scheduled entry: SubscriptionEvent((1)serviceQueueActivity1.UpdateHandlers, System.EventArgs) Missing step here!!! System.Workflow.Runtime Information: 1 : Workflow Runtime: Scheduler: InstanceId: 6602768f-f043-4382-9d29-0be944f0d390 : Done with running scheduled entry: SubscriptionEvent((1)serviceQueueActivity1.UpdateHandlers, System.EventArgs) System.Workflow.Runtime Information: 0 : Workflow Runtime: WorkflowExecutor: workflow instance '6602768f-f043-4382-9d29-0be944f0d390' has no work.

Any ideas why the EventHandlersActivity would not complete? At this point the workflow is forever hung because the event handler is listening for an event that will not be sent.

A: 

Root cause ended up being multiple HandleExternalEventActivity activities listening in parallel for the same event. Created a custom IEventActivity based on the sample at http://msmvps.com/blogs/theproblemsolver/archive/2008/09/16/versioning-long-running-workfows-part-3.aspx using queue.Peek instead of queue.Dequeue.