Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

How does System.TraceListener prepend message with process name?

I have been looking at using System.Diagnostics.Trace for doing logging is a very basic app. Generally it does all I need it to do. The downside is that if I call

Trace.TraceInformation("Some info");

The output is "SomeApp.Exe Information: 0: Some info". Initally this entertained me but no longer. I would like to just output "Some info" to console. So I thought writing a cusom TraceListener, rather than using the inbuilt ConsoleTraceListener, would solve the problem. I can see a specific format that I want all the text after the second colon. Here is my attempt to see if this would work.

class LogTraceListener : TraceListener
{
    public override void Write(string message)
    {
        int firstColon = message.IndexOf(":");
        int secondColon = message.IndexOf(":", firstColon + 1);

        Console.Write(message);
    }

    public override void WriteLine(string message)
    {
        int firstColon = message.IndexOf(":");
        int secondColon = message.IndexOf(":", firstColon + 1);

        Console.WriteLine(message);
    }
}

If I output the value of firstColon it is always -1. If I put a break point the message is always just "Some info". Where does all the other information come from?

So I had a look at the call stack at the point just before Console.WriteLine was called. The method that called my WriteLine method is: System.dll!System.Diagnostics.TraceListener.TraceEvent(System.Diagnostics.TraceEventCache eventCache, string source, System.Diagnostics.TraceEventType eventType, int id, string message) + 0x33 bytes

When I use Reflector to look at this message it all seems pretty straight forward. I can't see any code that changes the value of the string after I have sent it to Console.WriteLine. The only method that could posibly change the underlying string value is a call to UnsafeNativeMethods.EventWriteString which has a parameter that is a pointer to the message.

Does anyone understand what is going on here and whether I can change the output to be just my message with out the additional fluff. It seems like evil magic that I can pass a string "Some info" to Console.WriteLine (or any other method for that matter) and the string that output is different.

EDIT: I found the magic. Obviously it wasn't magic. The Write method gets call from a call to WriteHeader before the call to WriteLine which is where I thought the magic was happening.

like image 978
btlog Avatar asked May 13 '10 11:05

btlog


2 Answers

You can get this by overriding the TraceEvent() method in your listener. Like this:

    public override void TraceEvent(TraceEventCache eventCache, string source, TraceEventType eventType, int id, string message) {
        Console.WriteLine("{0}: {1}", id, message);
    }
like image 195
Hans Passant Avatar answered Oct 15 '22 21:10

Hans Passant


You also need to override this TraceEvent overload if using formatting:

public override void TraceEvent(TraceEventCache eventCache, string source, TraceEventType eventType, 
                                int id, string format, params Object[] data)
{
  base.WriteLine(String.Format(format, data));
}

For example:

Trace.TraceInformation("Thread {0} Waiting", Thread.CurrentThread.ManagedThreadId);

Override will output output only "Thread 9 Waiting\n" when data[0] == 9

like image 35
Dan Randolph Avatar answered Oct 15 '22 21:10

Dan Randolph