TraceOptions: An Easy Way to Get Common and Useful Data in Traces [Robert Villahermosa]
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!