Debugging Workflows

Because bugs and code issues are real, finding and fixing problems in code is a common exercise. There are many different techniques used in software development to debug and track down issues. The following sections describe these techniques in relation to workflows.

Debugging in Visual Studio

If your background is in .NET software development, you are probably intimately familiar with the Visual Studio development environment, including vital components such as the Toolbox for visual designing, IntelliSense for quick access to object members, and helpful features such as code highlighting. In addition, Visual Studio provides a great debugging infrastructure that allows for detailed inspection of code, variables, and threads (among other things) during runtime.

The debugging functionality in Visual Studio involves several components. First, breakpoints are vital components that serve as placeholders in the code. A breakpoint basically says, “When this line of code is reached, pause execution and turn control over to the user.” Then you, the developer, can do things such as check the values of variables using the Watch windows, change the execution path by dragging the execution indicator to a different line of code, or selectively step into or over blocks of code. You can access the step functionality by using keyboard shortcuts, by selecting buttons on the Debug toolbar (see Figure 12-9), or by selecting items in the Debug main menu.

Figure 12-9

The first button, which looks like an A/V appliance’s play button, issues the command to either start debugging a currently nonrunning piece of software, or to run until a breakpoint is reached if the software is running. The pause button tells the code to stop debugging and wait for further input from the user. The stop button halts the code debugging process. The left-pointing arrow button stops and restarts the debugging process.

The next group of buttons control stepping logic. The right-pointing arrow takes you to the current line of code that is ready to be executed. The step into, step over, and step out buttons control how you progress to the next statement in the code. Step over is useful if you don’t want to debug the code in the method or property that is about to be executed.

Windows Workflow Foundation has been developed so that the Visual Studio debugging features are available to workflow developers, even in the visual designer. You can set breakpoints on activities in the workflow designer so that when they are about be executed, Visual Studio pauses on the activity and allows you to perform whatever actions you deem necessary. To do this, right-click an activity in the designer, expand the Breakpoint menu, and select Insert Breakpoint. At this point, you can use the standard debugging commands (start debugging, step over, and so on) to watch the workflow execute visually. Figure 12-10 shows the context menu that allows you to add the visual breakpoints.

Figure 12-10

Figure 12-11 shows a screen shot of a workflow with an active breakpoint during execution. The Locals window toward the bottom of the screen gives you a view of the current variables that are local in scope. This enables you to inspect various values of activities and the workflow itself. In addition to debugging visually, you can set breakpoints and step through code, just as you can in standard .NET code.

Figure 12-11

Using the WorkflowRuntime Events

A somewhat rudimentary but extremely useful method of debugging workflow instances is to simply subscribe to the various events exposed by the WorkflowRuntime class. Many times, if a particularly frustrating issue is causing problems, such as stalled execution or an elusive exception, attaching to a few of the runtime events and using some diagnostic code can clear things up.

Here is a list of each of the events in the WorkflowRuntime class, which you can use for reference:

• ServicesExceptionNotHandled

• Started

• Stopped

• WorkflowAborted

• WorkflowCompleted

• WorkflowCreated

• WorkflowIdled

• WorkflowLoaded

• WorkflowPersisted

• WorkflowResumed

• WorkflowStarted

• WorkflowSuspended

• WorkflowTerminated

• WorkflowUnloaded

Many of these events pass various types of EventArgs classes that contain useful information for that event. For example, the WorkflowTerminated event passes an instance of the WorkflowTerminatedEventArgs class, which has a property for exposing an exception thrown from within the workflow.

You can use the methods in the following code for debugging workflow issues. You can place breakpoints in each event handler or place debugging or tracing messages (discussed next) in the methods.

  public static void Main(string[] args) {     WorkflowRuntime runtime = new WorkflowRuntime();     AutoResetEvent waitHandle = new AutoResetEvent(false);         runtime.WorkflowAborted +=         new EventHandler<WorkflowEventArgs>(runtime_WorkflowAborted);     runtime.WorkflowCompleted +=         new EventHandler<WorkflowCompletedEventArgs>(runtime_WorkflowCompleted);     runtime.WorkflowTerminated +=         new EventHandler<WorkflowTerminatedEventArgs>(runtime_WorkflowTerminated);     runtime.WorkflowIdled +=         new EventHandler<WorkflowEventArgs>(runtime_WorkflowIdled);     runtime.WorkflowPersisted +=         new EventHandler<WorkflowEventArgs>(runtime_WorkflowPersisted);     WorkflowInstance instance = runtime.CreateWorkflow(typeof(MyWorkflow));     instance.Start();     waitHandle.WaitOne(); } static void runtime_WorkflowPersisted(object sender, WorkflowEventArgs e) {     Console.WriteLine("The workflow " + e.WorkflowInstance.InstanceId.ToString() +         " was persisted."); } static void runtime_WorkflowIdled(object sender, WorkflowEventArgs e) {     Console.WriteLine("The workflow " + e.WorkflowInstance.InstanceId.ToString() +         " has gone idle."); } static void runtime_WorkflowTerminated(object sender,     WorkflowTerminatedEventArgs e) {     Console.WriteLine("The workflow " + e.WorkflowInstance.InstanceId.ToString() +         " has been terminated.");     Console.WriteLine("   ERROR MESSAGE: " + e.Exception.Message); } static void runtime_WorkflowCompleted(object sender, WorkflowCompletedEventArgs e) {     Console.WriteLine("The workflow " + e.WorkflowInstance.InstanceId.ToString() +         " has completed."); } static void runtime_WorkflowAborted(object sender, WorkflowEventArgs e) {     Console.WriteLine("The workflow " + e.WorkflowInstance.InstanceId.ToString() +         " has been aborted."); } 

This code can be found in the workflow host and is simply subscribing to some of the events exposed by the WorkflowRuntime class. Many of the event handlers receive event arguments specific to the type of event that occurred. These arguments can provide useful information about what happened. For example, the WorkflowTerminated event handler can access an Exception instance that may provide more insight into why the workflow was terminated prematurely.

Tracing

Tracing is a concept not specific to workflows but built into the .NET Framework. The types in the System.Diagnostics namespace provide the necessary infrastructure for the tracing functionality. Tracing enables you to capture pieces of information that are important to the execution of a piece of software. This is a flexible architecture and is able to send messages to a variety of sources, such as the console window, text files, the event log, and any other logging medium you want to use.

Basic Tracing Concepts

To implement tracing, you must first configure the code to write messages at certain points in the application’s execution. You do this by making calls to static methods on the Trace class, as follows:

  string[] myArray = new string[] { "hi", "hello", "goodbye" }; Trace.WriteLine("About to loop through an array with " +     myArray.Length + " items."); Trace.Indent(); for (int i = 0; i < myArray.Length; i++) {     Trace.WriteLine("Performing operation on item: " + myArray[i]);     // do something useful here... } Trace.Unindent(); Trace.WriteLine("Done looping..."); 

This code uses Trace.WriteLine calls and a method called Trace.Indent that allows for some additional formatting of the traced messages.

Now that you know how to add simple trace messages to your application, you need to know how to consume these messages. This occurs by using entities called trace listeners. A trace listener is a class that inherits from the System.Diagnostics.TraceListener. These classes receive messages that are broadcast using the various static Trace methods and then store or display these messages in whatever fashion you specify.

For example, the .NET Framework provides a TextWriterTraceListener class out of the box. This class takes the messages that were sent using the Trace class and writes them to a text file. In addition, there is a class that writes messages to the Windows Event Log called EventLogTraceListener.

You can easily develop new trace listeners by creating a new class; inheriting from TraceListener; and overriding, at a minimum, the Write and WriteLine methods of the base class. For example, you could develop a trace listener to write messages to a database table or an HTTP listener.

Whether you want to use an out-of-the-box trace listener or one that you custom-developed, you need to add an instance of the class to the Trace.Listeners collection. This collection can contain any number of listener instances, each of which is written to during runtime.

By default, the collection contains an instance of the DefaultTraceListener class, which simply writes messages to the Output window in Visual Studio. For example, if you run the preceding code with the default settings, the following text is displayed in the Output window of Visual Studio:

  About to loop through an array with 3 items.     Performing operation on item: hi     Performing operation on item: hello     Performing operation on item: goodbye Done looping... 

As you can see by this simple example, tracing can be an extremely powerful method of diagnosing issues and monitoring the execution of an application without using traditional Visual Studio debugging, which comes with its own overhead. However, it is important to note that tracing is meant to be used sparingly to diagnose issues. It should not be turned on and forgotten in a production application.

Luckily, the tracing infrastructure provides a way to turn messages on and off using configuration. The following code could be from an App.config or Web.config file and dynamically adds the TextWriter TraceListener to the Trace.Listeners collection without modifying the code. After you’ve completed your diagnostics, you can remove or comment out the text that adds the trace listener.

  <configuration>   <system.diagnostics>     <trace autoflush="true">       <listeners>         <add name="TextFileListener"           type="System.Diagnostics.TextWriterTraceListener, System,                 Version=2.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089"           initializeData="c:\logs\listener.txt" />       </listeners>     </trace>   </system.diagnostics> </configuration> 

To further configure tracing in .NET, you can use the TraceSwitch class to categorize messages. These categories are defined in the TraceLevel enumeration and include the following options, in order from highest priority to lowest (aside from Off, which turns tracing off altogether):

• TraceLevel.Off

• TraceLevel.Error

• TraceLevel.Warning

• TraceLevel.Info

• TraceLevel.Verbose (includes all trace messages)

You can define multiple trace switches for a single application, each of which gets its own TraceLevel value. For example, the following configuration snippet says that the trace switch called FileInfo should show all messages at or above warnings, and the trace switch called NetworkInfo should show all messages:

  <configuration>   <system.diagnostics>     ...     <switches>       <add name="FileInfo" value="Warning" />       <add name="NetworkInfo" value="Verbose" />     </switches>   </system.diagnostics> </configuration> 

To use this switch information, you need to create instances of the TraceSwitch class given the names in the configuration file and use its properties with the Trace.WriteIf and Trace.WriteLineIf methods, as follows:

  TraceSwitch fileInfoSwitch =     new TraceSwitch("FileInfo", "Show information about reading files."); TraceSwitch networkInfoSwitch =     new TraceSwitch("NetworkInfo", "Show information about network activity."); // file activity below Trace.WriteLineIf(fileInfoSwitch.TraceInfo, "About to read a file."); // read a file... Trace.WriteLineIf(fileInfoSwitch.TraceError, "An error occurred reading a file."); // network activity below Trace.WriteLineIf(networkInfoSwitch.TraceInfo, "About to access the network."); // try to access the network Trace.WriteLineIf(networkInfoSwitch.TraceWarning,     "The network might be down, will try again later."); 

Given the settings in the preceding configuration file, the code’s output would look like this:

  An error occurred reading a file. About to access the network. The network might be down, will try again later. 

The only message from the code not shown is the one that says it’s about to read a file, because this message is classified as informational. The FileInfo switch shows only messages in the warnings category and higher.

Tracing the Windows Workflow Foundation Platform

Windows Workflow Foundation has quite a few built-in hooks for tracing. The developers of the workflow platform placed a great deal of tracing message throughout the code. Therefore, if the right switches are turned on, you can receive a great deal of useful information.

You can specify the following built-in switches for tracing:

• System.Workflow.Runtime

• System.Workflow.Runtime.Hosting

• System.Workflow.Runtime.Tracking

• System.Workflow.Activities

• System.Workflow.Activities.Rules

You must set these switches to a value from the SourceLevels enumeration, which includes All, Critical, Error, Information, and more.

In addition to these switches, the workflow tracing infrastructure has configurable options for tracing custom applications. The System.Workflow LogToFile switch specifies whether a file called WorkflowTrace.log should be written to the working directory. This option is off by default. If this switch is turned on, the file contains all the trace information specified with the source switches listed previously. Figure 12-12 shows an example of this file.

Figure 12-12

Another switch, System.Workflow LogToTraceListeners, specifies whether to send the workflow tracing information to any other configured trace listeners. By default, the workflow trace messages are sent to the file only if that switch is turned on. This is useful when you want to be able to view the built-in workflow tracing messages on the console window or another listener.

You can easily configure workflow tracing options in an App.config or Web.config file. The following XML shows a .NET configuration file that references all five workflow trace sources as well as the System.Workflow LogToTraceListeners and the System.Workflow LogToFile options. This file specifies various SourceLevel values for each of the five trace sources. In addition, the workflow tracing information is sent to a ConsoleTraceListener because the System.Workflow LogToTraceListeners option is on and the System.Workflow LogToFile option is off.

  <?xml version="1.0" encoding="utf-8" ?> <configuration>   <system.diagnostics>     <trace autoflush="true">       <listeners>         <add name="myConsoleListener"          type="System.Diagnostics.ConsoleTraceListener" />       </listeners>     </trace>     <switches>       <add name="System.Workflow.Runtime" value="All" />       <add name="System.Workflow.Runtime.Hosting" value="All" />       <add name="System.Workflow.Runtime.Tracking" value="Critical" />       <add name="System.Workflow.Activities" value="Warning" />       <add name="System.Workflow.Activities.Rules" value="Off" />       <add name="System.Workflow LogToFile" value="0" />       <add name="System.Workflow LogToTraceListeners" value="1" />     </switches>   </system.diagnostics> </configuration> 

You can also implement you own tracing messages in workflow code, including custom activities, runtime services, and the workflow code-beside class. For example, if the code in the following listing is implemented using a Code activity’s ExecuteCode event handler, the “My custom trace” message will be intermixed with the built-in trace messages:

  private void codeActivity1_ExecuteCode(object sender, EventArgs e) {     Trace.WriteLine("My custom trace."); } 

Performance Counters

You can also trace workflow activities on a systemwide level by using performance counters. Performance counters are measurable indicators exposed by various applications. An application that ships with Windows called Performance Monitor (perfmon.exe) enables you to use these metrics. Because performance counters are registered with Windows, the Performance Monitor application can see and display these counters. Figure 12-13 shows a view of Performance Monitor with some basic Windows-level counters displayed.

Figure 12-13

Workflow Counters

Windows Workflow Foundation provides several useful metrics, as described in Table 12-1.

Table 12-1: Workflow Performance Counters
Open table as spreadsheet

Counter	Description
Workflows Aborted (count, per second)	The number of workflows aborted using WorkflowInstance.Abort().
Workflows Blocked (count, per second)	The number of workflows that are blocked, currently waiting for an external event.
Workflows Completed (count, per second)	The number of completed workflows.
Workflows Created (count, per second)	The number of created workflows.
Workflows Executing (count)	The number of workflows currently executing.
Workflows Idle (count)	The number of workflows that have work to do but are not currently processing.
Workflows In Memory (count)	The number of workflows in memory. These are workflows that have been created; loaded from persistence; and not completed, terminated, or unloaded.
Workflows Loaded (count, per second)	The number of workflows loaded into memory.
Workflows Persisted (count, per second)	The number of workflows that have been persisted using a persistence service.
Workflows Runnable (count)	The number of workflows that have received an external event to process but have not started processing.
Workflows Suspended (count, per second)	The number of suspended workflows.
Workflows Terminated (count, per second)	The number of terminated workflows.
Workflows Unloaded (count, per second)	The number of unloaded workflows.

You can view these performance counters at a system level, meaning across all WorkflowRuntime instances, or from the perspective of a single runtime instance. To view the workflow performance counters, first launch Performance Monitor by choosing Start Run and typing perfmon.exe. By default, standard system counters are displayed, such as % Processor Time and Avg. Disk Queue Length. You can remove any counter you don’t want to use by selecting the unwanted counter and pressing Delete.

Next, right-click the Performance Monitor background and select Add Counters. In the Add Counters dialog box, select Windows Workflow Foundation from the Performance object drop-down menu to display a list of the workflow performance counters (see Figure 12-14).

Figure 12-14

When you select one of the counters, the user interface allows you to apply that counter to all workflow instances on the machine, global instances, or individual WorkflowRuntime instances. Figure 12-14 indicates that the machine currently has two runtime instances: workflowruntimea and workflowruntimeb. These correspond to the names given to each workflow runtime section in the application’s configuration file. You specify this name using the Name attribute of the main workflow runtime node.

Select the performance counters you want to use and the instances where you want to use them, and then add them to the graph with the Add button. Click the Close button to return to the main screen, where you can easily monitor the selected measures.

Creating Logs and Alerts

You can use the Performance Monitor to tell Windows to capture counter data based on the parameters you specify. For example, you may want to record the number of active and created workflows for a certain two-hour period every day. The recorded data is written to a log file in a directory of your choosing to be later inspected, just as though you were looking at a snapshot in time.

To configure a log, open Performance Monitor and expand the Performance Logs and Alerts tree item in the left pane. Next, select the Counter logs item; a listing of currently configured logs appears on the right. To add a new log configuration, right-click an empty area in the right pane and select New Log Settings from the context menu. Enter an appropriate name for the new log; the dialog box shown in Figure 12-15 is displayed.

Figure 12-15

From this dialog box, you can configure the counters to be included, the counting interval, log file name and location, and the log scheduling. All of these options are pretty straightforward and allow a great deal of flexibility, depending on what data you want and when you want it.

The data of interest will now be captured by Windows, but it needs to be consumable. Again, you do this using the Performance Monitor. From the main System Monitor screen (the one with the graph), click the View Log Data button on the toolbar (or press Ctrl+L). From the subsequent dialog box, specify that the data source should be a log file and then point to where the log files of interest can be found.

Next, click the Add button on the Data tab. This displays a list of the counters available for viewing. The list consists of the same counters that were specified when you first configured the log. Click the OK button; the graph is loaded with the data captured during logging.

This is a great way to proactively keep tabs on system metrics. If performance issues start to crop up, you can review the counter logs for the past week to see what happened. Although this is just one of a multitude of system monitoring tools, it is a powerful and fairly simply way of troubleshooting potential issues.

Along with logging data for later use, you can configure alerts to perform an action based on a predetermined counter threshold being crossed. For example, if the Workflows Terminated counter reaches an unacceptable level, the operations team may want to be notified, because this could be a sign that something is seriously wrong. Configuring alerts is as simple as configuring new counter logs.

From within Performance Monitor, expand the Performance Logs and Alerts tree item in the left pane and then select Alerts. To create a new alert, right-click the right pane and select New Alert Settings. You are asked to enter a name for this set of alerts. After this, a dialog box is displayed, where you configure the counters of interest and the desired threshold for each.

After you configure the counter thresholds, you need to configure the corresponding actions. You do this on the Action tab, which is shown in Figure 12-16. As you can see, there are different actions that can be triggered when a counter threshold is breached.

Figure 12-16