Writing custom .NET trace listeners

• Download source files - 5 Kb

"When people talk, listen completely. Most people never listen."
Ernest Hemingway

Introduction

This article provides a brief introduction to .NET trace facilities and then discusses different methods to customize .NET trace listeners, based on overriding TraceListener, StreamWriter or Stream. As an illustration we'll build a listener that adds timestamp to trace messages and stores them in a text file that never exceeds given size. Once the maximum size is reached, the trace file is backed up and then truncated. This functionality is used in a real project that requires continuous generation of trace files.

1. Trace and trace listeners

One of the most useful debugging features of .NET Framework is Trace type (or class in C++). Functionally Trace is very similar to Debug type (and they share most of internal implementation), but unlike its Debug sibling that is supposed to be used only during debugging sessions, Trace functions can be compiled into a program and shipped to customers, so in case your users encounter a problem, they can activate trace by simply editing application configuration file.

Trace is easy to use and fully documented in .NET Framework documentation, so I will only briefly go through the basic trace features. The following code is a self-explanatory example of how to use Trace<code> type:

Trace.Assert(true, "Assertion that should not appear");
Trace.Assert(false, "Assertion that should appear ");
Trace.WriteLine(123, "Category 1");
Trace.WriteLineIf(true, 456, "Category 2");
Trace.WriteLineIf(false, 789, "Category 3 (should not appear)");

The real power of Trace and Debug types is in so called trace listeners - trace information subscribers. You can define unlimited number of listeners, and as soon as you add them to trace listener collection, they will start receiving trace messages. .NET Framework comes with three ready-made listeners: DefaultTraceListener, EventLogTraceListener and TextWriterTraceListener (all in System.Diagnostics namespace). DefaultTraceListener wraps traditional OutputDebugString API, EventLogTraceListener logs messages to Windows Event Log, and TextWriterTraceListener forwards them to a text file. The code below demonstrates how to forward trace messages to a text file (in addition to output debug window).

TextWriterTraceListener listener = new TextWriterTraceListener("MyTrace.txt");
Trace.AutoFlush = true;
Trace.Listeners.Add(listener);
Trace.WriteLine(123, "Category 1");

Defining trace output path in your source code is pretty bad idea and serves only demonstration purposes. Trace listener parameters can (and should) be specified in application configuration file.

2. Trace listener customization

Although three built-in .NET trace listeners cover pretty much of what developers would expect from trace facility, sometimes you will need more. A good programming exercise can be implementation of DatabaseTraceListener that will forward messages to a database. However, I suppose that most of developers use text files as primary means of storing intermediate program states (unless you expect your customers to configure SQL database in order to collect your program trace output). So in case generic TextWriterTraceListener is not enough, you may derive your own type from it:

class MyListener : TextWriterTraceListener
{
    // Custom implementation
}

This is a most straightforward approach, but before you start coding, it's worth taking a minute to analyze what kind of custom behavior you're going to implement. Think about split of responsibilities between objects that take part in trace process:

• Trace object decides if the message is going to be sent to listeners and who's going to receive it. Since this type is sealed, you don't have much control of this part;
• TraceListener receives trace message, optionally add extra formatting (indentation) and writes data using StreamWriter object;
• StreamWriter renders lines and single items into a byte stream using specified (or default) encoding and cultural settings;
• Finally, Stream is a final destination of trace messages; it does not deal with messages or even lines directly, it obtains only sequences of bytes.

So what type should you override to implement custom trace listener? Here are some basic guidelines:

• Do not try to come up with your own MyTrace class. Debug and Trace are sealed for good reasons: you don't have control over standard .NET and third-party types, and they all use built-in Debug and Trace.
• If you need to apply general message formatting that should be common for all listeners, you only need to convert trace messages into a new format, no changes need to be done to listeners.
• Override TraceListener if your will apply additional message formatting that is only relevant for this listener. For example, you can extend TextWriterTraceListener functionality by attaching timestamp information to every message (we will show how to do it later in this article). This does not make sense for EventLogTraceListener where timestamp is managed by Event Log itself.
• Override StreamWriter or Stream types if you need to change the way information is rendered to media. For example, your custom streamer can limit the size of a trace file and backup old data (we will also show how to implement it).

In the rest of the article we will go through implementation of custom TraceListener and Stream types.

3. Practical task: limiting trace file size

Let's see how we can solve fairly common task: managing continuously generated trace files. Default trace listener implementation is not really suitable for service applications that are supposed to be always active. If application produces a lot of trace output, then sooner or later this information will use up all disk space. Even if this does not happen, you will have to deal with huge files that are difficult to manage. In addition, default text trace listener does not store timestamp information with trace messages, so it is impossible to identify exact time when the message was sent.

To solve this problem, we will implement a new type (derived from FileStream) that will take care of trace file and automatically back it up and reset. Our custom FileStream object will be generating a collection of trace files instead of just one:

• MyTrace.txt (recent trace information);
• MyTrace00.txt (trace history backup);
• MyTrace01.txt (trace history backup);
• and so on...

In addition to standard FileStream parameters, our class will require the following initialization data:

• Maximum file length;
• Maximum number of backup files.
• Boolean switch that specifies if data that is sent to a stream can be split between different files within a single Write call.

The first parameter controls at what size file is split (and backed up). The second parameter specifies how many backup files can be created. When the maximum number of files is reached, file index is reset and backup files are overwritten beginning from the oldest one. The third parameter makes it possible to keep data integrity (for example, to avoid breaking text lines): if data that is sent to a stream with Write call must be stored in a single file, then in case data won't fit, the file is backed up and reset before the Write operation is performed.

4. Implementation: FileStreamWithBackup type

Since we're now dealing with FileStream-derived type, we should ensure that our implementation is general and can be used by any FileStream consumer. We start with overriding FileStream methods.

FileStream has 9 construstors. FileStreamWithBackup is going to have only 4 that take path as one of their arguments. We won't allow constructing a stream from a handle (it's bad idea for a stream that manages a set of files).

FileStreamWithBackup can only be used to write data to a stream, so CanRead properties will return false:

public override bool CanRead { get { return false; } }

We will need to override FileStream Write method:

public override void Write(byte[] array, int offset, int count);

In addition FileStreamWithBackup will have the following properties:

public long MaxFileLength { get; }
public int MaxFileCount { get; }
public bool CanSplitData { get; set; }

You can find class full implementation in enclosed source code, I'll just present the essential part of it: implementation of the Write method:

public override void Write(byte[] array, int offset, int count)
{
    int actualCount = System.Math.Min(count, array.GetLength(0));
    if(Position + actualCount <= m_maxFileLength)
    {
        base.Write(array, offset, count);
    }
    else
    {
        if(CanSplitData)
        {
            int partialCount = (int)(System.Math.Max(m_maxFileLength, 
                                                     Position) - Position);
            base.Write(array, offset, partialCount);
            offset += partialCount;
            count = actualCount - partialCount;
        }
        else
        {
            if( count > m_maxFileLength )
                throw new 
              ArgumentOutOfRangeException("Buffer size exceeds maximum file length");
        }
        BackupAndResetStream();
        Write(array, offset, count);
    }
}

The only proprietary method that Write calls is BackupAndResetStream. Here it is:

private void BackupAndResetStream()
{
    Flush();
    File.Copy(Name, GetBackupFileName(m_nextFileIndex), true);
    SetLength(0);

    ++m_nextFileIndex;
    if(m_nextFileIndex >= m_maxFileCount)
        m_nextFileIndex = 0;
}

I won't describe here GetBackupFileName, but it is fairly straightforward (and is not doing anything that does not match its name).

5. Using FileStreamWithBackup to enhance application trace

Here is a sample program with trace messages that are automatically backed up as soon as trace file reaches 60 bytes. Number of backup files is set to 10.

class CustomTraceClass
{
    /// <summary>
    /// The main entry point for the application.
    /// </summary>
    [STAThread]
    static void Main(string[] args)
    {
        FileStreamWithBackup fs = new FileStreamWithBackup("MyTrace.txt", 
                                                    60, 10, FileMode.Append);
        fs.CanSplitData = false;
        TextWriterTraceListener listener = new TextWriterTraceListener(fs);
        Trace.AutoFlush = true;
        Trace.Listeners.Add(listener);
        Trace.Assert(true, "Assertion that should not appear");
        Trace.Assert(false, "Assertion that should appear in a trace file");
        Trace.WriteLine(123, "Category 1");
        Trace.WriteLineIf(true, 456, "Category 2");
        Trace.WriteLineIf(false, 789, "Category 3 (should not appear)");
    }
}

Run this program several times, and you'll see increasing number of "MyTrace*.txt" files. Set FileMode to Create, and it will clean backup files every time you start it. Finally, change CanSplitData switch to true, and all trace files will be of the same (maximum) size, but trace lines will be broken at file ends.

6. Bells and whistles: TextWriterTraceListenerWithTime

Remember we complained that default text trace listener does not store timestamp information. We want each trace message to be stored together with its timestamp, isn't it useful? In this case we don't need to go as low as Stream customization. Streams do not deal with trace messages, they deal with bytes. Even StreamWriter do not handle message - it handles lines. So in this case overriding TextWriterTraceListener is the right thing to do.

Overriding TextWriterTraceListener is quite simple: you only need to supply custom WriteLine method that takes a single string argument. Your new WriteLine implementation will look similar to this:

public override void WriteLine(string message)
{
    base.Write(DateTime.Now.ToString());
    base.Write(" ");
    base.WriteLine(message);
}

Although TextWriterTraceListener has four WriteLine overridables, you only need to override the one above: it will be called from the others. In addition you should re-implement constructors that you will decide to expose from a new class.

And since you now have separate custom implementation of Stream and TraceListener functionality, you can use them in any combination. So if you want to add timestamp to messages, but don't need to break trace file into smaller pieces, you can easily achieve it:

TextWriterTraceListenerWithTime listener = 
                               new TextWriterTraceListenerWithTime("MyTrace.txt");
Trace.Listeners.Add(listener);
Trace.WriteLine(123, "Category 1");

7. Wish list: what is not possible to customize

Although currently implemented .NET trace facilities will suit majority of needs, there is nothing that can not be improved. I lack a couple of things that would make trace more flexible:

1. Although it is possible to define multiple Trace switches (instances of TraceSwitch type), it is not possible to apply different trace levels to different listeners. Let's say you have the following code:

   Trace.WriteLineIf(mySwitch.TraceVerbose, "Operation succeeded");
   Trace.WriteLineIf(mySwitch.TraceError, "Operation failed");

   The first line will end up in all listeners in case mySwitch is set to Verbose level. The purpose of having multiple listeners is to be able to send trace information to different destinations. When available destinations are so different (remember they incude Windows Event Log, Debugger window and text files, and you can define your own), it is natural to be able to set different filters on each listener. While you can be interested in collecting wide range of messages in a text file, you will probably want to send only warnings and errors to Windows Event Log. Right now it is not possible with a single Trace call. It would be nice to be able to do the following:

   // NB! does not work this way now
   myTextWriterTraceListener.TraceLevel = TraceLevel.Verbose 
   
   // NB! does not work this way now
   myEventLogTraceListener.TraceLevel = TraceLevel.Error 
   

2. When messages are sent to trace listeners, they are semantically associated with certain trace levels, i.e.

   Trace.WriteLineIf(mySwitch.TraceVerbose, "Operation succeeded");

   The message "Operation succeeded" can be classifed as having level >Verbose, since it is only sent to listeners when trace level is set to Verbose. Currently each single message has nothing to do with the trace level that it is tested for. If there was a way to assign a level to a message, not just test for a condition, then the listener could have access to message level and we could do the following:

    // NB! does not work this way now
   Trace.WriteLine(TraceLevel.Verbose, "Operation succeeded");

   In this case the level (TraceLevel.Verbose) would be send to a listener and might become a part of customization, for example, message severity level could be stored in a trace file.

Conclusion

Flexibility of .NET diagnostics classes let developers easily customize most of the implementation. We have shown that trace customization can be done at several levels - either by deriving a new type from TraceListener (or its subclasses), or by implementing custom Stream or StreamWriter. This gives developers good opportunities to adjust .NET diagnostics facilities to their needs.