Monitoring and Troubleshooting .NET 4 Service

Techniques for debugging traditional WCF Services and Workflow Services built on .NET 4

Exploring WCF Services



Monitoring and Troubleshooting .NET 4 Services

Techniques for debugging traditional WCF Services and Workflow Services built on .NET 4

By Zoiner Tejada

Debugging, troubleshooting, and monitoring are procedures familiar to any developer; all revolve around finding the "right" information. With .NET Framework 4.0, the number of options to find the right information is expanding, but .NET 4 also continues support of some tried and true techniques you may already be using. We'll explore the use of the Microsoft Visual Studio Debugger, Event Tracing for Windows (ETW), and Windows Application Server Extensions (code-named "Dublin") as valid tools to help you troubleshoot both imperative .NET 4 Windows Communication Foundation (WCF) services and declarative workflow services from development through production deployment.

Visual Studio Debugger Enhancements

No tool is more familiar to the .NET developer than Visual Studio, and when it comes to quickly smoking out a problem at development time, Visual Studio's debugger is hard to beat. This continues to hold true for debugging of traditional WCF and workflow services. In Visual Studio 2010, the F5 experience depends on the project template chosen. When pressing F5 to start a debug session with a WCF Service Library, the WCF Service Host will spin up with the debugger attached, and the WCF Test Client will be launched ready to make calls against the newly started service; this behavior is unchanged from Visual Studio 2008.

For a Declarative Flowchart or Sequential Service Library, the default is to launch and attach to an instance of WebDev.exe (variously known as Cassini, the Visual Studio Web Development Server, or the ASP.NET Development Server) with an automatically assigned port for each such project in the solution. In solutions with multiple Declarative Service projects, it is useful to set the Always Start When Debugging property to false when you're interested only in hosting and debugging projects you've set as startup.

A Declarative Service project may be configured to run within Microsoft IIS by choosing the project properties and clicking the Web tab. Figure 1 shows the result of changing the Servers selection to Use Local IIS Web Server and pressing the Create Virtual Directory button.

Figure 1: Configuring a project to run under IIS

Once configured this way, the debugger will attach to the worker process responsible for that virtual directory. Manually attaching to the process hosting either type of service is another option, which you activate via the Debug, Attach to Process menu. In the case of a declarative workflow service, to enable graphical debugging of your workflow (discussed shortly), you must explicitly attach to Workflow code by unchecking Managed (v4.0) and checking Workflow in the Select Code Type dialog box that appears when you press Select in the Attach to Process dialog box.

Once debugger is attached to the hosting process, debugging imperative WCF service code is just like debugging other managed code. However, if you're attached to a declarative workflow service, you can take advantage of graphical debugging, which lets you step into and across activities as if they were lines of code. Here you can also toggle breakpoints on activities in the workflow diagram, as Figure 2 shows. Upon hitting one, you can examine workflow variable values in the Locals, Watch, or Immediate windows.

Figure 2: Hitting a breakpoint during graphical debugging of a workflow

While stopped at a breakpoint, you can also view the Call Stack, which will list the executing activities by name in the unique dotted form:

Workflow![Dotted Path To Executing Activity] .[ExecutingActivityDisplayName]()

This is followed by a line number referring to the activity's line number in the XAMLX; Figure 3 shows an example call stack. It's worth noting that by opening the XAMLX using the XML editor when the code is stopped at a breakpoint, the line of XAML source will be highlighted to display the current statement (yellow) and breakpoints (red).

Figure 3: A workflow service call stack

Introducing Event Tracing for Windows

If you open the Event Viewer on Windows Vista or later, you'll find a new set of logs called Application and Service logs in addition to the System, Security, and Application Windows Event logs. The goal of Application and Service logs is to store diagnostic events for a particular application or component instead of events that are more global in their scope (e.g., events written to the System log). These logs are populated by a new, high-performance infrastructure, ETW. There are four event sources:

         Workflow Tracking: provides events that describe workflow lifecycle events, activity state changes, variable values, exceptions, and user-defined events.

         WCF Analytic Trace: provides events that include service host details, message processing, operation invocation, and faults.

         WCF Message Logging: provides events that capture the contents of service messages.

         WCF Diagnostic Trace: provides both WCF trace and message log events.

.NET 4 unifies the logging of Workflow Tracking Records, WCF Analytic Trace Events, and WCF Message Logs by writing those events to a new set of Application and Service logs via ETW. WCF Diagnostic Trace refers to the trace and message events that are logged to .svclog files on the file system, as was possible in .NET 3.5 and is still supported in .NET 4.

Viewing ETW Events

The querying and analysis of ETW events for imperative WCF Services and declarative workflow services is a simple matter of opening the Event Viewer and navigating to the appropriate log underneath the Application and Service Logs\Microsoft\WCF\WF-Development tree. Windows defines the following four standard log subtypes:

         Admin: logs events that define a problem and provide the corrective action that an administrator should take.

         Analytic: logs events that detail application execution in high volume and are useful variously for troubleshooting and monitoring.

         Debug: logs issues of interest to a developer only while troubleshooting.

         Operational: logs events of value to an end user or administrator that relate to an application as it is running, though they may not provide specific actionable guidance.

Of these four subtypes, the two most useful for troubleshooting .NET Services are the Analytic and Debug logs. The Analytic log, which Figure 4 shows, is the log for viewing the vast majority of useful events including workflow activity, user-created tracking records, service operation traces, and message logs. The Debug log is mostly used like a meta log: It records events about other events that could not be properly logged in the Analytic log for example, noting events that were not logged or were truncated. It is also where verbose events from the .NET Services infrastructure are logged.

Figure 4: Viewing tracking records in the Analytic log

A distinct advantage resulting from ETW's unified logging is the ability to easily see the correlated, ordered sequence of events between WCF activity and workflow execution. For example, the table in Figure 5 shows a new instance of the workflow we debugged in Figure 2 being launched as the result of invoking a workflow service's Receive activity (with CanCreateInstance set to true), defining the GetData operation, which takes an integer.

The events logged within the Analytic log fall broadly into two source categories according to their EventID:

         100 199 represent workflow tracking records.

         200 and greater represent WCF trace and message log records.

When performing analysis of the events in the Event Viewer, you might find it useful to filter out, for example, just the workflow tracking records. To create a custom view on records captured in the Analytic log, follow these steps:

1.     Right-click the Analytic log in the debug view and select Create Custom View.

2.     In the Includes/Excludes Event ID's text box, enter the range of IDs you want to see. To filter for Workflow events only and exclude WCF traces, enter 100-199. Click OK.

3.     Give the Custom View a name and click OK. Doing so will create the custom view under the Custom Views folder in the Event Viewer. Clicking the custom view will show the filtered event list.

Configuring ETW

To be able to view WF Tracking Record, WCF Analytic Traces, and WCF Message Log Traces for imperative WCF or declarative workflow services in the Event Viewer, you need to perform the following few steps:

1.     Show the Analytic/Debug logs: In Event Viewer, right-click the WF-Development folder and choose View, Show Analytic and Debug logs.

2.     Enable the Analytic/Debug logs: In Event Viewer, right-click the Analytic or Debug log you want to start collecting data and choose Enable Log.

3.     Enable WF Tracking Events in service web.config: Configure your Workflow Service to use the ETW Tracking Participant and configure the volume of records tracked by defining a Tracking Profile for it. (This setting does not apply to imperative WCF services.)

4.     Enable WCF Message Log Tracing in service web.config: Add a messageLogging element to the system.serviceModel/diagnostics section that enables message logging at the service and/or transport level. Note that WCF Analytic traces are enabled by default.

Figure 6 shows a sample web.config that registers the ETW tracking participant with the service via its service behavior, configures the ETW tracking participant with the JustRightTrackingProfile tracking profile defined further down, and defines a messageLogging element that enables the logging of complete messages at the service and transport level.

Tracking profiles, such as the one shown in Figure 6, define zero or more queries for each of the 10 different kinds of tracking records that the workflow runtime is capable of emitting. A record is only sent to the tracking participant when it matches one of the defined queries. The specifics of configuring each of the 10 query elements are beyond the scope of this article. Just as in WCF we can log the message body by enabling message logging, tracking profiles also let us log the values of workflow variables for activity events that match a defined query. For example, in the simple workflow we traced previously, we could capture the value of the "data" variable it defines by adding the following activity query as a child of the existing activityQueries element:

This would result in the last record listed in Figure 5 changing to include the value of the "data" variable extracted when the ReceiveRequest activity completed its execution, as Figure 7 shows.

Limitations of ETW Trace Events

The maximum size of a serialized ETW record cannot exceed 64KB. When a record exceeds this size, a warning-level trace record will be written to the Debug log, informing of either truncation or a failure to log the record. Special cases of this occur when caused by large variable payloads or message log content. In the former, the variable element will be truncated and have its content replaced with ellipses; in the latter, the message won't be logged. If you require the value of a message log, but it's always exceeding the ETW buffer size, then you must fall back to the .NET 3.5 approach of using WCF Diagnostic Message Logging and enable writing the message logs to .svclog files.

Application Server Extensions (aka "Dublin")

Dublin is a free, feature-rich enhancement to IIS. Although ETW provides a lot of information, the Event Viewer is limited in its ability to present the trace events in a fashion that's easy is to query (basically you can query only by timestamp and EventID) and navigate (solely moving between the Debug/Analytic log, through paged sets of events). Among many features that enhance service configuration and server robustness, Dublin adds a rich UI to the IIS Management Console that enables drill-down from a high-level dashboard (Figure 8) into WCF service calls or instances of a service and further into tracked events for that service. Moreover, it provides querying capabilities on event trace details, such as querying by variable values (Figure 9), which enable you to locate a service instance from the single event record that had the requested variable value (simply by right-clicking the returned event record and selecting Tracked Service Instance).

Figure 8: Dublin monitoring dashboard

Figure 9: Configuring a query to return events containing the variable afterGetData with the value 42

Under the covers, Dublin creates a trace session with ETW and logs the trace records it receives from the WF Tracking, WCF Analytic Trace, and WCF Message Logging providers to its monitoring SQL Server database. This has two ramifications. By storing the event records in a SQL Server database that's designed to be externally available (it even provides views to simplify querying the database directly), Dublin enables queries and analysis that might not be possible through the UI. The fact that it is logging ETW traces does cause one issue that may surprise you. Even though records are being logged to a SQL Server database that could support large event payloads, the 64KB event size limit still applies, and truncation or dropped events will still occur when they exceed this limit.

Configuring Dublin Monitoring

Out of the box, Dublin is pretty much ready to go. In the latest Community Technology Preview (CTP), you configure monitoring by selecting the server node (future releases will provide full support for configuring at the application level), right-clicking, selecting Configure defaults, then selecting Monitoring from the left tabs, as Figure 10 shows. The dialog box that's presented is effectively helping you edit the web.config relevant to the scope you've selected. In this case, that would mean changes made here will be reflected in the root web.config located under C:\[WinDir]\Microsoft.NET\Framework\v4.0.20506\config.

Figure 10: Dublin monitoring configuration

By default Dublin is set to use a monitoring level of Health Monitoring, which among other things automatically configures the tracking profile for the workflow service to use the HealthMonitoring_Tracking_Profile. The profile will collect only workflow instance-level events, unhandled exceptions, faults, and correlation events; it will not collect activity-level events. Changing this to include activity events is a simple matter of raising the Level slider to Troubleshooting and clicking Apply. Doing so will change the tracking profile used by the ETW tracking participant to one that also includes activity state-change events, activity scheduling, canceling, bookmark resumptions, and all custom user tracking events. As an aside, these default profiles are defined in machine.config.

If you want to enable variable value extraction, you'll have to define your own tracking profile and register it with Dublin. Simply click the Configure button on the Monitoring pane, click Add new, and browse to the Tracking Profile (*.tp) file containing the tracking profile you want to use. A tracking profile file is simply the same trackingProfile element you'd use in a web.config (like the JustRightDebugProfile we defined in Figure 6 previously), extracted to a text file with the .tp extension. Once you've selected the file, give the profile a name, and check the box to Set as current active tracking profile, then click OK three times.

Also note that Dublin enables you to configure WCF Diagnostic traces (which write to files independent from the Dublin monitoring database) from the same Monitoring configuration screen.

More Options for Services Troubleshooting

Because setting up your service to run in Dublin can be as simple as changing the project properties from running under the ASP.NET Development Server to running under IIS, it makes a lot of sense to use Dublin's powerful monitoring tools from the beginning of any services development project. The functionality provided by Dublin naturally carries forward to test and production with the appropriate configuration changes to adjust the volume of logged data. The one place where you cannot use Dublin for monitoring is in the scenario where your ServiceHost or WorkflowServiceHost are self hosted in their own process. Here you must use ETW or the Visual Studio Debugger.

Zoiner Tejada ([email protected]) is passionate about workflow and the future of implementing connected systems with them. He's the chief software architect at Hershey Technologies, is recognized as a Microsoft Industry Influencer, and is an advisor to Microsoft's Connected Systems Division. Zoiner has a degree in computer science from Stanford University and blogs at

Figure 5: Sample ETW log content

Event ID

Value in General Tab


The transport has received a message at a listen URI






text/xml; charset=utf-8







The operation 'GetData' of an instance of: 'a2983685-5516-401f-9d6c-cbc5025d18a3' invoked.


TrackRecord= WorkflowInstanceRecord, InstanceID = {a2983685-5516-401f-9d6c-cbc5025d18a3}, RecordNumber = 0, EventTime = ‎2009‎-‎08‎-‎02T13:25:12.287109300Z, Level = Info, State = Started, Annotations = , ProfileName = JustRightDebugProfile


TrackRecord = ActivityScheduledRecord, InstanceID = {a2983685-5516-401f-9d6c-cbc5025d18a3}, RecordNumber = 1, EventTime = ‎2009‎-‎08‎-‎02T13:25:12.287109300Z, Level = Info, Name = , ActivityId = , ActivityInstanceId = , ChildActivityName = Sequential Service, ChildActivityId = 1, ChildActivityInstanceId = 1, Variables=, Annotations=, ProfileName = JustRightDebugProfile


TrackRecord = ActivityScheduledRecord, InstanceID = {a2983685-5516-401f-9d6c-cbc5025d18a3}, RecordNumber = 2, EventTime = ‎2009‎-‎08‎-‎02T13:25:12.287109300Z, Level = Info, Name = Sequential Service, ActivityId = 1, ActivityInstanceId = 1, ChildActivityName = ReceiveRequest, ChildActivityId = 2, ChildActivityInstanceId = 2, Variables=, Annotations=, ProfileName = JustRightDebugProfile

additional records elided for clarity


TrackRecord = ActivityTrackingRecord, InstanceID = {a2983685-5516-401f-9d6c-cbc5025d18a3}, RecordNumber=11, EventTime=‎2009‎-‎08‎-‎02T13:25:12.290039000Z, Level = Info, State = Closed, Name=ReceiveRequest, ActivityId=2, ActivityInstanceId=2, Variables=, Annotations=, ProfileName = JustRightDebugProfile

Figure 6: Sample web.config that enables ETW tracing

behaviorConfiguration="DeclarativeSequentialServiceLibrary1.Service1Behavior" >

logMessagesAtServiceLevel="true" logMessagesAtTransportLevel="false" />

type="System.Activities.Tracking.EtwTrackingParticipant, System.Activities, Version=,

Culture=neutral, PublicKeyToken=31bf3856ad364e35"



Figure 7: Section of trace showing value of the "data" variable


TrackRecord = ActivityTrackingRecord, InstanceID = {11710778-2020-4b64-b46f-da39fa81bbdb}, RecordNumber=11, EventTime=‎2009‎-‎08‎-‎02T15:16:05.935546800Z, Level = Info, State = Closed, Name=ReceiveRequest, ActivityId=2, ActivityInstanceId=2, Variables=, Annotations=, ProfileName = JustRightDebugProfile

Hide comments


  • Allowed HTML tags: <em> <strong> <blockquote> <br> <p>

Plain text

  • No HTML tags allowed.
  • Web page addresses and e-mail addresses turn into links automatically.
  • Lines and paragraphs break automatically.