Service Trace Viewer
We've described how to enable various options for tracing and message logging, but how will the output of those diagnostic tools be put to effective use? Even over a brief period of time, tracing and message logging can emit large amounts of data.
WCF works with a powerful tool for analyzing diagnostics logs called the Service Trace Viewer. This tool can be used to import both trace and message log files from one or more components of a distributed application. After installing the Windows SDK, you can find the Service Trace Viewer via the All Programs → Microsoft Windows SDK → Tools menu.
|TIP: Configuring the SelfHost Example—In this section, we have enabled tracing and message logging for both the client and service projects. To follow along on your computer, use the Service Configuration Editor described earlier to enable tracing and message logging in both projects, selecting Information verbosity levels and defaults for all other settings. After it is configured, run the application to generate client and service log files.
Let's use the Service Trace Viewer to analyze the log files generated by the SelfHost
example. Launch the Service Trace Viewer and choose File → Open from the menu. Find the SelfHost/client
directory and select both the trace (app_trace.svclog
) and message (messages.svclog
) log files by holding the Shift key while clicking each. Be certain to select them both because subsequent uses of Open will clear any previously loaded information. (We'll later use File → Add to merge additional logs.)
|Figure 7. Service Trace Viewer with Client Trace and Message Logs|
The Service Trace Viewer is able to merge the contents of multiple trace and log files. Figure 7
shows the Service Trace Viewer with the SelfHost
client project's log files loaded.
This screen shows the merged results in the default Activity view. The left pane lists each of the activities along with the number of traces they contain, the duration, the start time, and the end time. When one or more activities are selected, the upper-right pane shows the individual traces associated with the selected activities.
|TIP: Warnings and Exceptions—Service Trace Viewer displays activities containing warning traces highlighted in yellow. Those with exceptions in their traces are shown with red text.
The first activity, 000000000000, is a dedicated root activity from which all others are linked. Moving down the list, we see the activities the client processed during the program run. First, ChannelFactory is constructed and opened, enabling communications with the service.
Each service call is shown as a Process action activity. There are four of these in our trace, relating to the Add, Subtract, Multiply, and Divide services that our client code invokes. The client also negotiates a secure session (Set Up Secure Session) as required by the service binding options.
Click the various activities and note the list of associated traces shown in the top-left pane. You can see the type of trace and a brief description. We'll see in a moment another option for inspecting these traces.
Another view, the Project view, can be shown by clicking the Project tab in the left pane. The Service Trace Viewer supports the concept of projects. A project enables you to specify multiple tracing and logging files that should be loaded when the project is opened. This is especially useful when you have multiple participants (for example, a client calling multiple services) that you are debugging together. From the File menu, choose Save Project after you have loaded the files you want to associate.
|Figure 8. Service Trace Viewer Message View|
The Project view displays the files associated with the current project. Using this view, you can create or modify projects and add or remove associated files.
The Message view lists all the logged messages, independently of any correlated activities. This is useful for quickly finding a specific message—for example, the message sent to the Multiply service—and inspecting its contents.
Figure 8 shows the Message view, highlighting the message sent from the client to the Divide service.
|Figure 9. Service Trace Viewer Graph View|
The Graph view is the most complex, yet potentially useful option in the Service Trace Viewer. You can access it by double-clicking any activity or message in the previous views or by selecting the Graph tab. The Graph view shown will be similar to Figure 9
In this view, the activities are now arranged across the top of the left pane. The vertical "swimming lanes" show each trace within those activities, with connections between correlated activities. Select any trace on the left side and the right pane will highlight that trace among all traces for that activity.
The primary benefit of this view will be seen in a moment when we include trace files from the service project.
Analyzing Logs from Multiple Sources
|TIP: Live Service Trace Viewer—Although the Service Trace Viewer is excellent for after-the-fact analysis of service interactions, a sample tool, called the Live Service Trace Viewer, offers an alternative approach. This application uses a custom TraceListener and a Windows Presentation Foundation (WPF) interface to receive and display diagnostic information as it occurs, which can be very useful, especially during development to avoid the manual process of continually reloading log files between runs.
Note that the Live Service Trace Viewer is not supported by Microsoft, but is an interesting example of how WCF diagnostics can be extended.
Details and code can be found at http://blogs.msdn.com/craigmcmurtry/archive/2006/09/19/762689.aspx.
|Figure 10. Service Trace Viewer with Service and Client Logs Loaded|
Although the Service Trace Viewer is helpful for viewing the logs for a single service or client, the real power of both the tool and of end-to-end tracing is realized when log files are added from more than one participant of a distributed application.
To see this, choose File → Add (which, unlike File → Open, merges new logs with currently loaded logs) and select the SelfHost service project's tracing and message logs. The service log files will be imported and correlated with the previously loaded client logs, as shown in Figure 10.
As you can see, there is much more detail available to us. The activity list now displays activities for both the client and service projects.
|Figure 11. Service Trace Viewer Graph of Activity Transfer|
Select the Process Action activity for the Subtract
service call and either double-click it or click the Graph tab above. You should see the Graph view similar to Figure 11
Now we can see how the Graph view can help us visualize otherwise complex interactions between services and callers. The top of the main pane organizes the activities by host, in our case service and client. Hover the mouse pointer over each activity to see its description. As you expand the traces within activities, you may see visual indicators of correlation between activities.
In Figure 11, you can see that the client sent a message to the service, the service processed that message by calling the Subtract method, and then a response message was created and sent back to the client. This visualization is possible because of end-to-end tracing and the use of correlation to link activities.
|Figure 12. Service Trace Viewer with Expanded Subtract Call Activity|
Clicking the plus symbol next to the highlighted trace in Figure 11
expands the display to show us another level of detail. Figure 12
shows the resulting detail.
A new activity is displayed under the service.vshost block, Execute 'Microsoft.ServiceModel.Samples.ICalculator.Subtract.' If there had been any exceptions or warnings traced, we would see them in the Graph view as yellow triangles or red circles, respectively. By expanding details to show contained activities and observing how interactions between activities and hosts are correlated, you can quickly use the Service Trace Viewer to locate the sources of unexpected behavior, whether you are a developer creating a distributed application or an IT professional investigating reported issues in production.
You may find, especially with production-generated log files, that locating specific information in trace and message logs can become a challenge. For example, you may know that a particular user's session led to unexpected behavior (and for the sake of example, let's say there were no warnings or exceptions thrown, only incorrect data). This would be an extremely challenging prospect, but the Service Trace Viewer offers a flexible infrastructure for finding and filtering entries.
In the toolbar, the Find What option enables you to quickly search all traces for matching text. For example, type "Divide" and click Find. The trace list will highlight those traces containing that word.
|Figure 13. Creating a Custom Filter in the Service Trace Viewer|
You can use the Look For box to quickly limit the displayed traces to those matching your criteria. Click the Search In drop-down and select criteria (for example, Start Time). The Look For field becomes enabled. Enter the earliest time you are seeking and click Filter Now. The activities list displays only those activities that started on or after the selected time. You can also use the Level field to select the severity of messages you want to see (for example, Warning). The Clear button returns the results to the unfiltered view.
The most powerful filtering option is the capability to create and save custom filters. Click the Create Custom Filter button at the top of the trace list to see a dialog similar to Figure 13.
This editor allows composition of filters with one or more XPath expressions. The nodes and attributes in the left pane default to those of the activity or trace that was selected when the Create Custom Filter button was clicked. Select the attribute(s) you want to query and then give the filter a name and description. After clicking OK, you can select your custom filter from the Search In list on the top toolbar to constrain the display to show only entries matching your custom filter.
In this chapter, we described how WCF utilizes much of the native functionality of the .NET Framework to improve developers' and IT professionals' abilities to diagnose issues in distributed applications.
End-to-end tracing is the concept where logically related actions in different areas of applications, and perhaps on different systems altogether, can be linked to improve our ability to follow specific scenarios through logged information. This correlation is performed by passing unique identifiers within and between endpoints of a WCF system.
Tracing and logging are simple to enable and configure, building on familiar concepts from the System.Diagnostics namespace. Tracing gives us insight into the actions occurring in our distributed applications. Message logging enables us to inspect the actual data being passed between clients and services.
The Service Configuration Editor is a useful Windows SDK tool that helps developers and administrators quickly and reliably inspect and change WCF configuration settings, including options for diagnostics.
Finally, we saw how the Service Trace Viewer, also included with the Windows SDK, is a powerful tool for visualizing and inspecting the often large amounts of data captured through tracing and message logging. It is especially useful when exceptions and warnings occur and multiple systems (or companies) are potentially involved. Developers or administrators can use the Service Trace Viewer to quickly isolate sources of unexpected behavior.
The diagnostic capabilities of WCF are an easy-to-use yet powerful way to ensure that your complex distributed applications can be effectively maintained and extended.