Logging, Tracing and Exception Management in Commerce Foundation

The Microsoft Multi-Channel Commerce Foundation Logging and Tracing is based on the .NET Framework's System.Diagnostics facilities provided for Tracing and Instrumenting Applications in Visual Basic and Visual C#, as described in the Visual Studio .NET documentation.

Exception Management provides a consistent and flexible mechanism to handle errors in all Commerce Server 2009 R2 subsystems from the Commerce Server Core Systems to the presentation layer. Exception Management relies on the logging feature to record exception information.

Logging and Tracing

The Commerce Server 2009 R2 Logging and Tracing mechanisms contain three main classes that help to make logging and tracing consistent and efficient, they are: Logger, Tracer and EtwTraceListener.

The driver for tracing and logging is the Logger class that serves as a wrapper for the functionality provided by the System.Diagnostics.TraceSource and exposes two public overloaded methods: LogMessage and LogTrace. The LogMessage method forwards the calls to the System.Diagnostics.TraceSource instance that is identified in the configuration file by the Microsoft.Commerce.Trace.Messages name. The following is an example of the System.Diagnostics configuration for the Microsoft Multi-Channel Commerce Foundation tracing:

<system.diagnostics>
  <sources>
    <source name="Microsoft.Commerce.Trace.Client"
            switchName="CommerceTraceSwitch">
      <listeners>
        <add name="CommerceEtwTraceListener" />
      </listeners>
    </source>

    <source name="Microsoft.Commerce.Trace.Presentation"     
            switchName="CommerceTraceSwitch">
      <listeners>
        <add name="CommerceEtwTraceListener" />
      </listeners>
    </source>

    <source name="Microsoft.Trace.Server"     
            switchName="CommerceTraceSwitch">
      <listeners>
        <add name="CommerceEtwTraceListener" />
      </listeners>
    </source>

    <source name="Microsoft.Commerce.Trace.SequenceComponents"     
            switchName="CommerceTraceSwitch">
      <listeners>
        <add name="CommerceEtwTraceListener" />
      </listeners>
    </source>

    <source name="Microsoft.Commerce.Trace.CoreSystems"     
            switchName="CommerceTraceSwitch ">
      <listeners>
        <add name="CommerceEtwTraceListener" />
      </listeners>
    </source>

    <source name="Microsoft.Commerce.Trace.Custom"     
            switchName="CommerceTraceSwitch">
      <listeners>
        <add name="CommerceEtwTraceListener" />
      </listeners>
    </source>

    <source name="Microsoft.Commerce.Auditing"
            switchName="CommerceAuditingSwitch">
      <listeners>
        <add name=" CommerceEtwTraceListener "
      </listeners>
    </source>

    <source name="Microsoft.Commerce.Exceptions" switchValue="Error">
      <listeners>
        <add
            name="EventLogExceptionsListener"
            type="System.Diagnostics.EventLogTraceListener"
            traceOutputOptions="None"
            initializeData="Commerce API Test" >
            <filter type="System.Diagnostics.EventTypeFilter" initializeData="All" />
        </add>
      </listeners>
    </source>

    <source name="Microsoft.Commerce.SessionsFaults" switchValue="Information">
      <listeners>
        <add
            name="SessionTokenEventLogListener"
            type="System.Diagnostics.EventLogTraceListener"
            traceOutputOptions="None"
            initializeData="Commerce SessionToken Log">
            <filter type="System.Diagnostics.EventTypeFilter" initializeData="All" />
        </add>
      </listeners>
    </source>

  </sources>

  <switches>
    <add name="CommerceTraceSwitch" value="All"/>
  </switches>

  <sharedListeners>
    <add 
name="CommerceEtwTraceListener"
type="Microsoft.Commerce.Server.EtwTraceListener, Microsoft.Commerce.Server">
<filter type="System.Diagnostics.EventTypeFilter" initializeData="All" />
    </add>
  </sharedListeners>
</system.diagnostics>

By using System.Diagnostics configuration it is possible to configure any standard trace listener such as: EventLogTraceListener, TextWriterTraceListener, XmlWriterTraceListener, and so on; or a custom one that derives from the System.Diagnostics.TraceListener to be used with the Microsoft Multi-Channel Commerce Foundation Logger.

LogTrace method works in a similar way to the LogMessage method since it also forwards the calls to the TraceSource class. However, the LogTrace uses different trace sources based on the value of the first parameter passed to the method. The first parameter of this method is the TraceLayer enumeration:

/// <summary>
    /// Intended to indicate the application layer at which the current Logger.LogTrace./> 
    /// operation is occurring.
    /// </summary>
    /// <remarks>
    /// <list type="bullet">
    /// <listheader>
    /// <term>Trace Layer Enumerations</term>
    /// </listheader>
    /// <item>
    /// <term>Presentation</term>
    /// <description>The presentation layer represents the user interface or target Channel>
    /// Presentation Channel for the current application instance.</description>
    /// </item>
    /// <item>
    /// <term>Server</term>
    /// <description>A "thin" layer used to determine the service to use in processing an individual 
    /// request object.  (For example; the two main services employed by the 
    /// application are the ConfigurationService and the OperationService.
    /// </description>
    /// </item>
    /// <item>SequenceComponents</item>
    /// <description>Providers are discrete units of loosely-coupled logic responsible for very specific 
    /// operations within the application, typically accessed either in-process or via the Windows 
    /// Communication Foundation (WCF).</description>
    /// </list>
    /// <para>This list is not comprehensive; but the type selected should accurately reflect the layer 
    /// wherein the traced operation occurs.</para>
    /// </remarks>
public enum TraceLayer
    {
        /// <summary>
        /// Indicates that the trace message originates from the Presentation application level
        /// </summary>
        Presentation,

        /// <summary>
        /// Indicates that the trace message originates from the Server application level
        /// </summary>
        Server,

        /// <summary>
        /// Indicates that the trace message originates from the Sequence Components application level
        /// </summary>
        SequenceComponents,

        /// <summary>
        /// Indicates that the trace message originates from the Core Systems application level
        /// </summary>
        CoreSystems,

        /// <summary>
        /// Indicates that the trace message originates from a custom application level
        /// </summary>
        Custom,

        /// <summary>
        /// Indicates that the trace message originates from the client application level
        /// </summary>
        Client,

        /// <summary>
        /// Indicates that the trace message is intended for the AuditingTraceSource
        /// </summary>
        Auditing,

        /// <summary>
        /// Indicates that the trace message is intended for the CommerceSessionTokenTraceSource
        /// </summary>
        CommerceSessionToken
    }

The following values of TraceLayer correspond to logical Commerce Server 2009 R2 tiers:

The TraceLayer.CommerceServer corresponds to the Commerce Server 2009 R2 code that directly invokes Microsoft Multi-Channel Commerce Foundation APIs within the Commerce Server 2009 R2 service. The TraceLayer.Custom is available for use by the custom components that extend the Commerce Server 2009 R2 functionality.

To reduce the performance impact of tracing, especially in production, it is recommended to use the Event Tracing for Windows APIs (ETW). Microsoft Multi-Channel Commerce Foundation provides the EtwTraceListener class that wraps ETW APIs and can be used as a System.Diagnostics trace listener.

The role of the CommerceEtwTraceListener provider is to register events with ETW session when one exists, where they can be accessed by the ETW consumers. An ETW session is created by an ETW controller. For example:

set CommerceEtwTracingFileName="c:\logs\CommerceEtwTracingFileName.etl" 
call logman create trace CommerceEtwTracingSession -o %CommerceEtwTracingFileName% -p "{790227F0-C820-4258-9826-1D521C29409C}"
call logman start CommerceEtwTracingSession

To stop recording the ETW events the ETW session should be ended, for example:

logman query CommerceEtwTracingSession 2>1 >NUL

IF %ERRORLEVEL% EQU 0 (
    logman stop -ets CommerceEtwTracingSession
    logman delete CommerceEtwTracingSession
)

The ETW log file can be viewed by using the Service Trace Viewer (SvcTraceViewer.exe) utility from the Windows SDK.

To add tracing to a new component you are building for Microsoft Multi-Channel Commerce Foundation the Tracer class is designed to make it easy to trace entry and exit points of the code blocks - most often the methods. The Tracer class implements IDisposable interface and is supposed to be used with the C# using statement. The Lifetime of the Tracer object determines the beginning and the end of the trace.

void SomeMethod()

{

using (new Tracer(TraceLayer.Custom))

{

// Method implementation goes here.

}

}

When constructed the Tracer object logs the TraceEventType.Start event and its timestamp using the Commerce Server 2009 R2 Logger.LogTrace. On leaving the using statement the Tracer object logs TraceEventType.Stop event and the duration of the code execution within the using statement using the Commerce Server 2009 R2 Logger.LogTrace. These event entries can be used for performance analysis in the production systems.

To enable tracing at any level be sure that the GlobalServiceConfiguration attribute enableTracing is set to true.

  <microsoft.commerce>
    <server>
      <!-- Set enabled="true" to enable all tracinf from the multichannel famework. -->
      <GlobalTracing enabled="false" />

Filtering

Two trace filter classes (EventIdFilter and EventIdExclusionFilter) allow developers to specify which faults to log. The default configuration logs all faults, except for those generated as a result of negotiating a session token with in the Commerce Routing Service.

<source name="Microsoft.Commerce.Exceptions" switchValue="Error">

<listeners>

<add name="EventLogExceptionsListener" type="System.Diagnostics.EventLogTraceListener" traceOutputOptions="None" initializeData="SharePoint Commerce Services Exceptions">

<!-- The following is a filter that will log all exceptions, except for those caused by missing or expired session tokens. These exceptions are common when the RoutingService is used. -->

<filter type="Microsoft.Commerce.Server.EventIdExclusionFilter, Microsoft.Commerce.Server, Version=9.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35" initializeData="0xB004,0xB005" />

</add>

</listeners>

</source>

Exception Management

The key class in the Exception Management is the ExceptionManager, which exposes a single overloaded method HandleException:

public static void HandleException(Exception exception)

public static void HandleException(string policyName, Exception exception)

where:

exception is the exception to handle;

If the policy name is not specified the default exception policy is used.

The power and flexibility of the ExceptionManager.HandleException method is based on the configurable exception policies. An exception policy is a named section in the configuration file that lists the exception handling components (exception handlers). When ExceptionManager.HandleException is invoked all the components specified in the exception policy are executed in the order they are listed in the configuration file. These components are required to implement the following interface:

    public interface IExceptionHandler
    {
        Exception HandleException(Exception exception);
        string InitializationData { get; set; }
    }

The IExceptionHandler.HandleException method, when implemented by a class, handles an exception. An exception handler can log exception information to a log, display an error window to the user, convert the original exception to a different exception type, and so on. Depending on the implementation this method returns either the original exception passed to it or a modified exception. The returned exception is passed to the next exception handler in the exception policy chain.

InitializationData is an optional property can be used to provide some initialization data to the handler. For example, the logging exception handler may have the trace source name provided through the InitializationData, this is an example of the Exception Management configuration:

<server>
 <CommerceExceptionHandling defaultPolicyName="Default">
    <exceptionPolicy name="Default">
      <exceptionHandler 
          name="TextLoggingExceptionHandler"
          type="Microsoft.Commerce.Server.TextLoggingExceptionHandler, Microsoft.Commerce.Server, initializeData="Microsoft.Commerce.Exceptions" />
</exceptionPolicy>

    <exceptionPolicy name="TestPolicy">
    <exceptionHandler
      name="WrappingExceptionHandler"
      type="Microsoft.Commerce.API.Test.Common.WrappingExceptionHandler, Microsoft.Commerce.API.Test" />
    <exceptionHandler 
      name="XmlLoggingExceptionHandler"
      type="Microsoft.Commerce.Server.XmlLoggingExceptionHandler, Microsoft.Commerce.Server" initializeData="Microsoft.Commerce.Exceptions" />
  </exceptionPolicy>
 </CommerceExceptionHandling>

All Exception Management configurations are contained within the <exceptionHandling> section, which consists of the collection of the exception policies configured within <exceptionPolicy> elements. The only required attribute of the <exceptionPolicy> element is name, which defines the policy name. This is the name used with the ExceptionManager.HandleException method. Each <exceptionPolicy> element contains one or more <exceptionHandler> elements that define exception handler components that belong to the policy. The <exceptionHandler> element has two required attributes and one optional attribute:

The <exceptionHandling> element has the required defaultPolicyName attribute, which refers to one of the <exceptionPolicy> elements contained within it. When ExceptionManager.HandleException method is called without the policy name specified then the ExceptionManager uses the policy specified by the defaultPolicyName attribute.

Microsoft Multi-Channel Commerce Foundation provides two exception handlers - XmlLoggingExceptionHandler and TextLoggingExceptionHandler. Application developers can provide additional exception handlers that implement IExceptionHandler interface and configure them through the <exceptionHandling> configuration section as described above.

See Also

Other Resources

Developing with the Multi-Channel Commerce Foundation

Extending Commerce Foundation

Starting, Stopping, and Formatting XMLTracer Output