WF4: How Tracking Helped Me Write a Better Unit Test

This morning I’ve been working on how to support cancelling a workflow via a CancellationToken.  The details of that are not important right now but what is really cool is how I was able to test this.

Scenario: Caller requests Cancellation via a CancellationToken and the UnhandledExceptionAction is Cancel

Given

• An activity that contains a CancellationScope
• The CancellationScope body has an activity that will create a bookmark and go idle
• The CancellationScope has a CancelHandler with a WriteLine that has a DisplayName "CancelHandlerWriteLine"

When

• The caller invokes the workflow asynchronously as a task with a CancellationToken
• and in the idle callback calls CancellationTokenSource.Cancel

Then

• A TaskCanceledException is thrown
• The WorkflowApplication is canceled
• The CancelationScope CancelHandler is invoked

Test Challenges

• How can I wait until the cancel is completed after handling the exception before verifying?
• How will I verify that the CancelHandler is invoked?

Solution

To wait until the cancel is completed after handling the exception before verifying I simply create an AutoResetEvent (line 18) and signal it from the WorkflowApplication.Completed event callback (line 19).  Then before verifying the tracking data I wait for this event (line 41)

To verify that the cancel handler was invoked I use the Microsoft.Activities.UnitTesting.Tracking.MemoryTrackingParticipant. This allows me to capture the tracking information into a collection that I can search using AssertTracking.Exists to verify that the activity with the name ExpectedCancelWriteline entered the Closed state.

    1: [TestMethod]
    2: public void ActivityIsCanceledViaTokenShouldInvokeCancelHandler()
    3: {
    4:     const string ExpectedCancelWriteLine = "CancelHandlerWriteLine";
    5:     var workflowApplication =
    6:         new WorkflowApplication(
    7:             new CancellationScope
    8:                 {
    9:                     Body = new TestBookmark<int> { BookmarkName = "TestBookmark" }, 
   10:                     CancellationHandler = new WriteLine { DisplayName = ExpectedCancelWriteLine }
   11:                 });
   12:  
   13:     // Capture tracking events in memory
   14:     var trackingParticipant = new MemoryTrackingParticipant();
   15:     workflowApplication.Extensions.Add(trackingParticipant);
   16:  
   17:     // Use this event to wait until the cancel is completed
   18:     var completedEvent = new AutoResetEvent(false);
   19:     workflowApplication.Completed = args => completedEvent.Set();
   20:  
   21:     try
   22:     {
   23:         var tokenSource = new CancellationTokenSource();
   24:  
   25:         // Run the activity and cancel in the idle callback
   26:         var task = workflowApplication.RunEpisodeAsync(
   27:             (args, bn) =>
   28:                 {
   29:                     Debug.WriteLine("Idle callback - cancel");
   30:                     tokenSource.Cancel();
   31:                     return false;
   32:                 }, 
   33:             UnhandledExceptionAction.Cancel, 
   34:             TimeSpan.FromMilliseconds(1000), 
   35:             tokenSource.Token);
   36:  
   37:         // Exception is thrown when Wait() or Result is accessed
   38:         AssertHelper.Throws<TaskCanceledException>(task);
   39:  
   40:         // Wait for the workflow to complete the cancel
   41:         completedEvent.WaitOne(this.DefaultTimeout);
   42:  
   43:         // Verify the the cancel handler was invoked
   44:         AssertTracking.Exists(
   45:             trackingParticipant.Records, ExpectedCancelWriteLine, ActivityInstanceState.Closed);
   46:     }
   47:     finally
   48:     {
   49:         // Write the tracking records to the test output
   50:         trackingParticipant.Trace();
   51:     }
   52: }
   53:  

When I run this test I also get the Tracking info in the Test Results along with any Debug.WriteLine output to help me sort out what is happening.  The tracking data is nicely formatted thanks to extension methods in Microsoft.Activities.UnitTesting.Tracking that provide a Trace method for each type of tracking record which produces human readable formatting.

 WaitForWorkflow waiting for workflowBusy - check for cancel
 Checking cancel token
 System.Activities.WorkflowApplicationIdleEventArgs
     Bookmarks count 1 (TestBookmark)
 Idle callback - cancel
 Checking cancel token from idle handler
 Cancel requested canceling workflow 
 WaitForWorkflow workflowBusy is signaled - check for cancel
 Checking cancel token
 Cancel requested canceling workflow 
 WorkflowApplication.Cancel
 this.CancellationToken.ThrowIfCancellationRequested()
 *** Tracking data follows ***
 WorkflowInstance for Activity <CancellationScope> state is <Started> at 04:13:53.7852
 Activity <null> is scheduled child activity <CancellationScope> at 04:13:53.7852
 Activity <CancellationScope> state is Executing at 04:13:53.7852
 Activity <CancellationScope> is scheduled child activity <TestBookmark> at 04:13:53.7852
 Activity <TestBookmark> state is Executing at 04:13:53.7852
 {
     Arguments
         BookmarkName: TestBookmark
 }
 WorkflowInstance for Activity <CancellationScope> state is <Idle> at 04:13:53.7852
 Activity <null> cancel is requested for child activity <CancellationScope> at 04:13:53.7852
 Activity <CancellationScope> cancel is requested for child activity <TestBookmark> at 04:13:53.7852
 Activity <TestBookmark> state is Canceled at 04:13:53.8008
 {
     Arguments
         BookmarkName: TestBookmark
         Result: 0
 }
 Activity <CancellationScope> is scheduled child activity <CancelHandlerWriteLine> at 04:13:53.8008
 Activity <CancelHandlerWriteLine> state is Executing at 04:13:53.8008
 {
     Arguments
         Text: 
         TextWriter: 
 }
 Activity <CancelHandlerWriteLine> state is Closed at 04:13:53.8008
 {
     Arguments
         Text: 
         TextWriter: 
 }
 Activity <CancellationScope> state is Canceled at 04:13:53.8008
 WorkflowInstance for Activity <CancellationScope> state is <Canceled> at 04:13:53.8008