ETW in C#: Controlling which events get logged in an System.Diagnostics.Tracing.EventSource

In my EventSource demo blog entry we defined an EventSource and turned on the logging with the command

PerfView /OnlyProviders=*MinimalEventSource run eventSourceDemo.exe

Which turned on all the events defined in the 'MinimalEventSource' we defined.    As you add more events to your EventSource, it becomes more and more likely that you will want more control over which events get logged.   In this blog, I will show you how to do this.  

Event Tracing for Windows (ETW) defines two mechanisms for controlling which events actually log their content.   Each event is tagged with two quantities:

  1. A small integer (enumeration) called a 'Level' which defines how verbose the event is.  Levels go from 0 to 5:   0 (Always) 1 (Critical) 2 (Error) 3 (Warning) 4 (Information) 5 (Verbose).  The default is 4 (Informational).   When the provider is turned on a level is specified Only those events that are less than or equal to the specified level will log messages. 
  2. A 64 bit, bit-vector called the events 'Keywords' which define 64 groups that an event can belong to.   When the provider is turned on a a set of keywords is passed in.  Only those events whose keywords overlap with the passed in keywords will log messages. 

 To see how to use these characteristics in your own eventSource consider the EventSource Example below.  

                [EventSource(Name = "MyCompany-WebServices")]
                internal sealed class MyCompanyEventSource : EventSource
                {
                    [Event(1, Keywords = Keywords.Requests)]
                    public void RequestStarted(string Url, int RequestID) { WriteEvent(1, Url, RequestID); }
       
                    [Event(2, Keywords = Keywords.Requests, Level = EventLevel.Verbose)]
                    public void RequestPhase(int RequestID, string PhaseName) { WriteEvent(2, RequestID, PhaseName); }
       
                    [Event(3, Keywords = Keywords.Requests)]
                    public void RequestCompleted(int RequestID) { WriteEvent(3, RequestID); }
       
                    [Event(4, Keywords = Keywords.Debug)]
                    public void DebugTrace(string Message) { WriteEvent(4, Message); }
       
                    public class Keywords // This is a bitvector
                    {
                        public const EventKeywords Requests = (EventKeywords)0x0001;
                        public const EventKeywords Debug = (EventKeywords)0x0002;
                    }
                    static public MyCompanyEventSource Logger = new MyCompanyEventSource();
}

 In this example, we define a 'MyComanyEventSource' and define a static instance of it (in brown at the bottom).   This EventSource has 4 events defined, and you can see that each of these events is 'Decorated' with an 'Event' Attribute which tells the EventSource base class more about the particular event.   These Event Attributes contain

  1. The Event Number.  Each event is given a unique number.  This is the same number that is passed to the first parameter of the 'WriteEvent' method in the event's body.  
  2. A set of additional ETW 'decorations' (Properties) for that event.   In this case we use two additional properties
    1. The 'Keywords' property indicates the keywords bitvector for the event (in blue).  You can see that we define two keywords: Requests, and Debug. 
    2. The 'Level' property indicates the level (verbosity) for the event.  By default is is 'Informational' but in the example above we made 'RequestPhase' a verbose event.

In addition to the event definitions themselves, there is also a nested class called 'Keywords' (you MUST use this name and it MUST be nested) which defined the numeric values for the keywords used in the event definitions.   Each of these should be a binary bit in the 64 bit long value.  

This example assumes that we have two event groups.  The first group (the 'Request' group) tracks a request as it journeys through the system.  Notice only the RequestStart event has the URL associated with the request.  The other events use a small integer value that is faster to write to indicate which exact events is being logged.   There is one verbose method (RequestPhase) which is meant mean for verbose diagnostic purposes and is often not needed.    The other group (the 'Debug') group has only one event DebugTrace that is meant for ad-hoc 'printf-sytle' diagnosis. 

Finally, the EventSource above follows a 'best practice' of naming its ETW provider a good name FROM THE U SER's POINT OF VIEW.   Names should at least start with your company name.  If you expect more than one EventSource for your company it is best to give them categories separated by '-'.   This is the convention that Microsoft has been following for the last several years.  (e.g. Microsoft-Windows-DotNetRuntime).  In the example above we named the provider 'MyCompany-WebServices'.   Please carefully consider this name as if you change it, it will break any users of your EventSource. 

The 'PerfView tool' supports using  levels and keywords with the following syntax.  

  • provider : keywords : level

You can add these at the command line or in the 'Additional Providers' textbox in the 'Advanced Options' section of the collection dialog.  By default PerfView turns on ALL keywords and the VERBOSE level, so the command

PerfView /OnlyProviders=*MyCompany-WebServices collect

Turns on all the events.   You can use '*' for the keyword to represent 'all' keywords so the command

PerfView /OnlyProviders=*MyCompany-WebServices:*:Information collect

Turns on all keywords (the :*:) that are a verbosity of Informational or below.  Thus this turns off the Verbose 'RequestPhase' event.   Currently PerfView does not support using the names of keywords, so you have to specify the keywords as a (hex) number.  Thus the command

PerfView /OnlyProviders=*MyCompany-WebServices:2 collect

Collects only the 'Debug' keyword events (at a Verbose level). 

Best Practices: Keep it Simple from the users point of view!!

Now that you have the ability to finely control which events are emitted, I am going to do something very surprising: I am going to tell you to NOT use it most of the time.  The reason is simple:  Users of your events are FAR more concerned about ease of use than they are about optimizing the size of data collected.    It is FAR more frustrating to not have the events you need than to have too many.  Really the ONLY time people will care is when the events are VERY verbose.   This leads to the following strategy

  • Events that fire less than 100 times a second on average are 'too small to care about'  Don't bother making special keywords for them, but make a catch all 'Default' keyword.
  • Events that fire more than 1K times a second on average need keywords to turn them off if they are not needed.
  • Events in between 100 and 1K are a judgement call
  • Define keywords from a USERS (or scenario) point of view.   Users don't like to set more than one keyword (too error prone) so define the keywords that all common scenarios can be done by setting a single keyword.   Most users will use simply use the default (turn everything on).  
  • Levels less than Informational are meant for relatively rare warnings or errors.   When in doubt stick with the default of Informational, and use verbose for events that can happen more than 1K events / second.    Typically users use Keywords much more than Level, so don't worry about it too much. 

For more best practices and features of EventSources, see the EventSource specification.  

 Again it is your turn, time to try it out!

If you have not already gone to my EventSource demo blog entry and built the VS 2010 demo, you can do that now.   You can try out the example above if you like or simply take a look at the 'MyCompanyEventSource' class in the  'AdvancedUsageDemo.cs' file.    As mentioned this demo works today (because it comes with EventSource.dll which defined EventSource), but will be even easier in a few months when V4.5 of the .NET Runtime ships and EventSource is available in the framework)

Review

Here are some other useful blog entries on EventSource:

  1. Introduction to EventSource 
  2. EventSource specification
  3. When you should be using EventSource