A Look at ETW – Part 1

Over the past few years I’ve returned from technical conferences with a to-do item of “look into ETW.” I’d make this note because at some point during one or more sessions a presenter would say something like “you really should be using ETW.” Unfortunately, I never did get around to looking into Event Tracing for Windows (ETW), and the to-do item got moved forward another year. I recently finished Ben Watson’s excellent new book, Writing High-Performance .NET Code, where he also encourages the use of ETW, and having some free time, decided I’d finally “look into ETW.”

I had a vague notion of what ETW was; after all, I’d used the EventLog/Event Viewer. And the Service Log Viewer. And Intellitrace. Weren’t these all using ETW? I’d need to do some research to find out.

Where to start learning more about ETW? How about the MSDN page? Channels, manifests, sessions, publishers? Vista?!?! Um, no, not there. Well, how about this MSDN Magazine article? Better, but it was written in 2007!  However, it did offer this:

Event Tracing for Windows® (ETW) is a general-purpose, high-speed tracing facility provided by the operating system. Using a buffering and logging mechanism implemented in the kernel, ETW provides a tracing mechanism for events raised by both user-mode applications and kernel-mode device drivers. Additionally, ETW gives you the ability to enable and disable logging dynamically, making it easy to perform detailed tracing in production environments without requiring reboots or application restarts. …
ETW was first introduced on Windows 2000. Since then, various core OS and server components have adopted ETW to instrument their activities, and it’s now one of the key instrumentation technologies on Windows platforms.

So it’s built into the OS, extremely fast, and allows for dynamic real-time tracing across system and application components. And it’s been available on Windows platforms for almost 15 years, which could be a mixed blessing, as the links to the somewhat outdated documentation above illustrate. Over its long history there have been several changes to ETW, and a confusing hodgepodge of tools, toolkits and terminology.

But first, some of that terminology.

Event – Really anything you want it to be. Events in ETW are strongly-typed: they have both predefined elements and additional developer-defined payload. ETW will also capture the stack trace and timestamp of the event. The semantic nature of events makes their definition both easy and quite difficult, as determining what should be instrumented, and when, takes some thought. There’s also a whole glossary of terms you need to know too. More on this in a later post.

Source or provider – Something which will generate events. Much of the OS and sub-systems are already ETW providers. There’s a legacy here too which can be important to remember when using some of the tooling or reading through documentation:

  • “Classic providers” (pre-Vista, in other words before 2007) had to be registered with “MOF” files and the mofcomp utility.
  • With Vista came “manifest-based” providers registered using something called wevtutil.
  • As of .NET 4.5, the EventSource is the preferred way to write a provider. (If you’re not using .NET 4.5 there’s a NuGet package to help.)

Controllers, sessions, and consumers – A controller will start and stop tracing sessions, while a consumer will work with the results. Generally you’ll use existing tools for all this, but you can also write your own.  ETW has a pub-sub type of architecture, which allows for both in-process, but more often out-of-process, tracing of a running application. This decoupling also helps make it fast – unless “something” is listening to a provider’s events then ETW essentially ignores the event.

ETW is not a logging platform like NLog, Log4Net, Enterprise Library, et al., as it’s not about defining a target destination. The EventSource(s) you define in your application will generate events to ETW. It’s any sessions and consumers, whether in-process or out-of-process, which will determine targets.

I’ve mentioned outdated documentation and the alphabet soup of tools (perfview, logman, xperf, tracerpt, wpa, and more), but there are other obstacles on the learning curve as well, two of which stand out:

  • Confusing message – How does ETW fit in with other, newer, Microsoft tools? Does Application Insights tie in with ETW? From what I can tell, no. How about Intellitrace? Umm, apparently not. The Semantic Logging Application Block? Yes! With SLAB you still write your own EventSource(s) but use SLAB for its various sinks and listeners. And the Service Log Trace Viewer? It can read ETW trace output (ETL files).
    About the Event Log / Event Viewer – Prior to 2007 you’d write to either the Event Log or use ETW; with Vista these techniques merged. You can still use the EventLog API directly, but you can also use some predefined “channels” with your events to have the Event Viewer consume them.
  • An anti-pattern? – Most applications today use some form of dependency injection to provide logging, and developers code to an interface. Although there don’t seem to be any best practices with ETW, the strongly-typed logging it provides generally means there will be a tight coupling between your code and your EventSource.

Despite my concerns, tracing and monitoring with ETW tools does look powerful. Providers are built-in for much of the OS and sub-systems, so it’s easy to enable providers for HTTP traffic, ASP.NET activity, WCF, JIT, GC, etc. Adding your own events to the mix for end-to-end tracing in a single unified view is very appealing.  The documentation picture isn’t quite as bleak as it first seemed either: Kathleen Dollard has a good introduction to the EventSource and a few other ETW blog posts as well; while Vance Morrison, a performance architect on the .NET runtime, has blogged extensively about ETW.

In part 2 I’ll try writing an EventSource to generate strongly-typed events from implementations of the EF 6 IDbConnectionInterceptor and IDbCommandInterceptor interfaces.

Advertisements

One thought on “A Look at ETW – Part 1

  1. Pingback: The Morning Brew - Chris Alcock » The Morning Brew #1723

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s