OmegaCodex: 2015

In service oriented environment, debugging an issue can often become difficult especially if something is failing during the communication between the service and client. .NET provides a System.Diagnostics namespace which allows us to interact with system process, event logs and other counters. WCF tracing is built on top on this namespace.

To use WCF tracing, we can define the trace sources either in configuration file or in code. Here in this blog I will explain how to define it in configuration file. The System.ServiceModel trace source is the most general trace source which records milestones across the WCF communication stack from entering/leaving transport to entering/leaving user code. The System.ServiceModel.MessageLogging source records all messages that flow through the system.

This tracing is not enabled by default. To activate it, we must create a listener and set the trace level to something other than “Off”. If we do not define a listener, tracing is automatically disabled. If we define a listener, but not a trace level, it is automatically set to “Off” and hence no tracing is performed.

We start with defining <system.diagnostics> tag in configuration file.

<configuration>

<system.diagnostics>

</system.diagnostics>
</configuration>

WCF has a set of predefined trace sources available for each assembly.

· System.ServiceModel:

· System.ServiceModel.MessageLogging

· System.IdentityModel.

· System.ServiceModel.Activation.

· System.IO.Log:

· System.Runtime.Serialization:

· CardSpace.

The first step is to define the source for tracing. For example “System.ServiceModel”

<source name="System.ServiceModel">

We need to set a proper tracing level other than “Off” for the above mentioned source to enable the tracing. Following tracing levels are available:

Trace Level	Tracked Events
Off	No traces are emitted.
Critical	Unhandled exceptions including the following are logged: OutOfMemoryException ThreadAbortException (the CLR invokes any ThreadAbortExceptionHandler) StackOverflowException (cannot be caught) ConfigurationErrorsException SEHException Application start errors Failfast events System hangs Poison messages: message traces that cause the application to fail.
Error	All exceptions are logged.
Warning	The application is receiving more requests than its throttling settings allow. The receiving queue is near its maximum configured capacity. Timeout has exceeded. Credentials are rejected.
Information	In general, messages helpful for monitoring and diagnosing system status, measuring performance or profiling are generated. You can use such information for capacity planning and performance management: Channels are created. Endpoint listeners are created. Message enters/leaves transport. Security token is retrieved. Configuration setting is read.
Verbose	In general, you can use this level for debugging or application optimization. Understood message header.
ActivityTracing	This level allows administrators and developers to correlate applications in the same application domain: Traces for activity boundaries, such as start/stop. Traces for transfers.
All	All previous events.

The tracing level is determined by the switchValue setting of the source.

<source name="System.ServiceModel" switchValue="Information">

Next step is to configure a listener. To define a listener we need to add the following to config file.

<source name="System.ServiceModel" switchValue="Information">

There are different kinds of listeners available but I have chosen XmlWriterTraceListener for this example. We can add any number of listeners to each source. If the trace listener emits trace to a file, we need to specify the output file location. This is done by setting initializeData to the location and name of the file. The advantage of using XmlWriterTraceListener is that we can open this log file in SvcTraceViewer.exe (Service Trace Viewer Tool) which helps us analyze traces generated by WCF.

So putting all together the file appears like this:

<system.diagnostics>

<source name="System.ServiceModel"

switchValue="Information">

<add name="traceListener"

type="System.Diagnostics.XmlWriterTraceListener"

initializeData="D:\log\Traces.svclog" />

</listeners>

</source>

</sources>

</system.diagnostics>

</configuration>

The .svclog file generated can be directly opened in Service Trace Viewer Tool by double clicking the file. The tool can also be found under

C:\Program Files\Microsoft SDKs\Windows\v7.0A\bin\ or C:\Program Files (x86)\Microsoft SDKs\Windows\v7.0A\bin\

Shown below is the screenshot of the tool.

Service Trace Viewer Tool (SvcTraceViewer.exe)

Configuring Shared Listeners

In case of multiple trace sources, we can also configure all traces sources to use the same listener using <sharedListeners>. Please see the below example for usage of <sharedlisteners>

<configuration>

    <system.diagnostics>
        <sources>
          <source name="System.ServiceModel"
                    switchValue="Information, ActivityTracing"
                    propagateActivity="true">
                <listeners>
                    <add name="xml" />
                </listeners>
            </source>
            <source name="System.IO.Log">
                <listeners>
                    <add name="xml" />
                </listeners>
            </source>
            <source name="System.Runtime.Serialization">
                <listeners>
                    <add name="xml" />
                </listeners>
            </source>
       </sources>
        <sharedListeners>
            <add name="xml"
type="System.Diagnostics.XmlWriterTraceListener"
                 initializeData="D:\log\Traces.svclog" />
        </sharedListeners>
    </system.diagnostics>
</configuration>

Enable Message Logging

To activate tracing for System.ServiceModel.MessageLogging we need to set attributes for <messagelogging> element as well. This has be set under <system.serviceModel> tag.

<system.diagnostics>
<sources>
      <source name="System.ServiceModel.MessageLogging">
        <listeners>
                 <add name="messages"
                 type="System.Diagnostics.XmlWriterTraceListener"
                 initializeData="D:\log\messages.svclog" />
          </listeners>
      </source>
    </sources>
</system.diagnostics>
<system.serviceModel>
<diagnostics>
    <messageLogging
         logEntireMessage="true"
         logMalformedMessages="false"
         logMessagesAtServiceLevel="true"
         logMessagesAtTransportLevel="false"
         maxMessagesToLog="3000"
         maxSizeOfMessageToLog="2000"/>
</diagnostics>
</system.serviceModel>

logEntireMessage: By default, only the message header is logged but if we set it to true, the entire message including message header as well as body will be logged.
logMalformedMessages: This option logs messages that are rejected by WCF stack at any stage known as malformed messages.
logMessagesAtServiceLevel: Messages those are about to enter or leave user.
logMessagesAtTransportLevel: Messages those are about to encode or decode.
maxMessagesToLog: Maximum quota for messages. Default value is 10000.
maxSizeOfMessageToLog: Message size in bytes.

OmegaCodex

Thursday, February 19, 2015

WCF Tracing