Wednesday, June 11, 2008

Using wcf ServiceTraceViewer to view your own events and log messages

How one should use Trace and TraceSource in order to achieve the following view of events in the ServiceTraceViewer?


One of the straightforward solutions would be:

        public void ShouldLogWithXmlRollingListenerNoConfig()
            // Setup source and listener
            string initializationString =
                @"name = XmlLogger; logrootpath = c:\log; staticpattern = log_; maxSizeBytes = 20000;";
            XmlWriterRollingTraceListener traceListener =
                new XmlWriterRollingTraceListener(initializationString);
            TraceSource log = new TraceSource("Test", SourceLevels.All);
            // Start Activity #1
            Guid activity1Guid = Guid.NewGuid();
            Trace.CorrelationManager.ActivityId = activity1Guid;
            log.TraceEvent(TraceEventType.Start, 2, "Activity #1");
            // log information inside Activity #1
            log.TraceInformation("Information from Activity #1");
            // Start Activity #2
            Guid activity2Guid = Guid.NewGuid();
            log.TraceTransfer(3, "Transferring to Activity #2", activity2Guid);
            Trace.CorrelationManager.ActivityId = activity2Guid;
            log.TraceData(TraceEventType.Start, 4, "Activity #2");
            // Complete Activity #2
            log.TraceEvent(TraceEventType.Stop, 5, "Completing Activity #2");
            log.TraceTransfer(6, "Returning back to Activity #1", activity1Guid);
            // Get back into Activity #1
            Trace.CorrelationManager.ActivityId = activity1Guid;
            // Log something extra in Activity #1 before completing it
            log.TraceEvent(TraceEventType.Warning, 7, "Warning from Activity #1");
            // Complete Activity #1
            log.TraceEvent(TraceEventType.Stop, 8, "Completing Activity #1");

I used the XmlWriterRollingTraceListener from here-, but standard XmlWriterTraceListener can be "used" (more on that in the coming entries) as well.

Main points are:

- You set the ActivityId on the Trace.CorrelationManager to your activity Guid (that is persisted in the current thread logical call context). All events logged after that are correlated under this same Guid when flushing events into xml:

<Correlation ActivityID="{XYZ}" />

- You should log the "Start" event of your activity, otherwise instead of a meaningful activity name in the left pane, you'll see your Guid (part of it).
- You declare a transfer of activity by logging the "Transfer" event with new ActivityId, after that you set that ActivityId on the CorrelationManager.

This is just one of the ways how to achieve the result shown in the screen shot.

No comments: