Pushing ETW events through SignalR

ETW or Event Tracing for Windows is a very efficient pub/sub built-in mechanism that runs in Kernel Mode for doing event tracing. That implies there is just a little overhead in using this feature compared to other traditional tracing solutions that are I/O bound and drop the traces in different storages like files or databases for example. As it is a built-in mechanism in Windows, many of the operating systems services and components make good use of it. You can not only troubleshoot your application but also many of the OS components involved in the execution of that application.

In ETW, you have applications publishing events in queues (or providers) and other applications consuming events from those queues in real-time through ETW sessions. When an event is published in a provider, it goes nowhere unless there is session collecting events on that queue. (The events are not persisted).

The adoption of ETW in .NET application was pretty low as it was very hard to configure and use. However, things might change now that .NET 4.5 supports a new EventSource class for publishing events easily in any .NET application. Another way to publish events in the past was to use .NET diagnostics infrastructure with the trace listener for ETW, “EventProviderTraceListener”.

About this last one, it can be easily configured and associated to a trace source as it is shown bellow,

<system.diagnostics>
  <sources>
    <source name="MyConsoleApp" switchValue="Verbose">
      <listeners>
        <add name="ETWListener" type="System.Diagnostics.Eventing.EventProviderTraceListener, System.Core, Version=3.5.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089"
               initializeData="13D5F7EF-9404-47ea-AF13-85484F09F2A7" />
      </listeners>
    </source>
  </sources>

  <trace autoflush="true"/>
</system.diagnostics>

The trace listener is associated to a GUID through the initializeData attribute. That identifier is used by ETW and associated to the provider, so it’s the one you will use to collect the events in a session.

Once the listener is configured, you can start publishing events in that provider through a the trace source.

TraceSource myTraceSource = new TraceSource("MyConsoleApp");

myTraceSource.TraceEvent(TraceEventType.Error, 1, "Tracing Error Message.");
myTraceSource.TraceEvent(TraceEventType.Warning, 2, "Tracing Warning Message.");
myTraceSource.TraceEvent(TraceEventType.Information, 3, "Tracing Information.");
myTraceSource.TraceEvent(TraceEventType.Verbose, 4, "Tracing Verbose Message.");
myTraceSource.TraceEvent(TraceEventType.Critical, 5, "Tracing Critical Message.");
            
myTraceSource.Close();

Listening for those events in a ETW session is a different story. The standard procedure is to use a set of tools for starting an ETW session and dump the events into a binary file with a proprietary format (these are “etl” files), that can be imported in the event log viewer or an specific tool for this kind of file. You also have a tool for converting “etl” files to more user readable formats like xml or cvs. However, you can also use the ETW unmanaged API to start a new session and subscribe to the events as it was done with the EventTraceWatcher implementation in this sample.

var providerId = new Guid("13D5F7EF-9404-47ea-AF13-85484F09F2A7");

using (EventTraceWatcher watcher = new EventTraceWatcher("MySession", providerId))
{
  watcher.EventArrived += delegate(object sender, EventArrivedEventArgs e)
  {
    if (e.Error != null)
    {
      Console.Error.WriteLine(e.Error);
      Environment.Exit(-1);
    }

    // Dump properties (key/value)
    foreach (var p in e.Properties)
    {
      Console.WriteLine("Event", "\t" + p.Key + " -- " + p.Value);
                        
    };

    // Start listening
    watcher.Start();

    Console.WriteLine("Listening...Press <Enter> to exit");
    Console.ReadLine();
}

You use the EventTraceWatcher to subscribe to events generated by an ETW provider, which are received as part of an event. What’s really interesting about this code is that it runs out of process. You could be collecting the events in a completely different application in the same host and doing whatever you want with those events like persisting them in a database for example. The performance of the application generating the events would not be affected at all.

Now, imagine that you have a service running in one of your servers, which can be used to start a new ETW session and publish those events via SignalR. In that way, you can connect with a browser to the SignalR hub created by that service and get the events realtime, which represents an interesting way to see what’s going on your server at a given time.

You can do an slight change to the code using the EventTraceWatcher to publish the events to a SignalR hub as it is shown bellow,

class Program
{
    static void Main(string[] args)
    {
        string url = "http://localhost:8080";

        using (WebApplication.Start<Startup>(url))
        {
            Console.WriteLine("Server running on {0}", url);
                
            var hubConnection = new HubConnection("http://localhost:8080/");
            var serverHub = hubConnection.CreateHubProxy("EventsHub");
            hubConnection.Start().Wait();

            var providerId = new Guid("13D5F7EF-9404-47ea-AF13-85484F09F2A7");

            using (EventTraceWatcher watcher = new EventTraceWatcher("MySession", providerId))
            {
                watcher.EventArrived += delegate(object sender, EventArrivedEventArgs e)
                {
                    if (e.Error != null)
                    {
                        Console.Error.WriteLine(e.Error);
                        Environment.Exit(-1);
                    }

                    // Dump properties (key/value)
                    foreach (var p in e.Properties)
                    {
                        serverHub.Invoke("PushEvent", "\t" + p.Key + " -- " + p.Value).Wait();
                    }
                };

                // Start listening
                watcher.Start();

                Console.WriteLine("Listening...Press <Enter> to exit");
                Console.ReadLine();
            }

            Console.ReadLine();
        }
    }
}

class Startup
{
    public void Configuration(IAppBuilder app)
    {
        // Turn cross domain on 
        var config = new HubConfiguration { EnableCrossDomain = true };
            
        // This will map out to http://localhost:8080/signalr by default
        app.MapHubs(config);
    }
}
        
public class EventsHub : Hub
{
    public void PushEvent(string message)
    {
        Console.WriteLine("Event: " + message);

        Clients.All.PushEvent(message);
    }
}

This uses SignalR hosted in a console application with OWIN, so it could be literally moved to a windows service as well. Every time an event is captured from the ETW session, it is published in the SignalR hub.

On the other side, you can also use SignalR to subscribe to the same hub and receive the generated messages at real time.

<script type="text/javascript">
    $(function () {
        var messages = $('#messages');

        var connection = $.hubConnection('http://localhost:8080');
        connection.start()
            .done(function () {
                console.log("Connected, transport = " + connection.transport.name);
            })
            .fail(function () { console.log('Could not connect'); });

        var proxy = connection.createHubProxy('EventsHub');

        proxy.on('PushEvent', function (message) {
            messages.append(message + "<br>");
        });
    });
</script>

The code is available at Github, https://github.com/pcibraro/RealtimeTracing