From the MVPs: “EventSource Improvements Include Better Diagnostics for Diagnostics”

This is the 31st in our series of guest posts by Microsoft Most Valued Professionals (MVPs). You can click the “MVPs” tag in the right column of our blog to see all the articles.

Since the early 1990s, Microsoft has recognized technology champions around the world with the MVP Award. MVPs freely share their knowledge, real-world experience, and impartial and objective feedback to help people enhance the way they use technology. Of the millions of individuals who participate in technology communities, around 4,000 are recognized as Microsoft MVPs. You can read more original MVP-authored content on the Microsoft MVP Award Program Blog.

EventSource Improvements Include Better Diagnostics for Diagnostics

Many of the improvements in .NET 4.5.1 are tactical – they improve how you do what you’re already doing now. But a seemingly small change to the EventSource class is strategic – it’s part of changing what you do. In the same way process has been a conversation over the last ten years, diagnostics will be a key strategic conversation for the next ten years. I’ll define diagnostics simply – understanding what’s happening in a badly behaved application, especially in production. Although there’s a lot of room to grow in the surrounding tooling, EventSource tracing will help you today and increase its impact as the tooling matures. The .NET 4.5.1 changes to EventSource make it truly ready to play the central role in your diagnostic game plan.

The .NET framework has had tracing since its very first release and there are several good third party libraries. But in this old style of tracing, your code and the libraries took responsibility for all of the work, tracing was comparatively slow, output was isolated to your application, tracing data was not strongly typed, and the result tended to printf style debugging like Trace.WriteLine(…) or logger.Warning(…).

EventSource is a lightweight tracing tool that can output to many targets. The most important of these targets is the built-in support for Event Tracing for Windows (ETW). ETW is part of the Windows operating systems and is already gathering diagnostics, even while you’re reading this blog post.

ETW takes responsibility for tracing control, doesn’t require you to restart your application, manages complexities like rolling buffers, and is blazingly, blazingly fast. Your application becomes one of many available providers in a rich and holistic tracing stream, so you can get an integrated view of what’s happening on the box. And, when EventSource targets a friendly listener like ETW, tracing data is strongly typed. For example, a trace might include an entry named “PrimaryKey” typed as an integer or Guid. Behind the scenes, EventSource accomplishes this via a manifest –XML (you never see) that explains to other tools how to interpret the data.

The design of EventSource encourages action based tracing with its accompanying IntelliSense support. In action based tracing a specific method call indicates what occurred LoadFile…(…), OpenConnection…(…), AccessPrimaryKey…(…), LoadJsonData…(…). In addition to predictable switches like severity level, and keywords, there’s a common pattern of actions, the most important of which is Start/Stop, such as LoadFileStart() and LoadFileStop().

EventSource was introduced in .NET 4.5, so why do I think it’s so important in relation to .NET 4.5.1? The initial version of EventSource had an Achilles Heel – common errors caused silent failures in tracing. Silent failure in the trace can lead to misinterpretation, and since you’re often using traces in time critical scenarios (a euphemism for stuff just hit the fan), that can be a disaster.

The new .NET 4.5.1 version of EventSource solves this problem by communicating failure in two new ways, without raising an exception. An exception in tracing would either crash your application, or would slow it down as you avoided crashing the app.

If the .NET 4.5.1 version of EventSource encounters an issue and can’t output a trace entry, it outputs a zero event trace entry. EventSource identifies individual trace events via an integer, and by convention your EventId’s start with one. Starting in .NET 4.5.1, if tracing fails, TraceSource sends a trace entry with an EventId of zero and information about the failure. So, you can know that there’s a problem and avoid misinterpreting your traces.

This EventSource class shows how easy it is to make the kind of mistakes that lead to zero event failures:

[EventSource(Name = "KadGen-ETWPreMan-TestEventSource")]

public classTestEventSource : EventSource

{ // illustrates problems, do not copy and use

public void LoadFileStart(string FileName)

{ WriteEvent(2, FileName); }

[Event(1)]

public void AccessByPrimaryKey(int PrimaryKey, string TableName)

{ if (IsEnabled()) WriteEvent(1, TableName, PrimaryKey); }

}

There are at least three things here that will cause tracing to fail. Since the first method does not specify its EventId via an attribute, the default is assigned based on its position in the file – so it has an EventId of 1. Since this doesn’t match the first value passed in its WriteEvent call, tracing fails. The second method fails for two reasons. It’s specified EventId conflicts with the implicit EventId of the LoadFileStart method, so is non-unique. But even if this is fixed, tracing fails because the parameters do not match between the method declaration and the WriteEvent call.

The difficulty in guaranteeing that these kinds of problems do not exist in your EventSource code is the reason I think the new diagnostics for EventSource are so important, particularly the zero event trace entries. Zero events are likely to become a well-known pattern, with ETW consumers blaring on about the failure. But for now, keep an eye out for these trace entries.

The other scenario in which the earlier version of EventSource allowed silent failures was the EventSource constructor. Within the constructor, there’s a good chance that target listeners like ETW are not yet correctly hooked up, so the event zero approach could fail because no one was listening. The EventSource class gets a ConstructorException property in.NET 4.5.1. This property will contain any exception thrown by the constructor, with a null value indicating correct construction.

The EventSource class in .NET 4.5.1 also includes a number of new methods and properties that include “ActivityId” in the name. The primary purpose of these features is to lay groundwork for future tools. As a complex operation is performed, many players may be involved – multiple threads or servers contributing to a single logical operation. ActivityId related features allow correlation of these actions – and the great news is that someone else can generally take responsibility for keeping it all straight!

The new EventSource features in .NET 4.5.1 give you a solid tracing foundation and ETW makes it fast enough to turn on in production. Things popping up in the surrounding space – such as the NuGet version, TraceEvent, WPA support in the Windows 8.1 ADK, and SLAB – indicate how exciting the next few years will be for diagnostics. Look for more information on Vance Morrison’s blog and coming up on my blog.

Bio

Kathleen Dollard is passionate about community and has been a Microsoft MVP since 1998. She works to turn good programmers great programmers by training and mentoring individuals and teams. You can follow @KathleenDollard on Twitter and watch her blog at http://msmvps.com/blogs/kathleen.