Correlating events

The Semantic Logging Application Block supports the ActivityId and RelatedActivityId properties available for the EventWrittenEventArgs class in the .NET Framework version 4.5.1. The ActivityId property returns the globally unique identifier (GUID) for the current activity in the process for which the event is involved. The RelatedActivityId property returns a GUID for a related activity in a different process that is related to the current process.

These properties can be used to correlate events that have been published while handling a specific request in applications running on .NET 4.5.1 and higher, and they are available in the output from all of the sinks and formatters in the Semantic Logging Application Block. If the application is running on .NET 4.5 or earlier, the activity IDs will be empty.

Note

For more details about activity correlation, see Improve Debugging And Performance Tuning with ETW in MSDN Magazine.

Typical Goals

You are monitoring an application that uses asynchronous code or separate tasks that can spawn more than one thread, and you want to correlate events from more than one task. You want to be able to relate events that are involved in the same operation, even when they are part of different execution processes or tasks.

Notes

Asynchronous tasks are typically generated by features such as implementing request handlers asynchronously, and by using the Task Parallel Library (TPL). The activity IDs in all of the threads involved in the operation must be related to enable proper end-to-end tracing of the request.

The current activity ID of a thread is stored as thread-local storage. Once it has been set, all events are tagged with it without requiring any changes to the event sources that produce them.

When using TPL Tasks, each thread gets its own activity ID and the TPL scheduling code automatically publishes transfer events that contain the ActivityId and RelatedActivityId values. These can be used to correlate related events.

If you spawn new threads in your application code when you are not using TPL, and you want to be able to correlate related events across the different threads, you must publish the ActivityId and RelatedActivityId values. Depending on the architecture of your application, a current activity ID might have been set by the infrastructure, but your application can choose to provide a new activity ID using the SetCurrentThreadActivityId method. In that case, a transfer event should be logged linking the two activity IDs using the WriteEventWithRelatedActivityId method in your event source instead of the usual WriteEvent method.

Solution

The following steps describe how to capture and correlate events from separate tasks when using the Task Parallel Library.

To capture and correlate separate application and TPL Task events

1. If required, in the code in your application that initiates the TPL task, set the currentActivityID on that thread using the static SetCurrentThreadActivityId method of the EventSource class.

   EventSource.SetCurrentThreadActivityId(Guid.NewGuid());
   

   Note

   In many cases, the current thread identifier is set automatically. For example, ASP.NET will typically set this when you use sampling. In other cases, you can use the code shown above to set the current thread identifier using a new GUID value.

2. Create a listener in your application, or configure a listener for the Out-of-Process Host, to listen for events from the TLP event source named System.Threading.Tasks.TplEventSource.

3. Configure a suitable event sink (and formatter if required) to record the events captured by this listener.

   • If you are using the block in-process, you do this using code as shown in the following example.

     var tplListener = new ObservableEventListener();
     tplListener.EnableEvents("System.Threading.Tasks.TplEventSource", 
                   EventLevel.Informational, Keywords.TransfersOnly);
     var formatter = new EventTextFormatter() { VerbosityThreshold = EventLevel.Informational };
     tplListener.LogToFlatFile(@"C:\Logs\TPLlog.txt", formatter);
     

   • If you are using the block out-of-process, you do this in the configuration file for the Out-of-Process Host, as shown in this extract.

     <flatFileSink name="MySink" filename="C:\Logs\TPLlog.txt">
       <sources>
         <eventSource name="System.Threading.Tasks.TplEventSource"
                      level="Informational" matchAnyKeyword="1"/>
       </sources>
       <textEventTextFormatter verbosityThreshold="4" />
     </flatFileSink>
     

4. Run the application to generate event log entries that include the TPL events.

5. Examine the event log to discover the transfer events, and use the ActivityId and RelatedActivityId values to correlate the events. See Sampling and filtering events for more details and an example.

If your application logs relatively few events, but has a great many TPL Task-related operations, the ratio of TPL events to application events might be extremely high and cause the event sinks to be overloaded with TPL events. Additionally, the Semantic Application Logging Black sinks themselves are implemented using Tasks, and so their actions produce TPL events that will also be captured. Sampling can be used to address these data flooding issues to some extent. For more information, see Sampling and filtering events.

Next Topic | Previous Topic | Home | Community