Incorporating TraceSource and Other Techniques with EventSource

I got a great question on ETW/EventSource/Semantic Tracing from someone watching my Pluralsight course on ETW and EventSource:

I am going through your ETW training on Pluralsight. I like the content. Want to thank you for it.

I want to embrace semantic logging and go all out for it. And I have a question:

  • If I am developing on .NET 4.5/4.5.1, should I use just EventSource class or do you see any need for using TraceSource as well? This question emanates from the fact that there are two kinds of logging – one is exception logging – which I want to do no matter what, irrespective of whether or not the ETW provider has been enabled or not. Second kind is tracing log, which I may want to do only when the provider is enabled.

So in the exception logging case above, should I use EventSource with SeverityLevel of “LogAlways” or should I use TraceSource for this (as we did earlier) and use ETW for trace logging only.

It will be great to get your thoughts on this.

I want to answer in two parts. First, the great, fantasmicalogical thing about Semantic Tracing is that you make this decision in an isolated location. Since a semantic trace method is just a method that wraps whatever tracing you’re doing, it can be as flexible as you want it to be. Call this single, simple, IntelliSense supported method from the body of your application, pass the interesting information as parameters, and then do whatever you want in the body of that method. If you like, you can call EventSource and then also log in a different way, even TraceSource.

In some cases, the signature of the Semantic Trace method and the signature of the WriteEvent method of the EventSource class are different. In this case, wrap a private WriteEvent method with a public method and put the NonEvent attribute on the public method

Semantic Tracing is more than just friendly to parallel use of other trace technology. The more complicated your needs, and the more older technology you’re using, the more important it is to hide it behind the Semantic Tracing method façade so you can adjust later.

So, the next question – what is TraceSource offering that you don’t otherwise have with EventSource and ETW? You’ve identified a couple of aspects. You can control, at application startup via configuration, that certain trace events will always be recorded. With ETW and EventSource, if no one is listening, no one is listening, and even trace events marked “LogAlways” will be dropped on the floor.

Also, exceptions don’t happen very often. Since it’s rare and terribly important, a performance hit to record the exception is acceptable. I think the deeper issue is how you control the pipeline – and who controls the pipeline – what happens after the trace is recorded.

One approach you can take is to use the NuGet version, write to the admin channel, ensure that the provider is properly registered on the target machine and use reporting features of Event Viewer to route the exception to the right people. I think it will be very common for trace events written to the Admin channel to also be written to the Debug channel from the same semantic trace method. Just use a public NonEvent wrapper method that calls two private event methods, along with variations in the data appropriate to each channel. While performance won’t be hurt if you send a lot of messages to the admin channel, it will teach your IT staff to ignore what you put in Event Viewer, so save this for rare, high importance messages.

Another approach is to use TraceSource, and if other applications in your organization are reporting through a particular listener, this can be a great idea. Similarly Log4Net can still play a role. Although these tools work in process so certain types of application crashes aren’t captured because the streams aren’t flushed correctly. Be careful about doing this for anything other than rare events of very high importance. Excess calls will create performance problems.

With both the admin channel and TraceSource/Log4Net approaches, I suggest that you create a semantic tracing method, and from that single method call you place the trace event information in multiple locations. The semantic trace method hard codes the calls you’re making.

There are two other approaches that allow simple “normal” EventSource methods to serve as your semantic trace methods. With these two approaches, your EventSource class is unchanged to accommodate the requirement to always log.

The Semantic Logging Application Block from Patterns (SLAB) works in two modes, in process and out of process. In process allows you to start SLAB from your configuration, as you do with TraceSource. However, it also retains the TraceSource problem of losing critical final events with certain types of crashes.

Out or process, you can start a service that SLAB provides to act as a controller. You can filter to the specific events you consider critical and route these events to traditional locations, like a log file. The real value here is routing to those traditional locations (console, log, XML, SQL). That’s particularly useful during development, but it can also be used across the life cycle. Out of process SLAB will record final events, as long as the service and its output locations remains functional. You will need to start the service at application startup. You can check out more in the SLAB documents (which are awesome).

A more complex possibility, possibly more appropriate on a server, is to ensure ETW listeners are started when your application is started. One way to do this is by starting your application with a script. I realize that PerfView is hard to use, but if you get the command line correct, you can do “flight recorder” tracing. You can set PerfView to maintain a rotating buffer of informational events that it writes out permanently only when something bad like an exception happens. How cool would it be to have the previous five minutes (arbitrary) of informational trace event when your application crashes?

So, there are four ways to provide special handling for exceptions to ensure they are always recorded, while staying within your commitment to do Semantic Tracing:

  • Write semantic trace methods that write to the debug and admin channel and use EventViewer
  • Write semantic trace methods that write to ETW and a legacy tool like TraceSource or Log4Net
  • Use the Semantic Logging Application Block to log to write certain EventSource events to an alternate stream in process or out of process
  • Start an ETW session automatically when your application starts up

At some future point, I hope .NET makes it extremely easy to automatically start an adjacent ETW session.

Thanks for asking such a great question!

Leave a Reply

Your email address will not be published. Required fields are marked *