TraceOptions: An Easy Way to Get Common and Useful Data in Traces [Robert Villahermosa]

  • Article

I have seen a few recent posts floating around the user community where users have been writing complicated code to get some very simple information such as a timestamp into their traces. As a follow up to this, I’d like to describe the TraceOptions enum and show how it can be used provide some useful information.

 

When a trace event occurs, the data is actually cached in an instance of the TraceEventCache class. When logging to file (we will use the TextWriterTraceListener in this example), not everything in the TraceEventCache is automatically output. By default only the message provided in the call to TraceEvent is logged. There is a practical reason for doing this – not everyone needs all the available information in the TraceEventCache to be logged so it makes sense to keep the payload size small unless it is explicitly stated that it is needed.

 

The TraceOptions enum is used to specify what should or shouldn’t be logged. It basically has 6 useful members (plus the none option): ProcessId, LogicalOperationStack, ThreadId, DateTime, Timestamp, and Callstack

You can read about what each of these options at :

https://msdn2.microsoft.com/en-us/library/system.diagnostics.traceoptions.aspx

Specifying any combination of these causes the listener to log the related info when a trace event occurs.

 

Here’s a short code snippet example to show this:

using System;

using System.Diagnostics;

namespace TraceOptions

{

    class Program

    {

        static void Main(string[] args)

        {

            TraceSource test = new TraceSource("MyTraceSource");

            test.TraceEvent(TraceEventType.Information, 5, "Informational Event Occurred.");

            test.Flush();

            test.Close();

        }

    }

}

 

The corresponding configuration file is:

<?xml version="1.0" encoding="utf-8" ?>

<configuration>

    <system.diagnostics>

      <trace autoflush="true" indentsize="4"/>

      <sources>

        <source name="MyTraceSource" switchName="MySwitch">

          <listeners>

            <add name="TextListener"/>

          </listeners>

        </source>

      </sources>

      <sharedListeners>

   <add name="TextListener"

           type="System.Diagnostics.TextWriterTraceListener"

           traceOutputOptions="Timestamp,Callstack,DateTime,LogicalOperationStack,ProcessId,ThreadId"

           initializeData="TWOutput.log" />

      </sharedListeners>

      <switches>

        <add name="MySwitch" value="Information"/>

      </switches>

    </system.diagnostics>

</configuration>

 

The output is as follows:

I’ve colored the headings of the sections that are now being output to make them more visible. These correspond to the enum values for ProcessId, LogicalOperationStack, ThreadId, DateTime, Timestamp, and Callstack

MyTraceSource Information: 5 : Informational Event Occurred.

    ProcessId=232

    LogicalOperationStack=

    ThreadId=1

    DateTime=2006-07-20T21:23:03.2701756Z

    Timestamp=172433816811503

    Callstack= at System.Environment.GetStackTrace(Exception e, Boolean needFileInfo)

   at System.Environment.get_StackTrace()

   at System.Diagnostics.TraceEventCache.get_Callstack()

   at System.Diagnostics.TraceListener.WriteFooter(TraceEventCache eventCache)

   at System.Diagnostics.TraceListener.TraceEvent(TraceEventCache eventCache, String source, TraceEventType eventType, Int32 id, String message)

   at System.Diagnostics.TraceSource.TraceEvent(TraceEventType eventType, Int32 id, String message)

   at TraceOptions.Program.Main(String[] args) in D:\VisualStudio2005Projects\TraceOptions\TraceOptions\Program.cs:line 14

 

As you can see, a lot of extra information other than the message string gets logged, so you really don’t have to jump through hoops to get useful info like the Timestamp, PID, or TID. Hope this helps some of you, happy tracing!