Announcing TraceEvent – Monitoring and Diagnostics for the Cloud

In this post, Vance Morrison, software developer on the .NET Runtime team, will talk about the TraceEvent NuGet library we just shipped. — Immo

I am happy to report that we have just released the TraceEvent library on (prelease) NuGet. This library is an important part of the .NET, end-to-end, cloud scale diagnostics and monitoring story. It allows you to easily control and process any Event Tracing for windows (ETW) logging events, and in particular the logging events generated by the .NET System.Diagnostics.Tracing.EventSource class. Together EventSource and TraceEvent form a complete logging system that is light weight, efficient, interoperable with operating system logging, and which can easily be automated for cloud-scale installations.

The TraceEvent library has been available for some time via the BCL codeplex site, however repackaging this library as a NuGet package makes it significantly easier for you to add to your app and also to get all of our updates. In addition we have created a ‘TraceEvent Samples’ NuGet package that makes it even easier to get started.

Here’s what it does

Here is a quick demo of what you can do. In the following demo we have two processes. The process on the left represents an application being monitored. This application EvenSource to log a ‘MyFirstEvent’ when it start a user’s request, and a ‘MySecondEvent’ when it is done. For demo purposes, this process also logs messages to the console when these events are logged. The process on the left is using ETW to monitor ‘interesting’ events machine wide, including the ‘MyFirstEvent’ and ‘MySecondEvents’ as well as .NET runtime garbage collection (GC) events. It uses this information to perform its analysis: for this demo, it is how long requests take and how long.NET GCs take. In this particular screenshot, you can see we highlighted a GC that happened on the third request and the resulting logging that happened in the monitor. This scenario is typical, how you can combine both your own events along with a wealth of built in ones to perform better analysis (in this case determining if GC has impact on response times). Building something like this is straightforward with the TraceEvent library, but you can also do so much more. The PerfView tool was built entirely on top of the TraceEvent library.

How to get started

It is really easy to get started with our sample in Visual Studio:

Create an empty console application,
Right click on the References node in Project Explorer and select Manage NuGet Packages
Set the filtering to include pre-release packages and search for ‘TraceEvent Samples’ and select that package a part of that project.
Add the line TraceEventSamples.AllSamples.Run(); to your main program.
Browse the sample code in the ‘TraceEventSamples’ directory the NuGet package inserted into your project.
Hit “F5” when you want to see it run.

The samples package shows you several of the most common scenarios for using TraceEvent. It demonstrates how to enable both your own EventSource or .NET/OS events and then send the data either to a file or process them in real time.

The TraceEvent NuGet package also comes with a ‘TraceEventProgrammersGuide.docx’ file (I have included a copy at the end of the blog but as you will see it is not finished. The most up to date one will always be in the package). Once you have decided that you want to use this library, reading this doc is the fastest way to get truly ramped up.

Enough Overview. Show me the code!

The EventSource class in the .NET Framework 4.5 makes logging as easy as defining a class that has a method for each different kind of event. You can see what that looks like in the example definition below, and learn more in my EventSource tutorial.

class MyEvents : EventSource 
{
 public void MyFirstEvent(string MyName, int MyId) { WriteEvent(1, MyName, MyId); }
 public static MyEvents Log = new MyEvents();
}

The MyFirstEvent method would then be called from the appropriate places within an app.

MyEvents.Log.MyFirstEvent("hello", 35);

Events then ‘go to subscribers’. Those subscribers could be EventListeners in the same process as the EventSource. EventSource also supports out-of-process listeners, using its built in support to send events to the Event Tracing for Windows (ETW) infrastructure. There are tools like PerfView, which let you enable EventSource providers ‘manually’ (see my tutorial for details).

You can also listen to events from other processes from code, which is valuable for automation. This is where the TraceEvent library comes in, which make it easy to collect ETW events. Here is the code to turn on monitoring of the ‘MyEvents’ EventSource (from another process) for 10 seconds and send the data to MyEventData.etl. It is about as easy as you can get.

using (var session = new TraceEventSession("MySession", "MyEventData.etl"))
{
 session.EnableProvider("MyEvents");
 // Collect for 10 seconds then stop. 
 System.Threading.Tasks.Task.Delay(TimeSpan.FromSeconds(10)).Wait();
}

Once you have data, TraceEvent makes it easy to process the events that you’ve collected. Here is the code that plucks out the events you want, using lambda syntax.

using (var source = new ETWTraceEventSource("MyEtlFile.etl"))
{
 source.Dynamic.AddCallbackForProviderEvent("MyFirstEvent", "MyEvents", (TraceEvent data) =>
 {
 Console.WriteLine("GOT {0}({1}, {2})", data.EventName,
 data.PayloadByName("MyName"), data.PayloadByName("MyId"));
 });
 // Typically you have several of these callback registration calls. 
 source.Process();
}

You might wonder why the API signature includes an Actionparameter, which you see above as the lambda, instead of a more traditional IEnumerable pattern. TraceEvent also supports ‘real time’ processing of events, so exposes an API that works well for that. In that situation, an implementation needs to be called as events come in. In the scenario above, which processes an ETL file, that approach isn’t needed, however, that’s the reason for the API shape. Because the code is written in this way, it is easy to modify this sample to process the data in real time rather than from a file.

The code above registers callbacks for the set of events that it is interested in. In this example, that’s only ‘MyFirstEvent’ from the ‘MyEvents’ provider). This implementation is simple: it finds the ‘MyName’ and ‘MyId’ values and print them. A typical implementation would register several callbacks, one for each kind of event needed for analysis. Once all the callbacks are registered, ‘Process’ is called to invoke the callbacks, as the events are read from the source (in this case the ETL file).

Not bad. In a dozen lines of code or so, I have set up all the code needed to log an event, pass different types of argument to it, enable it from outside the process, and receive that event data to parse those arguments to do whatever monitoring logic I want. That’s not a lot of effort to create the beginnings of a real cloud monitoring solution.

And that is only the beginning. For those of you who like the Reactive Extensions framework, TraceEvent supports that too, and the NuGet TraceEvent Samples package has examples of this. You also have the wealth of .NET and OS events that let you know about the GC, the Just in time compiler, CPU, Disk I/O, Network activity, Blocked time and more. Events can also have stack traces associated with them, which are SUPER useful for doing ‘deep dive’ diagnosis. We have only scratched the surface.

If you want to learn more:

Read the Programmers guide at the end of this blog entry.
Read Vance Morrison’s Blog on TraceEvent and EventSource.
Read Grigori’s blog on Semantic (strongly typed) logging and the Semantic Logging Application Block code on codeplex that lets you send EventSource events to other places besides ETW (e.g. a local file, or a database, or Azure storage …)

Next steps!

You should follow my suggestion above about creating an empty console project in Visual Studio and referencing the ‘TraceEvent Library Samples’ NuGet Package in your empty project (currently is a pre-release package so make sure your filters don’t hide it). If you want to skip the samples, you can simply reference the ‘TraceEvent Library’ directly and start writing your code that uses it. In either case, reading the TraceEventProgrammersGuide.docx (either at the end of this blog or in the TraceEvent package) is highly recommended.