Windows Communication Foundation (WCF) is the easiest way to produce and consume Web services on the Microsoft platform. With .NET 3.5, WCF has been extensively revamped?and Visual Studio 2008 gives developers powerful new tools for utilizing it. Essential Windows Communication Foundation shows developers exactly how to make the most of WCF with .NET 3.5 and Visual Studio 2008.
Drawing on extensive experience working with early adopters, three Microsoft insiders systematically address the topics developers ask about WCF. The authors approach each subject with practical advice and present best practices, tips, and tricks for solving problems. Throughout, you’ll find detailed explanations, solutions for the “pain points” of WCF development, and an extensive collection of reusable code examples. Coverage includes:
- Using WCF contracts to define complex structures and interfaces
- Understanding WCF’s channel stacks and channel model architecture
- Configuring the WCF communication stack to use only the protocols you need
- Using standard and custom service behaviors to manage concurrency, instances, transactions, and more
- Serializing data from .NET types to XML Infosets and representing Infosets “on the wire”
- Hosting WCF services via IIS, managed .NET applications, and Windows Activation Services
- Implementing WCF security, in depth: authentication; transport and message-level security; and Internet and intranet scenarios
- Improving reliability: exception handling, diagnostics, and more
- Workflow services: new integration points between WCF 3.5 and Windows Workflow Foundation
- Building client-to-client, peer network-based applications
- Utilizing WCF for non-SOAP Web services: AJAX and JSON examples and .NET 3.5 hosting classes
Chapter 9 covers WCF Diagnostics. Working with a sample application, you’ll find out how to configure WCF to use end-to-end tracing, correlating WCF activities with traces via a GUID (activityID), implement message logging, use shared listeners to output message data from multiple sources to a shared file, analyze and filter messages, use performance counters, and WMI, and simplify your configuration tasks with the Service Configuration Editor.
Reproduced from Essential Windows Communication Foundation (WCF): For .NET Framework 3.5 by permission of Addison Wesley. Copyright ? 2007 Pearson Education. ISBN-10: 0-321-44006-4, ISBN-13: 978-0-321-44006-8. All rights reserved.
s you’ve seen in the previous chapters, WCF offers numerous options for configuring your distributed applications and for extending WCF with custom code. Combine that with the complexities of cross-machine and even cross-company interactions and you have many places to look for sources of unexpected behavior.
Debugging distributed applications can be a challenging prospect. Even if you do have access to the processes and symbol tables necessary for stepping through flow across service call boundaries, remote logic might have been created by a different team with different coding and execution practices. There is also the difficulty of filtering diagnostic information to isolate a particular flow of execution?for example, a single user’s session across multiple services and machines.
However, the challenge of any distributed system is not only its initial development, but ensuring ease of maintenance as that application is utilized in production scenarios. IT administrators need efficient means for finding root causes of issues so that the responsible company and development team can be notified.
Fortunately, WCF has a number of built-in features and tools for diagnosing causes of issues, often without much more effort than electing to enable those features in your configuration files. As you’ll see in this chapter, WCF utilizes and builds on the native tracing and diagnostics features of the .NET Framework. This allows you to leverage your existing knowledge, and it enables integration of WCF applications’ diagnostics with those of other applications.
In this chapter, we describe how to use tracing facilities to capture WCF events and logging to capture details of exchanged messages. Trace listeners are described, along with examples that show how to configure the settings for different events. The Service Trace Viewer, a powerful tool that is included with WCF, is also described, which enables you to inspect activities across service call boundaries.
Sample WCF Application
This chapter uses the SelfHost sample application that is included with the Windows SDK. Details on obtaining, configuring, and running the sample can be found on MSDN at http://msdn2.microsoft.com/en-us/library/ms750530.aspx. If you have the SDK installed, you’ll find the SelfHost application under BasicServiceHostingSelfHost with both C# and VB.NET versions available.
SelfHost is an introductory sample consisting of simple service and client Windows console projects. The client console application makes several calls to the WCF service, and results are displayed on both the client and service consoles.
The core diagnostics capabilities of WCF build on the existing tracing facilities provided by the .NET Framework itself. The System.Diagnostics namespace includes classes that enable applications to easily emit tracing information and store those details in a variety of formats and locations.
System.Diagnostics features tracing capabilities organized around the concepts of trace sources and trace listeners. Trace sources are configured using the System.Diagnostics.TraceSource class and enable applications to emit details of execution, such as data or events. The traces emitted by a trace source can be received and processed by one or more trace listeners, classes derived from the abstract base class System.Diagnostics.TraceListener.
WCF natively utilizes these features to emit details about the actions occurring during the processing of service calls and responses. No custom code is required to create these details and the developer or IT administrator need only add configuration to enable the source and listener, as described next. However, developers are free to add their own tracing calls to emit additional details as desired.
A central feature for monitoring WCF applications is called end-to-end (E2E) tracing. This concept utilizes System.Diagnostics features of the .NET Framework to pass identifiers between the various entities of a distributed application so that their actions can be correlated into a logical flow. Using E2E tracing, it is possible to follow a sequence of actions across service and machine boundaries?for example, from request origination on the client through the business logic invoked by the target service.
E2E tracing uses a specific XML schema to persist details of processing across logical boundaries. The XML is created by registering an instance of the System.Diagnostics.XMLWriterTraceListener, which processes trace information into the E2E XML format (defined at http://schemas.microsoft.com/2004/06/E2ETraceEvent).
The code below shows an abridged E2E trace XML fragment:
131085 LAERTES Activity boundary. Host.vshost.exe Construct ServiceHost 'service'. Construct
Note in particular the Correlation node and the ActivityID property. These are the keys to combining individual trace fragments from a variety of sources into a unified logical flow. The concepts behind correlation are described next.
Activities and Correlation
A WCF activity is a logical subset of functionality used to group traces for ease of identification and monitoring. An example is the processing of a call into a service endpoint. Although activities are independently useful, effective monitoring requires a mechanism to track flow between multiple activities.
Correlation is the concept of associating multiple activities to create a logical sequence of flow in a distributed application. Correlation is performed via transfers, linking activities within an endpoint, and propagation, linking activities across multiple endpoints.
Activities are correlated by the interchange of an identifier called the activity ID. This identifier, a GUID, is generated by the System.Diagnostics.CorrelationManager class. CorrelationManager is associated with a trace and can be retrieved via the static property System.Diagnostics.Trace.CorrelationManager. It has two primary methods, StartLogicalOperation() and StopLogicalOperation(), used to link associated actions into a logical unit for tracing purposes.
Tracing is disabled by default and can be enabled by configuring a trace source to emit information and trace listeners to process and save the final trace details.
Here are the relevant portions of the SelfHost App.config file configured for tracing:
In the preceding code, the node references the System.ServiceModel trace source, which is the source used by WCF to emit tracing details. In the
|Author’s Note: Service Configuration Editor?To avoid having abstractions hide the mechanics of WCF diagnostics, we’re enabling tracing and message logging by manually specifying settings in the respective App.config files. Later in this chapter, we’ll show how to use the Service Configuration Editor to quickly and accurately make such changes without editing the configuration files directly. The trace source has a switchValue property that is used to specify the level of detail that should be captured. Table 1 shows the possible values for the switchValue property when configuring the trace source.|
|Off||Disables the trace source.|
|Critical||Tracks the most serious application and environmental failures, such as a service failing, or a service being unable to start.|
|Error||Issues with application logic or the environment?for example, an unrecoverable exception.|
|Warning||Scenarios that may result in an exception or failure in the future, or notifications that the application recovered from an exception.|
|Information||Details about system events that may be helpful for debugging, simple auditing, and overall monitoring.|
|Verbose||Full information at each processing step. Useful for pinpointing sources of issues.|
|ActivityTracing||Uses correlation to track flow between logically connected components of the distributed application.|
Note that ActivityTracing can be combined with a verbosity selector (for example, switchValue=”Warning, ActivityTracing”).
Using the more verbose options for tracing can quickly lead to large amounts of traced information, which can add to system overhead and increase the challenge of separating the relevant data from extraneous data. When diagnosing an issue, we recommend that you begin tracing at the Warning level.
When operating under normal production conditions, consider leaving tracing off or at Critical or Error until conditions require further information for diagnostics or monitoring.
Tracing is used to record the flow and individual actions of the various components of a distributed application. Another feature, message logging, is used to record the contents of the messages from or to clients and services. Message logging can be configured to capture messages at the service level, the transport level, and to record messages that are malformed. The data captured via message logging can be useful for a variety of situations, from diagnostics to creating audit trails of service utilization.
Enabling Message Logging
Like tracing, message logging is based on System.Diagnostics and is disabled by default. It can be enabled first by adding a trace listener (for example, XMLWriterTraceListener) to process messages from the System.ServiceModel.MessageLogging trace source.
Here’s the SelfHost application configuration, configured for message logging:
Unlike tracing, however, the format and verbosity of messages emitted by the MessageLogging source is specified in a
|logEntireMessage||False||If true, both the message header and body are logged. If false, only the message header will be logged.|
|logMalformedMessages||False||Logs incorrectly formatted messages.|
|logMessagesAtServiceLevel||False||Logs messages as received or sent by the service itself.|
|logMessagesAtTransportLevel||False||Logs messages either just before encoding for transport or directly after being received from transport.|
|maxMessagesToLog||10,000||Number of logged messages after which further logging will be suspended.|
|maxSizeOfMessageToLog||262,144||Maximum message size, in bytes, that will be logged. If a message exceeds this limit, it will be ignored and a warning trace will be emitted.|
Note that messages logged at the transport level may be encrypted, depending on the binding or configuration options you have selected.
Additional Configuration Options
The previous sections described basic approaches for configuring logging and tracing. In this section, we’ll describe several other options that you should be aware of for configuring your WCF application.
The previous examples have used dedicated listeners for each of the sources (messages and tracing). You may choose to configure a shared listener and assign multiple sources, unifying the output to a single item, such as an XML file. The code below shows how to configure both tracing and message logging to use the same output file:
For each source, the code ads add a listener whose name matches the name of one of the shared listeners. In this case, we’re matching the “diagnostics” listener, which will write traces and messages to the same diagnostics.svclog file.
By default, all messages appropriate for the level specified in the
Message filters are XPath expressions that must be satisfied before a message will be logged. Messages that do not match the XPath queries are excluded, except for malformed messages, which are not affected by filters.
Specify the filters by adding a
/s12:Envelope/s12:Header/wsa10:Action[ starts-with(text(), 'http://Microsoft.ServiceModel.Samples/ICalculator')]
This example may seem complex, but the bulk of it defines the namespaces used in the XPath expression. Those namespaces are for the SOAP envelope and addressing schemas. The expression checks the header of each message to ensure it is directed to one of the ICalculator services defined in our SelfHost example. Messages for other services are ignored.
Trace Source Auto Flushing
If you want each tracing or message logging operation to automatically complete (write to disk) after each trace, enable auto flushing in the
Trace auto flushing is off by default. Before enabling auto flushing in production scenarios, be certain to measure the impact in a test environment because it can add overhead, especially as message traffic increases.
Three sets of WCF-related performance counters are installed with the .NET Framework 3.0. In Performance Monitor, you can see these counters under ServiceModelService, ServiceModelEndpoint, and ServiceModelOperation. You can choose to enable these for your application via configuration as follows:
Enable performance counters by including the performanceCounters attribute in the
|Author’s Note: Observing Performance Counters?You need a running instance of a WCF service or client to add performance counters in the Performance Monitor application. Ensure performance counters are enabled in configuration and start your service, then add the counters you want to observe, and then run your client application.|
Windows Management Instrumentation (WMI)
WCF supports the capability to expose settings and status via Windows Management Instrumentation, or WMI. Many popular application administration and management applications, such as Microsoft Operations Manager and HP OpenView, use WMI to access various systems across an enterprise. Windows PowerShell also has native WMI capabilities, enabling you to write custom scripts for specific management and monitor scenarios.
You can enable the WMI provider for your WCF application in configuration like this:
Enabling WMI is similar to enabling performance counters. Add the wmiProviderEnabled attribute to the
Using the Service Configuration Editor
So far this chapter has discussed manual XML-based methods of updating configuration files to enable tracing and message logging. In practice, there’s an easier and less error-prone way to add and modify configuration settings using the SDK tool, Service Configuration Editor. If the Window SDK has been installed, this editor can be found under All Programs ? Microsoft Windows SDK ? Tools. However, in Visual Studio you can quickly launch the editor by right-clicking a configuration file and choosing Edit WCF Configuration.
Let’s use the Service Configuration Editor on the service project’s App.config file. Right-click the SelfHost service project’s App.config file, choose Edit WCF Configuration, and select the Diagnostics node from the Configuration pane.
To enable message logging and tracing, click the “Enable MessageLogging” and “Enable Tracing” hyperlinks. Doing so will configure the system as shown in Figure 1.
|Figure 1. Tracing and Message Logging Enabled|
Notice that the listeners and sources are now displayed in the left panel. You can now click the hyperlinks in each section to configure other related options.
Once tracing is enabled, explore the available options by clicking the link next to the Trace Level label.
Here you can elect to enable activity propagation and tracing (described earlier in this chapter, and both are typically enabled) as well as the verbosity level from Off through Verbose. Remember that the trace level will affect the amount of space consumed by trace logs. A large log is more difficult to navigate, so you should typically choose the least verbose level necessary.
|Figure 2. Advanced Message Logging Settings|
To access the Message Logging Settings dialog, click the link next to the Log Level label in the MessageLogging section. As described earlier, you can choose to log any of three types of messages: those that are malformed, messages as they are received or sent by the service level, and messages as they are ready for transport or just received from transport.
Clicking the Message Logging item inside the Diagnostics node on the left panel will show the advanced logging settings options shown in Figure 2.
These options affect the behavior of the ServiceModel.MessageLogging source. They relate directly to the
|Figure 3 Message Logging XPath Filter|
Earlier, we showed that message logging supports the concept of filters to log only those messages that pass specified XPath filters. The Message Logging node in the Service Configuration Editor exposes a New XPath Filter option in the Tasks pane. Figure 3 shows the same XPath filter we used earlier defined in the Service Configuration Editor.
The tool lets you specify the maximum number of nodes to search (the nodeQuota attribute) and lists commonly used namespaces, along with the prefix for each. You can add more namespaces if you need and reference them via the prefix in your XPath expression.
Enabling tracing and logging via the Service Configuration Editor will automatically configure the System.ServiceModel and System.ServiceModel.MessageLogging trace sources. To see them, expand the Diagnostics/Sources node in the Configuration pane. Select the System.ServiceModel source and you will see the settings shown in Figure 4.
|Figure 4. Trace Source Settings|
On this screen, you can view or change the verbosity level as well as whether activity tracing and propagation will be used. Note that activity tracing and propagation are available only for tracing listeners and not for message logging listeners.
Returning to the main diagnostics screen (shown in Figure 1), you can access detailed listener settings by clicking the links for each listener name (for example, ServiceModelTraceListener). These options, shown in Figure 5, enable you to specify the target file for the listener as well as multiple options for the details included with each trace or message.
The check boxes relate to the System.Diagnostics.TraceOptions enumeration. The basic options are to include Timestamp, Process ID, Thread ID, Callstack, and/or DateTime of the trace. The Logical Operation Stack includes the correlation “stack” of the trace, essentially the correlated history of the trace, which is not necessarily the same as the environmental callstack.
For a summary of each listener’s settings, expand the Listeners node in the Configuration pane and click a listener. This displays the option summary for each listener, shown in Figure 6.
Here you can quickly review or change all the listeners’ configuration options.
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.
|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.
Analyzing Logs from Multiple Sources
|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|
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.