In a previous post I discussed the joys of using the Windows Performance Toolkit to record and analyze Windows slowdowns. In summary, you can record a system trace using Windows Performance Recorder (WPR), and then use Windows Performance Analyzer (WPA) to visually drill into CPU, memory, & disk usage to figure out what is causing your slowdown.
The power of WPT does not end there. You can instrument and register your own Windows binaries to log events that can appear side by side with Windows system events. If you’ve ever tried to correlate your application logs with the Windows Event Viewer, or Process Monitor, you will immediately see the value here.
There are few steps involved in making this happen:
- Instrument your binary with Event Tracing for Windows (ETW) logging. ETW is a high performance logging mechanism that is baked into Windows. The instrumentation process is different for desktop apps, Windows Store apps, and drivers but all are supported.
- Register your binary as an ETW provider on the system.
- Configure WPR to enable your provider, and run your scenario. (You could also use xperf or an ETW controller of your choice.)
- Save the trace and open it with WPA.
The first two steps are out of scope of this article, but they are not particularly difficult thanks to some decent tools (ecmangen, mc, wevtutil). This article is a good starting point. [Update: Article is now only available as a .chm file. Download the April 2007 edition of MSDN Magazine from the link]
The next step is to create a Windows Performance Recorder Profile (wprp) file so that WPR knows how to enable your provider. MSDN has an article on authoring wprp profiles, but it is a little more complicated than we need.
I have cribbed from a couple of sources (including Bruce Dawson) and come up with a wprp profile that is about as simple as you can get. Comments inline.
<!-- A fully specified .wprp file should have four profiles, with DetailLevel set to Verbose and Light and with Logging Mode set to Memory and File. WPR enforces that the name conforms to Profile.Level.OutputType -->
You can add this profile to WPR and enable any other providers that you like.
Now you just need to start recording, run your scenario, and save your trace to disk. When you open the trace, you should magically see your provider and its associated events under System Activity -> Generic Events.
Mission accomplished! I can now see exactly what happens on the system during my events of interest. Starting in WPT 8.1, you can even link events together using Regions of Interest. This is pretty well documented so I’ll save it for another time (or never).