Category Archives: 18226

Semantic Tracing


I talk about semantic tracing in my Pluralsight course Event Tracing for Windows (ETW) in .NET. Here’s a summary.

The Semantic Logging Application Block (SLAB) documentation discusses semantic tracing here. This is great documentation, but obscures the fact that semantic tracing can be done on any platform in any language. It’s just a style of tracing.

You create a class, or a very small number of classes, dedicated to tracing (pseudo-code)

public class Logger
    public static Logger Logger = new Logger();
    public void AccessByPrimaryKey(int PrimaryKey, string TableName)
    public void CalculateGrowthRateStart(int InitialPopulation)
    public void CalculateGrowthRateEnd()
    // Numerous methods

.csharpcode, .csharpcode pre
font-size: small;
color: black;
font-family: consolas, “Courier New”, courier, monospace;
background-color: #ffffff;
/*white-space: pre;*/
.csharpcode pre { margin: 0em; }
.csharpcode .rem { color: #008000; }
.csharpcode .kwrd { color: #0000ff; }
.csharpcode .str { color: #006080; }
.csharpcode .op { color: #0000c0; }
.csharpcode .preproc { color: #cc6633; }
.csharpcode .asp { background-color: #ffff00; }
.csharpcode .html { color: #800000; }
.csharpcode .attr { color: #ff0000; }
.csharpcode .alt
background-color: #f4f4f4;
width: 100%;
margin: 0em;
.csharpcode .lnum { color: #606060; }

Now tracing just involves knowing the logger class name and typing:


.csharpcode, .csharpcode pre
font-size: small;
color: black;
font-family: consolas, “Courier New”, courier, monospace;
background-color: #ffffff;
/*white-space: pre;*/
.csharpcode pre { margin: 0em; }
.csharpcode .rem { color: #008000; }
.csharpcode .kwrd { color: #0000ff; }
.csharpcode .str { color: #006080; }
.csharpcode .op { color: #0000c0; }
.csharpcode .preproc { color: #cc6633; }
.csharpcode .asp { background-color: #ffff00; }
.csharpcode .html { color: #800000; }
.csharpcode .attr { color: #ff0000; }
.csharpcode .alt
background-color: #f4f4f4;
width: 100%;
margin: 0em;
.csharpcode .lnum { color: #606060; }

With IntelliSense at every step this is about a dozen keystrokes. The only specific knowledge you need is the name of the Logger class – and with Visual Studio IntelliSense, you’ll get that easily if you include “Logger” anywhere in the name. Just imagine how simple that is!


Discoverability and easy access are just two of the benefits of this style of logging.

The call to the trace method states what is happening and helps to document the calling source code. This is especially true if you use named parameters.

The resulting trace output is strongly typed and easily filtered and sorted on specific named parameter values.

Strongly typed parameters improve performance by avoiding string creation and avoiding boxing on any platform that has cheap stacks and expensive heap memory usage (such as .NET).

All access to the underlying tracing technology is isolated. Stuck with TraceSource now, but intimidated by the potential of future performance issues? Move to semantic tracing and the future change to USE EventSource and ETW will involve a single file. Any change that doesn’t involve the signature, even a technology change, is isolated to a single class.

Another implication of isolated tracing is that details can be added and removed as they are available via the underlying technology – things like thread and user.

Details about the trace are also consistent. The calling code is unconcerned about issues like level (error, warning, information), channel, and keywords. These details can be changed at any point in the application life cycle.

The result is a trace strategy that is clear and consistent.

ETW, EventSource and SLAB

Both EventSource and SLAB encourage semantic tracing, assuming you avoid creating generic trace methods like “Log” and “Warning.” Semantic logging involves giving a nice name to the method, along with strongly typed parameters.

You might want vague methods to keep you going one afternoon when you encounter something new you want to trace, but use them as a temporary measure.

Whether a particular event is a warning, information or an error is in the nature of the action, not the nature of this particular occurrence of the action – or it’s not very well defined, and it’s not semantic.


One of the most important tools in improving your trace performance is semantic tracing. Simply put, it means that all trace calls are to a common class, or small set of classes, that have methods indicating each specific thing you will trace along with strongly typed parameters. The trace method and each trace parameter has a very clear name allowing IntelliSense to guide correct calls.

Multiple Versions of EventSource and One Version of SLAB

There are several versions of EventSource. .NET 4.5 has the initial version, which is improved in .NET 4.5.1. You want to use the 4.5.1 version if you possibly can. The diagnostics, in particular are significantly better.

The CLR team has also done a pre-release version of EventSource on NuGet. This version has a couple of important features, including even better diagnostics and Windows Event Viewer support. That’s right, you have to use the latest and greatest NuGet version if you have events you want admins to see in EventViewer.

Switching from EventSource in .NET 4.5.1 to the NuGet version of EventSource just requires changing the references and namespaces.

The Patterns and Practices team provides SLAB (Semantic Logging Application Block) that uses EventSource extensibility to offer a more familiar experience. In particular, SLAB offers traditional listeners so you can avoid ETW complexities during development. At runtime, you probably want ETW performance, but the tools still stink and you probably don’t want to use them during development.

The P&P team thinks all this multiple version of EventSource stuff is confusing. Well, they are right, it is confusing.

Rather than offer a version of SLAB for the NuGet version of EventSource, the P&P team decided to stick with a single version of SLAB that targets the .NET 4.5.1 version of EventSource.

If you want a version of SLAB that targets the NuGet version of EventSource, download the SLAB source code and make the same changes you’d make to your own code – change the references and namespaces. Here Grigori Melnik says SLAB 1.1 will improve the test suite to better support this modification.

What does Blazingly Fast Tracing Mean

I wrote a summary of ETW here and some basics here. I’ll be posting more to coincide with my new Pluralsight course on ETW tracing.

ETW tracing is blazingly fast. The operating system tosses the trace work like accessing files onto another thread. It does this at a very low level allowing very, very fast tracing when tracing is turned on. If tracing is turned off, the performance hit is even smaller. But why worry about tracing turned off!?!?! The goal is creating a trace system you can leave on in production!

OK, that’s a good sound bite, but while I think you should have some tracing that you leave on all the time, you might also want some high frequency event that you have on only some of the time, such as when you’re doing a particular kind of evaluation.

Here are some rough performance metrics I did a while ago – this is on my laptop with a fair amount of open applications.




Object Overload


Event Off


100 million/sec


50 million/sec

Event Watched


2 million/sec


1 million/sec


Don’t get carried away with the details of these numbers, and do your own metrics if you feel the details are important. A nanosecond is one billionth of a second. Dedicating the CPU to tracing (a loop) allows about 2 million trace calls/sec with tracing turned on, 100 million with tracing turned off. That’s really, really fast.

But, Ok, you aren’t going to dedicate 100% of your CPU to tracing.

More or less, if you allow 1% of your system resources for tracing, with it turned on, you can do about twenty thousand trace events per second (20,000!). OK, there’s latency and throughput, but I’ll argue at 1% you just don’t care. Doing a super high throughput system with 10,000 transactions/second? You can probably still afford a few trace calls per request – yes, in production (benchmark that in your specific scenario).

By the way, the specification suggests that the hit of using the fallback overload that takes parameter array of objects might have an impact of 10-20 fold. I didn’t see that. The spec explains how to add more overloads – but it’s ugly, requires unsafe code and not something I think you initially need to worry about. It’s about double, and you can add required overloads when you need tracing at half a millionth of a second, instead of a millionth of a second.

The spec also suggests that you might see a performance increase using a locally cached copy of the logger, rather than repeated hits to a static property on the log class. I have not been able to measure any performance improvement, so this unnecessarily complicates your code (unless you are using DI, which I recommend for many, many things, but not tracing).

When you turn tracing off, the impact drops by nearly two orders of magnitude.

You can’t get anywhere close to this kind of performance out of any other trace technique I know of. Certainly not from Trace.Write, TraceSource, or Log4Net.

Some ETW Basics

I wrote a summary of ETW here. I’ll be posting more to coincide with my new Pluralsight course on ETW tracing.

This is just a quick post so I can link back to these basics.

Tracing is what you include in your code so you know what’s happening during development and more importantly in production. Supporting players like .NET and the operating system also have trace output.

ETW stands for Event Tracing for Windows and is the tracing mechanism built into the Windows operating system.

ETW has controllers that turn tracing on and off, providers that create trace event entries, and consumers that let you view traces. Managing ETW tracing requires tools.

.NET provides good ETW support starting with .NET 4.5 with the EventSource class. This creates an ETW provider. You need external tools (not yet available in Visual Studio) to create and view traces.

ETW tracing with the EventSource class is fundamentally different than Trace and TraceSource. It is a different pipeline, configured with ETW tools, and can be turned on and/off without restarting your app.

ETW does the slow part of tracing on a separate thread. Trace, TraceSource, Log4Net and most other trace solutions do not do this, or not with the massive efficiency and blazingly fast performance of ETW.

Semantic tracing logically decouples from trace technology, isolates trace decisions like severity, is strongly typed (at the app), and states what is happening in the app, not details of what the trace should say.

Semantic tracing can be done with any trace technology, allowing you to switch later to ETW if you can’t do it now.

The Semantic Logging Application Block (SLAB from P&P) uses EventSource, avoids ETW tools during development, eases the transition to ETW, and has docs on using a semantic approach to tracing.

How are Event Parameters Best Used to Create an Intuitive Custom EventSourceTrace

Jason asked a really, really good question on StackOverflow. I’m answering it here, because it’s a wordy answer. The good news, is the answer is also in my about-to-be-released ETW Pluralsight video on ETW (everything is in their hands, just not posted yet, hopefully next Thursday!). I’ve also got some additional blog posts coming, but today, let me just answer Jason’s question.

“it is unclear how some of the properties are best used to create an intuitive custom trace”

Jason goes on to categorize Event attributes as “intuitive” and “non-intuitive”. I’m throwing out that distinction and covering all of them. And the most important advice might be the last on Message.


ETW supports four basic channels and the potential for custom channels. EventSource does not support custom channels (if you have a user story, contact me or the team). The default channel and the only one currently supporting in-line manifests is the Debug channel.

The Channel parameter exists only in the NuGet version and only for the purpose of accessing the additional channels, primarily the admin channel to access EventViewer for messages to admins. I was one of the people that fought for this capability, but it is for a very limited set of cases. Almost all events logically write to your channel – the default channel – the Debug channel.

To write to EventViewer, you need to write to the Admin channel and install a manifest on the target computer. This is documented in the specification, in my video, and I’m sure a couple of blog posts. Anything written to the admin channel is supposed to be actionable by ETW (Windows) guidelines.

Use Operational and Analytic channels only if it is part of your app requirements or you are supporting a specific tool.

In almost all cases, ignore the Channel parameter on the Event attribute and allow trace events to go to the Debug channel.


For the Admin Channel

If you are writing to the admin channel, it should be actionable. Information is rarely actionable. Use warning when you wish to tell them (not you, not a later dev, but ops) that you want them to be concerned. Perhaps that response times are nearing the tolerances of the SLA. Use error to tell them to do something. Perhaps that someone in the organization is trying to do something they aren’t allowed to do. Tell them only what they need to know. Few messages, but relatively verbose and very clear on what’s happening, probably including response suggestions. This is “Danger, danger Will Robinson” time.

For the Debug Channel

This is your time-traveling mind meld with a future developer or a future version of yourself.

I’m lucky enough to have sat down several times with Vance, Dan and Cosmin and this is one of the issues they had to almost literally beat into my head. The vast majority of the time, your application can, and probably should run with the default information turned on.

If you’re looking at an event that clearly represents a concern you have as a developer – something you want to scare a later developer because it scares you – like a serious failed assert – use warning. If someone is holding a trace file with ten thousand entries, what are the three things or the ten things you think tell them where the problem is? If they are running at the warning (not informational level) what do they really, truly need to know?

If it’s an error, use the error level.

If it’s a massively frequent, rarely interesting event, use verbose. Massively frequent is thousands of times a second.

In most cases, use the default informational level for the Level parameter of the Event attribute. Depending on team philosophy, ignore it or record it.


If you have verbose events, they need to be turned on and off in an intelligent fashion. Groups of verbose events need keywords to allow you to do this.

Warnings and Error levels do not need keywords. They should be on, and the reader wants all of them.

The danger of missing an event so vastly outweighs the cost of collecting events that informational events should be turned on without concern for keywords. If keywords aren’t going to be used to filter collection, their only value is filtering the trace output. There are so many other ways to filter the trace, keywords are not that helpful.

In most cases, use the Keywords parameter of the Event attribute only for verbose events and use them to group verbose events that are likely to be needed together. Use Keywords to describe the anticipated debugging task where possible. Events can include several Keywords.


On the roller coaster of life, we just entered one of the scary tunnels – the murky world of ETW trace event naming. As far as ETW is concerned, your event is identified with a numeric ID. Period.

Consumers of your trace events have a manifest – either because it’s in-line (default for Debug channel, supported by PerfView and gradually being supported by WPR/WPA) or installed on the computer where the trace is consumed. The manifest does not contain an event name that is used by consumers.

Consumers, by convention, make a name from your Task and Opcode.

EventSource exists to hide the weirdness (and elegance) of ETW. So it takes the name of your method and turns it into a task. Unless you specify a task. Then it uses your task as the task and ignores the name of your method. Got it?

In almost all cases, do not specify a Task parameter for the Event attribute, but consider the name of your method to be the Task name (see Opcode for exception).


I wish I could stop there, but Jason points out a key problem. The Start and Stop opcodes can be very important to evaluating traces because they allow calculation of elapsed time. When you supply these opcodes, you want to supply the Task to ensure proper naming.

And please consider the humans. They see the name of the method, they think it’s the name displayed in the consumer. For goodness sakes make it so. If you specify a task and opcode, ensure that the method name is the concatenation. Please

This is messy. I’m working on some IDE generation shortcuts to simplify EventSource creation and this is a key reason. I think it will help, but it will require the next public release of Roslyn.

Almost never use an Opcode parameter other than Start/Stop.

When using Start/Stop Opcodes, also supply a Task and ensure the name of the method is the Task concatenated with the Opcode for the sake of the humans.


The version parameter of the Event attribute is available for you and consumers to communicate about whether the right version of the manifest is available. Versioning is not ETW’s strength – events rarely changed before we devs got involved and now we have in-line manifests (to the Debug channel). You can use it, and the particular consumer you’re using might do smart things with it. And even so, the manifest is or is not correctly installed on any machines where installed manifests are used.

Overall, I see some pain down this route.

The broad rule for versioning ETW events is don’t. That is do not change them except to add additional data at the end (parameters to your method and WriteEvent call). In particular, never rearrange in a way that could give different meaning to values. If you must remove a value, force a default or marker value indicating missing. If you must otherwise alter the trace output, create a new event. And yes, that advice sucks. New events with “2” at the end suck. As much as possible, do up front planning (including confidentiality concerns) to avoid later changes to payload structure.

Initially ignore the Version parameter of the Event attribute (use default), but increment as you alter the event payload. But only add payload items at the end unless you can be positive that no installed manifests exist (and I don’t think you can).


Did you notice that so far I said, rarely use any of the parameters on the Event attribute? Almost never use them.

The Message parameter, on the other hand, is your friend.

The most important aspect of EventSource is documenting what the event needs from the caller of the code. It’s the declaration of the Event method. Each item passed should be as small as possible, non-confidential, and have a blazingly clear parameter name.

The guy writing against your event sees an available log method declaration like “IncomingDataRequest(string Entity, string PrimaryKey).” Exactly how long does it take him to get that line of code in place? “IncomingRequest(string msg)” leaves the dev wondering what the message is or whether it’s even the correct method. I’ve got some stuff in my upcoming video on using generics to make it even more specific.

Not only does special attention to Event method parameters pay off by speeding the writing of code that will call the Event method (removing all decision making from the point of the call), but (most) consumers see this data as individual columns. They will lay this out in a very pretty fashion. Most consumers allow sorting and filtering by any column. Sweet!

This is what Strongly Typed Events are all about.

Parameters to your method like “msg” do not cut it. Period.

In addition to the clarity issues, strings are comparatively enormous to be sticking into event payloads. You want to be able to output boatloads of events – you don’t want big event payloads filling your disks. Performance starts sucking pretty quickly if you also use String.Format to prepare a message that might never be output.

Sometimes the meaning of the parameter is obvious from the name of the event. Often it is not. The contents of the Message parameter is included in the manifest and allows consumers to display a friendly text string that contains your literals and whatever parts of the event payload seem interesting. Sort of like String.Format() – the “Message” parameter is actually better described as a “format” parameter. Since it’s in the manifest, it should contain all the repeatable parts. Let the strongly typed data contain only what’s unique about that particular call to the trace event.

The Message parameter uses curly braces so you feel warm and fuzzy. That’s nice. But the actual string you type in the parameter is passed to the consumer, with the curly braces replaced with ETW friendly percent signs. Do not expect the richness of String.Format() to be recognized by consumers. At least not today’s consumers.

By splitting the data into strongly typed chunks and providing a separate Message parameter, the person evaluating your trace can both sort by columns and read your message. The event payload contains only data, the manifest allows your nice wordy message. Having your beer and drinking it too.

Not sold yet? If you’re writing to a channel that uses installed manifests, you can also localize the message. This can be important if you are writing to the admin channel for use in EventViewer.

Almost always use Message so consumers can provide a human friendly view of your strongly typed event payload.


There are four basic rules for EventSource usage:

  • Give good Event method names
  • Provide strongly typed payload data – consider confidentiality – and work to get payload contents right the first time (small where possible)
  • Use the Message parameter of the event attribute for a nice human friendly message
  • For every other Event attribute parameter – simplify, simplify, simplify. Use the defaults unless you are trying to do something the defaults don’t allow