Home » Technical Papers » Debugging in .NET

Debugging in .NET

Debugging is one of the most painful parts of the entire software development process. We don't want to describe how hard it can be to find one little bug - you probably all know this already... possibly, too well. The amount of bugs in programs increases with product complexity and often when bugs aren't fixed in time, they can interact and produce extra complexities in a project that is complex itself. So, we are trying to constantly monitor and eliminate bugs.

The best way to monitor bugs is to perform unit testing but, when it says that a test has failed, it doesn't say why and our task is to trace the execution process to see what's wrong.

In this article we just want to describe how this process can be simplified when using the .NET Framework debugging and tracing means. We'll briefly tell you how to use them efficiently, plus we'll you give some examples of this.

Tracing

The first debugging strategy to be discussed in this article is tracing. Tracing can be a very powerful technique in skillful hands, because it allows you to see the whole picture of the application run time behavior and analyze it more efficiently, although it cannot provide information by request.

Tracing support in .NET is covered (as most of the other debug components) in the System.Diagnostics namespace, exactly in the Trace class.

Trace is a static class (which means that all its members are static and you don't need to instantiate it to get the key to its functionality). It allows you to do the following:

Raise an assertion (conditional or not)

Output trace messages with condition support

Format the trace output

Let's start discovering its possibilities with a brief member's overview:

public static void Assert(bool)
public static void Assert(bool, string)
public static void Assert(bool, string, string)

The Assert method displays a failure message (it is displayed on the application failure and allows users to abort execution, ignore the failure or retry the code that caused the failure) if the condition is false. Two overloads allow displaying custom information by specifying one or two accompanying messages (these messages can be set by the string parameters - this is done to allow developers to display extra information about the assertion fail).

To describe how the messages are displayed, we'll demonstrate several examples to you. The first shows the results of assertion without any extra messages. Such an assertion can be made using code like the following:

// Assertion demo
// 
// Purpose: To demonstrate results of different Assert method calls

using System;
using System.Diagnostics;

namespace Assertion
{
    class Application
    {
        [STAThread]
        static void Main(string[] args)
        {
            // Simple assertion. No additional messages
            Trace.Assert(false);
        }
    }
}

This program displays the following message box:

As you can see, only exception information is displayed. This message doesn't display any context-dependent information and we can't see the reason of the failure. Next, the application uses one attribute when calling the Assert method:

// Assertion demo
// 
// Purpose: To demonstrate results of different Assert method calls

using System;
using System.Diagnostics;

namespace Assertion
{
    class Application
    {
        [STAThread]
        static void Main(string[] args)
        {
            // Assertion with one additional message.
            Trace.Assert(false, "Simple assertion message");
        }
    }
}

This program displays a message box with more information. You can see that now we can provide information about the failure cause.

The most detailed form of assertion is calling Assert with two messages:

// Assertion demo
// 
// Purpose: To demonstrate results of different Assert method calls

using System;
using System.Diagnostics;

namespace Assertion
{
    class Application
    {
        [STAThread]
        static void Main(string[] args)
        {
            // Assertion with two additional messages - simple and detailed.
            Trace.Assert(false, "Simple assertion message",
             "This message is just an example. In real applications you
              can provide detailed information here");
        }
    }
}

Now you will see detailed failure information:

Actually, this method is used when checking life-important conditions, such as data correctness, etc. The following code is a usual case when it is used:

public void StoreObject( PersistentObject obj )
{
Trace.Assert(obj != null, "Cannot store null object");
}

This method verifies that the object that is going to be stored is not null. Often, the failure of such a condition is a good time to raise an exception, but it's not always enough. For instance, if this method stores some program-important data, the assertion is a perfect choice.

Note: At the debugging stage trace is useful, but tracing messages irritate users if they appear in the final release version. Here are some tricks to help you toggle tracing on/off.

If you compile your project manually (i.e. from the command line), tracing is disabled by default. To enable tracing in C#, add the /d:TRACE flag to the compiler command line when you are compiling your code, or you can simply add #define TRACE to the top of your file.

For example, take a look this small application:

using System;
using System.Diagnostics;

namespace TraceShow
{
    /// <summary> 
    /// Summary description for Class1.
    /// </summary>
    class Class1
    {
        /// <summary> 
        /// The main entry point for the application.
        /// </summary>
        [STAThread]
        static void Main(string[] args)
        {
            Trace.Listeners.Add(new TextWriterTraceListener(Console.Out));
            Trace.Write("Hey, this is a trace message\n", "SIMPLE MESSAGES");
        }
    }
}

If it is compiled in the command line, you won't see anything until you set the /d:TRACE key or add the #define TRACE string to the top of the application.

The situation changes when you compile the application in Visual C#, where tracing is enabled by default. As a result, you'll see all tracing messages. To turn the tracing off, navigate to the project properties (it can be done in the solution explorer or in the View > Property Pages menu. In the Property Pages dialog, find the Conditional Compilation Constants (this option is located in the Build pane of the Configuration Properties folder) and remove TRACE from this option:

public static void Fail(string)
public static void Fail(string, string)

The Fail method raises an unconditional assertion. Its behavior is the same as that of the Assert method, but it doesn't require any condition to proceed.

This method can be used if the fail condition cannot be checked with a simple condition. One example of such a situation is exception handling:

try
{
throw new Exception("Sample exception");
}
catch (Exception ex)
{
Trace.Fail("Exception caught", ex.Message);
}

public static void Write(object)
public static void Write(string)
public static void Write(object, string)
public static void Write(string, string)

The Trace class can also write trace messages without generating an error. Such messages are posted to trace output devices known as trace listeners. This output is performed by the Write method.

The Write method creates a message which can be represented as an object or a string; In the previous case, the object.ToString() method call is performed. There are three more methods that perform similar actions: WriteLine outputs lines, WriteIf - conditional messages, WriteLineIf outputs a conditional message as a line.

The second parameter of the Write methods specifies a category (i.e. a string) that will be written before messages.

The output is made to all registered listeners. A listener is an object that can output trace messages to some device. Note that the Assert and Fail methods always output error messages to a window or console no matter which listener is currently selected. The class of such an object must inherit the TraceListener class, which has the following important members:

public virtual void Fail(string)
public virtual void Fail(string, string)

public virtual void Flush(string)

public virtual void Write(object)
public abstract void Write(string)
public virtual void Write(object, string)
public virtual void Write(string, string)

public virtual void WriteLine(object)
public abstract void WriteLine(string)
public virtual void WriteLine(object, string)
public virtual void WriteLine(string, string)

The Fail methods don't stop the application here. They only output error messages. The Write and WriteLine methods write a message. The only difference between them is that the latter feeds a line after the output has been performed. Finally, the Flush method flushes buffers. The Flush method works with devices that buffer the trace output (for example, buffered streams). You can also use auto flush - flush listeners after each message. This can be configured in the configuration file:

As you can see, if you create your own listener, you should at least implement the Write(string) and WriteLine(string) methods (these methods are the only abstract methods).

Microsoft provides three trace listeners: DefaultTraceListener, EventLogTraceListener and TextWriterTraceListener. The first one has the default behavior (it outputs information to the console if the application is running in the command environment or to the VS Output Window if the application is being debugged there). The second writes trace messages to the specified event log (this works only under Windows systems based on NT Technology - Windows NT, 2K, XP or .NET). Finally the third listener - to the text output stream.

A list of active listeners can be set programmatically or in the configuration file. By default, it includes DefaultTraceListener.

To programmatically change a list of active listeners, you should manage the Listeners collection (with its Add and Remove methods). To manage listeners in the configuration file, you should use the following syntax:

The initializeData parameter will be passed to the constructor that takes only a string parameter (e.g. for the EventLogTraceListener listener it sets an event source).

To become familiar with listeners, let's create an application that will use listeners to write trace messages. Its code is very simple:

// Tracing listeners demo
// 
// Purpose: To demonstrate how to use listeners

using System;
using System.Diagnostics;

namespace Assertion
{
    class Application
    {
        [STAThread]
        static void Main(string[] args)
        {
            Trace.WriteLine("Calling WriteLine method", "Tracing listeners demo");
            Trace.Flush();
        }
    }
}

But it's not enough to have code - we also must create a configuration file to set up listeners:

This configuration file removes the default listener and adds two custom ones: The first one outputs messages to a text file, the second, to the event log. For the first listener the initializeData attribute specifies a file to output data to, for the second, the event log to send events to.

Now let's run the application. To check the output of the first listener, we can view the myListener.log file. It must contain the following information:

Tracing listeners demo: Calling WriteLine method

So, we can see that the first listener just writes messages to a text file. Now let's check the second one. To do this, open Microsoft Management Console and navigate to the Application event log (the one that we've specified for the listener in the configuration file) in Event Viewer. You will find the event from our application there. Most possible, it's at the top of the list. If you double-click it, you will see its contents. We had the following information on our machine:

Making the trace output more readable

Sometimes an application is so complex, that the trace itself should be formatted for better understanding. To make the trace log look nicer, you can employ indenting. Take a look at the following sample code:

public void Callee()
{
    Trace.WriteLine("Callee started");

    ... // Some internal logic

    Trace.WriteLine("Initializing buffer");

    ... // Some extra internal logic

    Trace.WriteLine("Exiting callee");
}

public void Caller()
{
    Trace.Write("Caller called");

    ... // Some external logic

    Callee();

    ... // Some extra logic

    Trace.WriteLine("Initializing buffer");
    Trace.Write("Exiting caller");
}

The trace output for this code may look like the following:

Caller called Callee started Initializing buffer Exiting callee Initializing buffer Exiting caller

If there were no messages displayed before and after executed methods, the duplicated Initializing buffer message would confuse us. But even this appearance doesn't look clear. To avoid this ambiguity, we use the Trace class that supports indentation. We can modify the existent code taking the advantage of indentation:

public void Callee()
{
    Trace.Indent();
    Trace.WriteLine("Callee started");

    ... // Some internal logic

    Trace.WriteLine("Initializing buffer");

    ... // Some extra internal logic

    Trace.WriteLine("Exiting callee");
    Trace.Unindent();
}

public void Caller()
{
    Trace.Write("Caller called");

    ... // Some external logic

    Callee();

    ... // Some extra logic

    Trace.WriteLine("Initializing buffer");
    Trace.Write("Exiting caller");
}

The output of this modified code will look like the following:

Caller called Callee started Initializing buffer Exiting callee Initializing buffer Exiting caller

As you can see, the Callee method output is indented, so we can easily separate messages of different methods. To do this, we have called the Indent() and Unindent() methods.

The Trace configuration can be modified in the configuration file:

Debugging

Actually, debugging and tracing have much in common. The methods of the Debug class, where debugging functionality is implemented, have the same names and signatures and almost the same semantics. The only difference is that debugging is disabled in the release configuration (this means that no binary code is produced to call these methods). The debug output can be also set in the configuration file in the following manner:

Note: For debugging, the statements and instructions similar to those employed for tracing are used. The only difference is that the word TRACE is replaced with DEBUG.

Switching debug configurations

The last topic to discuss here is switches. A switch is an object that can have one of several states. Its state can be set in the configuration file or changed programmatically. The switches let you create configurable debugging and tracing code. The best way to get to know switches is to take a look at the sample code:

using System;
using System.Diagnostics;

namespace Switching
{
    class SampleClass
    {
        // Creating a switch. It is initialized by an externally specified value
        static TraceSwitch generalSwitch = new TraceSwitch("CoolSwitch", "Global scope");

        static public void SampleMethod() 
        {
            // The first message is written if the switch state is set to TraceError
            Trace.WriteLineIf(generalSwitch.TraceError, "TraceError message");

            // The second message is written if the switch state is set to TraceVerbose
            Trace.WriteLineIf(generalSwitch.TraceVerbose, "TraceVerbose message");

            // The third message is written if the switch state is set to TraceWarning
            Trace.WriteLineIf(generalSwitch.TraceWarning, "TraceWarning message");

            // The fourth message is written if the switch state is set to TraceInfo
            Trace.WriteLineIf(generalSwitch.TraceInfo, "TraceInfo message");
        }

        public static void Main(string[] args) 
        {
            // Calls the SampleMethod method
            SampleMethod();
        }
    }
}

There are several switch classes: TraceSwitch and BooleanSwitch. In this sample we used TraceSwitch to produce the output according to its state. The switch state is checked by TraceError, TraceInfo, TraceVerbose and TraceWarning properties. These properties test the switch state and return true if the trace level is equal to or greater than the corresponding constant. For example, TraceWarning is true when the level is 2 or greater. The following is a table of level values:

TraceError	1
TraceWarning	2
TraceInfo	3
TraceVerbose	4

The level value can be set in the configuration file in the following manner:

But, as we have already said, the state of a switch can be changed from code. We've modified the following code to demonstrate you this:

using System;
using System.Diagnostics;

namespace Switching
{
    class SampleClass
    {
        // Creating a switch. It is initialized by an externally specified value
        static TraceSwitch generalSwitch = new TraceSwitch("CoolSwitch", "Global scope");

        static public void SampleMethod() 
        {
            // The first message is written if the switch state is set to TraceError
            if(generalSwitch.TraceError)
               Console.WriteLine("TraceError message");

            // The second message is written if the switch state is set to TraceVerbose
            if(generalSwitch.TraceVerbose)
                Console.WriteLine("TraceVerbose message");

            // The third message is written if the switch state is set to TraceWarning
            if(generalSwitch.TraceWarning)
                Console.WriteLine("TraceWarning message");

            // The fourth message is written if the switch state is set to TraceInfo
            if(generalSwitch.TraceInfo)
                Console.WriteLine("TraceInfo message");
        }
 
        public static void Main(string[] args) 
        {
            Console.WriteLine("Before manual level set\n");

            // Call the SampleMethod method with configuration parameters
            SampleMethod();

            Console.WriteLine("\nAfter manual level set\n");

            // Set trace switch level
            generalSwitch.Level = TraceLevel.Warning;

            // Call the SampleMethod method with manual parameters
            SampleMethod();
        }
    }
}

Now if we run the application with the same configuration, we'll obtain the following output:

Before manual level set

TraceError message
TraceWarning message
TraceInfo message

After manual level set

TraceError message
TraceWarning message

This shows that the trace switch level has been changed.

Timing the Performance

In this section we'll tell you how much time may be spent on debugging. Actually, debugging has nothing to do with business logic, but execution of debugging code takes some time. We'll measure the time spent on outputting debug messages in applications. For instance, this measurement is important when you are testing a time-critical application. Take a look at the following code:

using System;
using System.Diagnostics;

namespace DebugDemo
{
    class PrimeNumberDetector
    {
        public static bool IsPrime( int n )
        {
            int upperbound = (int)Math.Sqrt(n);

            for (int i = 2; i <= upperbound; i++)
            {
                Debug.WriteLine("Processing number " + n + ", testing with " + i);
                if ((n % i) == 0)
                {
                    Debug.WriteLine("FAILED");
                    return false;
                }
            }
            return true;
        }
    }

    class Application
    {
        [STAThread]
        static void Main(string[] args)
        {
            for (int i = 2; i < 10000; i++)
                if (PrimeNumberDetector.IsPrime(i))
                    Console.WriteLine("{0} is a prime number", i);
        }
    }
}

This program tests integers from 2 to 10000 for primality and outputs prime numbers. For debugging purposes we output each number being tested, no matter whether it's a prime number or not. If a number is not prime, we output FAILED.

Now we'll measure the time spent on the script run with enabled and disabled debugging.

	1st test	2nd test	3rd test
With debugging (hh:mm:ss.ff)	00:00:07.9714624	00:00:07.9414192	00:00:07.9714624
Without debugging (hh:mm:ss.ff)	00:00:05.1273728	00:00:05.5179344	00:00:05.1273728

As you can see, debugging is quite expensive - in our case it took 64% of the execution time.

Conclusion

In this article we have described general approaches to debugging and tracing .NET applications. Of course there are some other issues, for instance, conditional compilation, that haven't been covered here. To learn more about them, see MSDN. We hope this article will help you master debugging and tracing techniques of .NET applications.