Defensive Programming in C# – Part 2: Using Switches to Control Debug and Trace

The previous example showed how to control logging based upon a bool variable. The drawback of this approach is that there must be a way to set that variable within the program. It’d be more useful to have a way to set the value of such a variable externally.

The BooleanSwitch and TraceSwitch classes provide this feature. You can control their behavior at runtime by either setting an environment variable or setting a registry entry.

1. BooleanSwitch

The BooleanSwitch class encapsulates a simple Boolean variable, which is then used to control logging:

// file=boolean.cs

// compile with: csc /D:DEBUG /r:system.dll boolean.cs

using System;

using System.Diagnostics;

 

class MyClass {

public MyClass(int i)

{

this.i = i;

}

[Conditional(“DEBUG”)] public void VerifyState()

{

Debug.WriteLineIf(debugOutput.Enabled, “VerifyState Start”);

if (debugOutput.Enabled)

Debug.WriteLine(“VerifyState End”);

}

BooleanSwitch debugOutput =

new BooleanSwitch(“MyClassDebugOutput”, “Control debug output”);

int i = 0;

}

class Test {

public static void Main()

{

Debug.Listeners.Clear();

Debug.Listeners.Add(new TextWriterTraceListener(Console.Out));

MyClass c = new MyClass(1);

c.VerifyState();

}

}

This example creates an instance of BooleanSwitch as a static member of the class, and this variable controls whether output happens. If this code runs, it produces no output, but you can control the debugOutput variable by setting the value in the configuration file for the assembly. This file is named <assembly-name>.config, which for this example means it’s called boolean.exe.config, and it has to be in the same directory as the assembly. Not surprisingly, the config file uses XML to store its values. Here’s the config file for the example:

<configuration>

<system.diagnostics>

<switches>

<add name=”MyClassDebugOutput” value=”1″ />

</switches>

</system.diagnostics>

</configuration>

Running the code using this file produces the following results:

VerifyState Start

VerifyState End

The code in VerifyState shows two ways of using the variable to control output. The first usage passes the flag off to the WriteLineIf() function and is the simpler one to write. It’s a bit less efficient, however, since the function call to WriteLineIf() is made even if the variable is false. The second version, which tests the variable before the call, avoids the function call and is therefore slightly more efficient.

2. TraceSwitch

It’s sometimes helpful to use something other than a Boolean to control logging. It’s common to have different logging levels, each of which writes a different amount of information to the log.

The TraceSwitch class defines five levels of information logging. They’re defined in the TraceLevel enum. Table 39-1 shows the possible values of TraceLevel.

Each of the higher levels implies the lower level; for example, if the level is set to Info, Error and Warning will also be set. You use these numeric values when setting the flag via an environ­ment variable or registry setting.

The TraceSwitch class exposes properties that tell whether a specific trace level has been set, and a typical logging statement checks to see whether the appropriate property was set. Here’s the previous example, modified to use different logging levels:

// compile with: csc /r:system.dll file_1.cs

using System;

using System.Diagnostics;

class MyClass

{

public MyClass(int i)

{

this.i = i;

}

[Conditional(“DEBUG”)] public void VerifyState()

{

Debug.WriteLineIf(debugOutput.TraceInfo, “VerifyState Start”);

Debug.WriteLineIf(debugOutput.TraceVerbose,

“Starting field verification”);

if (debugOutput.TraceInfo)

Debug.WriteLine(“VerifyState End”);

static TraceSwitch debugOutput =

new TraceSwitch(“MyClassDebugOutput”, “Control debug output”);

int i = 0;

}

class Test {

public static void Main()

{

Debug.Listeners.Clear();

Debug.Listeners.Add(new TextWriterTraceListener(Console.Out));

MyClass c = new MyClass(1);

c.VerifyState();

}

}

3. User-Defined Switch

The Switch class nicely encapsulates getting the switch value from the registry, so it’s easy to derive a custom switch if the values of TraceSwitch don’t work well.

The following example implements SpecialSwitch, which implements the Mute, Terse, Verbose, and Chatty logging levels:

// compile with: csc /r:system.dll file_1.cs

using System;

using System.Diagnostics;

enum SpecialSwitchLevel

{

Mute = 0,

Terse = 1,

Verbose = 2,

Chatty = 3

}

class SpecialSwitch: Switch

{

public SpecialSwitch(string displayName, string description) :

base(displayName, description)

{

}

public SpecialSwitchLevel Level {

get

{

return((SpecialSwitchLevel) base.SwitchSetting);

}

set

{

base.SwitchSetting = (int) value;

}

}

public bool Mute {

get

{

return(base.SwitchSetting == 0);

}

}

public bool Terse {

get

{

return(base.SwitchSetting >= (int) (SpecialSwitchLevel.Terse));

}

}

public bool Verbose {

get

{

return(base.SwitchSetting >= (int) SpecialSwitchLevel.Verbose);

}

}

public bool Chatty {

get

{

return(base.SwitchSetting >=(int) SpecialSwitchLevel.Chatty);

}

}

protected new int SwitchSetting

{

get

{

return((int) base.SwitchSetting);

}

set

{

if (value < 0)

value = 0;

if (value > 4)

value = 4;

base.SwitchSetting = value;

}

}

}

class MyClass {

public MyClass(int i)

{

this.i = i;

}

[Conditional(“DEBUG”)] public void VerifyState()

{

Console.WriteLine(“VerifyState”);

Debug.WriteLineIf(debugOutput.Terse, “VerifyState Start”);

Debug.WriteLineIf(debugOutput.Chatty,

“Starting field verification”);

if (debugOutput.Verbose)

Debug.WriteLine(“VerifyState End”);

}

static SpecialSwitch debugOutput =

new SpecialSwitch(“MyClassDebugOutput”, “application”);

int i = 0;

}

class Test {

public static void Main()

{

Debug.Listeners.Clear();

Debug.Listeners.Add(new TextWriterTraceListener(Console.Out));

MyClass c = new MyClass(1);

c.VerifyState();

}

}

You can control this switch with the same config file as the previous example.

4. Capturing Process Metadata

Simply outputting a string that records what a particular thread is doing is insufficient to monitor operations and track down problems in production environments. It isn’t usually necessary to have thousands of threads running within hundreds of processes on dozens of machines. Although it’s interesting that a particular thread called Trace.WriteLine() exists and has recorded that an error occurred, finding the actual thread that originated the statement, along with other metadata about the state of the process, is also interesting. To allow you to capture this information without having to manually code its retrieval, the Trace class in the 2.0 release of the .NET Framework libraries includes a new method called TraceInformation().

This method is capable of outputting the thread’s call stack, the date and time the Trace statement was made, the logical operation stack (which is the chain of calls in the current call context and may span multiple threads), the process ID, the thread ID, and the time stamp (which is a long that represents the number of ticks in the system timer and is a higher resolution than the date and time value that’s also available). The actual listener decides which output values should be collected for a TraceInformation statement. To add and output all the available information, use the following code:

ConsoleTraceListener ctl = new ConsoleTraceListener();

ctl.TraceOutputOptions = TraceOptions.Callstack | TraceOptions.DateTime | 

TraceOptions.LogicalOperationStack | TraceOptions.ProcessId |

TraceOptions.ThreadId | TraceOptions.Timestamp;

System.Diagnostics.Trace.Listeners.Add(ctl);

Trace.TraceInformation(“An error occurred “);

Running this code produces the following output:

Trace.exe Information: 0 : An error occurred

ProcessId=2324 LogicalOperationStack=

ThreadId=1

DateTime=2005-01-25T10:52:56.4135000Z

Timestamp=15259908099

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 severity, Int32 id, String message)

at System.Diagnostics.TraceInternal.TraceEvent(TraceEventType severity, Int32 id, String format, Object[] args)

at System.Diagnostics.Trace.TraceInformation(String message)

at Trace1.Program.Main(String[] args) in

z:\nick\pic#\code\trace\trace\program.cs:line 17

Obviously, collecting all this information is an expensive process, and the output informa­tion should be collected during a TraceInformation call only as it’s needed.

Source: Gunnerson Eric, Wienholt Nick (2005), A Programmer’s Introduction to C# 2.0, Apress; 3rd edition.

Leave a Reply

Your email address will not be published. Required fields are marked *