Three Simple Rules for Better Debugging with WorkflowApplication - Ron Jacobs - Site Home

Developers often say that there is a steep learning curve with Windows Workflow Foundation (WF4). I won’t deny that… instead, allow me to share three simple rules that will help you to get over that curve sooner and to make them easy to remember, they all begin with “U” which is appropriate because they do all begin with you.

Use Tracking
Unit Tests
Use Timeouts

Download Sample Code

Workflow TV - Three Simple Rules for Better Debugging with WorkflowApplication

Use Tracking

Tracking is the single best way to understand what your workflow is doing. There is just one simple problem… We didn’t make it easy for people to read tracking information.

     WorkflowInstanceRecord { InstanceId = e9579393-c150-46c9-be60-42bdf4dc509e, RecordNumber = 0, EventTime = 7/5/2012 12:04:11 AM, ActivityDefinitionId = Workflow, State = Started }

    ActivityScheduledRecord { InstanceId = e9579393-c150-46c9-be60-42bdf4dc509e, RecordNumber = 1, EventTime = 7/5/2012 12:04:11 AM, Activity {  }, ChildActivity { Name=Workflow, ActivityId = 1, ActivityInstanceId = 1, TypeName=ThreeRulesBetterDebugWF4.Workflow } }

    ActivityStateRecord { InstanceId = e9579393-c150-46c9-be60-42bdf4dc509e, RecordNumber = 2, EventTime = 7/5/2012 12:04:11 AM, Activity { Name=Workflow, ActivityId = 1, ActivityInstanceId = 1, TypeName=ThreeRulesBetterDebugWF4.Workflow }, State = Executing }

As you can see in the previous example, this is a mind numbing dump of data. If you want something much more useful try Microsoft.Activities.Extensions.Tracking which includes tracking record extensions designed to make it easy for you to follow what is going on.

    0: WorkflowInstance "Workflow" is Started

    1: Activity [null] "null" scheduled child activity [1] "Workflow"

    2: Activity [1] "Workflow" is Executing

    3: Activity [1] "Workflow" scheduled child activity [1.1] "Sequence"

    4: Activity [1.1] "Sequence" is Executing

    5: Activity [1.1] "Sequence" scheduled child activity [1.10] "WriteLine"

    6: Activity [1.10] "WriteLine" is Executing

    {

        Arguments

            Text: Creating bookmark B1

            TextWriter: 

    }

    7: Activity [1.10] "WriteLine" is Closed

    {

        Arguments

            Text: Creating bookmark B1

            TextWriter: 

    }

    8: Activity [1.1] "Sequence" scheduled child activity [1.8] "WaitForBookmark "B1""

    9: Activity [1.8] "WaitForBookmark "B1"" is Executing

    {

        Arguments

            BookmarkName: B1

    }

    10: WorkflowInstance "Workflow" is Idle

Now that is a trace that helps you to understand exactly what is going on, including things that you don't see in the simple record.ToString() trace above such as arguments, annotations, variables and more.

Tracking to the Trace Provider

When debugging, just add a TraceTrackingParticipant to get the tracking output written to Visual Studio Debug Output window. Or if you are using a logging library such as NLog or Enterprise Library.

       1: using Microsoft.Activities.Extensions.Tracking;

       2:  

       3: private static void RunWorkflow()

       4: {

       5:     var host = new WorkflowApplication(WorkflowDefinition);

       6:  

       7:     // Tip: Output tracking to System.Diagnostics.Trace

       8:     host.Extensions.Add(new TraceTrackingParticipant());

       9:  

      10:     // ...

      11: }

      12:

Tracking to a File

If you just want a text file with the output

       1: private static void RunWorkflow()

       2: {

       3:     var host = new WorkflowApplication(WorkflowDefinition);

       4:  

       5:     // Tip: Capture tracking to a file for help debugging

       6:     using (var fileTracker = new FileTracker("tracking.txt"))

       7:     {

       8:         host.Extensions.Add(fileTracker);

       9:         host.Run();

      10:         // Wait for it to complete and then

      11:  

      12:         // FileTracker is Disposable 

      13:     }

      14: }

      15:

Unit Tests

Unit testing is an art, but it is one you can learn if you don’t give up. I am such a believer in it I created Microsoft.Activities.UnitTesting to help you.

Given this workflow

What do we need to test?

There is a protocol of bookmarks that must be followed for this workflow to function correctly. Our tests should verify that the protocol is followed from the workflow side and from the host side. Using the Given / When / Then pattern helps me to be clear about what I’m testing and helps me to focus the test on just one aspect of the behavior.

       1: /// <summary>

       2: ///   Given

       3: ///   * A Workflow run until the second idle with bookmark "B2" 

       4: ///   When

       5: ///   * Workflow resumes bookmark "B2"

       6: ///   Then

       7: ///   * It will run and complete

       8: /// </summary>

       9: [TestMethod]

public void WorkflowResumedB2WillComplete()

{

    // Arrange

    var activity = new Workflow();

    var host = WorkflowApplicationTest.Create(activity);

    try

    {

        // Run to the first bookmark

        host.TestWorkflowApplication.RunEpisode(Program.Bookmark1, Global.Timeout);

  

        // Run to the second bookmark

        host.TestWorkflowApplication.ResumeEpisodeBookmark(Program.Bookmark1, 1, Program.Bookmark2, Global.Timeout);

  

        // Act

        // Use Microsoft.Activities.Extensions episode support

        // Resume bookmark "B2" and run until complete

        // Tip: Use the timeout for better debugging

        var result = host.TestWorkflowApplication.ResumeEpisodeBookmark(Program.Bookmark2, 2, Global.Timeout);

  

        // Assert

        Assert.IsNotNull(result);

        Assert.IsInstanceOfType(result, typeof(WorkflowCompletedEpisodeResult));

        var completedResult = (WorkflowCompletedEpisodeResult)result;

        Assert.AreEqual(ActivityInstanceState.Closed, completedResult.State);

    }

    finally

    {

        host.Tracking.Trace();

    }

}

Use Timeouts

When everything goes right, you don’t need timeouts. So you create programs that will one day hang because on that particular day something didn’t go right. I’m as guilty as anyone when it comes to this. Recently I’ve been reviewing the code I’ve written for Microsoft.Activities.Extensions and Microsoft.Activities.UnitTesting and I came up with these rules.

Any class that has one thread waiting on an asynchronous operation from another thread you must use a timeout and handle timeouts gracefully.
Classes should have a Default Timeout that will be used if one is not supplied by the caller
Timeouts should be consistent across the library
Timeouts should self-adjust when the debugger is attached

To implement this pattern, in the sample I have a class named Global which contains these shared global properties.

       1: /// <summary>

       2: ///   Global readonly static values

       3: /// </summary>

       4: internal static class Global

       5: {

       6:     #region Static Fields

       7:  

       8:     /// <summary>

       9:     ///   The default timeout used when a debugger is attached

    /// </summary>

    private static TimeSpan defaultDebugTimeout = TimeSpan.FromSeconds(10);

  

    /// <summary>

    ///   The default timeout used

    /// </summary>

    private static TimeSpan defaultTimeout = TimeSpan.FromSeconds(1);

  

    #endregion

  

    #region Properties

  

    /// <summary>

    ///  Gets or sets the default timeout used when a debugger is attached

    /// </summary>

    /// <remarks>

    /// Allows users of this library to set the default

    /// </remarks>

    internal static TimeSpan DefaultDebugTimeout

    {

        get

        {

            return defaultDebugTimeout;

        }

  

        set

        {

            defaultDebugTimeout = value;

        }

    }

  

    /// <summary>

    ///  Gets or sets the default timeout

    /// </summary>

    /// <remarks>

    /// Allows users of this library to set the default

    /// </remarks>

    internal static TimeSpan DefaultTimeout

    {

        get

        {

            return defaultTimeout;

        }

  

        set

        {

            defaultTimeout = value;

        }

    }

  

    /// <summary>

    ///   Gets Timeout used for wait operations

    /// </summary>

    /// <remarks>

    ///   TODO: Notice how the Timeout adjust when the debugger is attached

    /// </remarks>

    internal static TimeSpan Timeout

    {

        get

        {

            return Debugger.IsAttached ? defaultDebugTimeout : defaultTimeout;

        }

    }

  

    #endregion

}

How many times have you decided to debug your program only to get TimeoutException because you were slowly stepping through the code? With this approach when I do an operation that needs a timeout, I get a consistent timeout that automatically adjusts when a debugger is attached.

// Use Microsoft.Activities.Extensions to run until idle with a bookmark
host.RunEpisode(Bookmark1, Global.Timeout);

// Whenever you use WaitOne you MUST use a timeout
if (!idleEvent.WaitOne(Global.Timeout))
{
    throw new TimeoutException();
}

Summary

Any time you create multi-threaded programs you have crossed over into advanced territory. Whenever you use WorkflowApplication you are writing a multi-threaded program and you cannot escape the need for these three simple rules.

Any other rules that you have? Just leave a comment below.

Ron Jacobs
blog: http://blogs.msdn.com/rjacobs
Twitter: @ronljacobs