TraceLogging events in event viewer

I’ve been using the TraceLogging ETW wrapper and can make pretty nice detailed traces using the Windows Performance Recorder.

I’m wondering if anybody knows if you can get TraceLogging events to show up in a driver specific ETW log viewable in event viewer, and/or the global system log. TraceLogging has this concept of channels, but I haven’t found the correct magic to make them work yet. I would like to enable an operational log that’s just always recording things like errors detected by the driver, and perhaps send some events to the global system log if a really bad error is detected. In the past I’ve created XML manifest files with full ETW event metadata to interface with these ETW logs, but have so far not had success getting TraceLogging self-described events to show up. It would be ideal if I could also automatically get the event manifest to register when the drivers is installed, much like the WMI MOF resource gets automagically installed.

Thanks,
Jan

Not sure you’re going to find a magical way. Look at “wevtutil.exe” to
install your manifest. In your driver installer just call this utility.
That’s how I got it working.

On Thursday, October 13, 2016, Jan Bottorff wrote:

> I’ve been using the TraceLogging ETW wrapper and can make pretty nice
> detailed traces using the Windows Performance Recorder.
>
>
>
> I’m wondering if anybody knows if you can get TraceLogging events to show
> up in a driver specific ETW log viewable in event viewer, and/or the global
> system log. TraceLogging has this concept of channels, but I haven’t found
> the correct magic to make them work yet. I would like to enable an
> operational log that’s just always recording things like errors detected by
> the driver, and perhaps send some events to the global system log if a
> really bad error is detected. In the past I’ve created XML manifest files
> with full ETW event metadata to interface with these ETW logs, but have so
> far not had success getting TraceLogging self-described events to show up.
> It would be ideal if I could also automatically get the event manifest to
> register when the drivers is installed, much like the WMI MOF resource gets
> automagically installed.
>
>
>
> Thanks,
>
> Jan
>
> —
> NTDEV is sponsored by OSR
>
> Visit the list online at: http:> showlists.cfm?list=ntdev>
>
> MONTHLY seminars on crash dump analysis, WDF, Windows internals and
> software drivers!
> Details at http:
>
> To unsubscribe, visit the List Server section of OSR Online at <
> http://www.osronline.com/page.cfm?name=ListServer&gt;
></http:></http:>

Just a follow-up to my own question. You CAN get TraceLogging events to show up in event viewer, if you do a trivial but completely undocumented little adjustment. It tried the following on Server 2016, and assume it works on Win 10 also. Not sure what it does on Server 2012 R2 update or Windows 8.1.

It turns out, if you generate a .H include file from a ETW manifest file, the keyword field in the event definitions have some bits set in the top byte. The system seems to use these for filtering the events into different event channels. The event manifest compiler knows to do this. The TraceLogging APIs know nothing about these magic filter bits, but you can add them yourself.

The requirements for getting TraceLogging events into the system/custom ETW log are:

  1. Create an ETW manifest file, defining the provider and channels. The order of channels in the file is important, the first channel you define will need the most significant bit of the event keyword set, the second channel will require the second most significant bit. You can use the ImportChannel directive to make the System (or Security or Application) event log one of your channels. For your custom channels, the name is parsed into levels at the dash character. So a name OurCompany-OutProduct-OutComponent/Operational will generate 4 levels in the event log naming hierarchy. You can also set some options to enable/disable the log by default.

  2. You can define keywords and a mask value, keep the top byte 0 of 64-bits in the mask

  3. When you build your project, ask it to build a .H kernel function interface, this gives you some #defines for the channel and keywords

  4. Define the TraceLogger global control structure normally

  5. Define some 64-bit constants, with 1 bit in the top byte set, to match the channels you defined in the manifest, the first channel you define/import will have a keyword value of 0x8000000000000000, the second 0x4000000000000000. It would be nice if the manifest compiler generated these constants automatically, but it currently doesn’t.

  6. When you want to write an event to the system event log or a custom log, in the call to TraceLoggingWrite you need to add the parameter macro TraceLoggingChannel() and TraceLoggingKeyword(). You can use multiple TraceLoggingKeyword parameters for other filter keywords, and the bits are ored, so you can make events that feed to an event channel, or are enabled by a manual trace session.

  7. You need to register the manifest with the wevtutil tool. It looks possible registry stuffing from an INF file might get the manifest installed too

  8. Your driver can now write TraceLogging events that show up in the ETW log, although it’s text format doesn’t use a nice variable substitution string like a full manifest defined event. If you click details, it will show the event name, and parameters values. You also can export the event xml with the structured logged fields.

  9. Note that while event viewer was open, I noticed that reloading the driver via .kdfiles got an error, and the driver was not updated, so you need to exit event viewer during development and driver restart. I did use a manifest that defined a resource and message path, and suspect event viewer does not let go of the driver file.

  10. There is a sample in the WDK, OSR’s FX2 I believe, that shows full manifest based event definition. This was very useful sample, especially looking at the generated .H file.

  11. A BIG advantage of TraceLogging or manifest defined events over WPP tracing is you get to use the activity field, which is extremely useful for filtering events after collection, assuming you generate unique activity ids. For example, if I’m tracing interrupt activity, my driver generates a unique activity id in the ISR and stores it in the interrupt context. I then tag all the activity caused by this specific interrupt. The related activity field allows creating connections between activity ids, so I can be processing some interrupt generated activity, which eventually caused an upper I/O completion, and can tag an event with both the interrupt activity id and activity id from the original I/O request, allowing you to find an I/O event, and find the interrupt activity that resulted in I/O completion. A problem with rich detailed traces has always been filtering, and this helps a lot. Filtering is also easier if you use care in your event field names.

  12. It also is possible to have mixed TraceLogging and manifest based logging, using the same provider registration. You have to do some fudging of the provider initialization, which is all in source code in the generated .h file. Manifest based events are more work, but are prettier in event viewer. Manifest based events can’t be decoded without the manifest, although I assume are a little higher performance and smaller than TraceLogging events, as you don’t write the event metadata with the event. Exporting the log to XML or .evtx I believe stores the event metadata for viewing on any machine.

So now not only can my driver collect detailed debugging traces using Windows Performance Recorder (I tend to use Message Analyzer 1.4 or perfview to look at the detailed traces), the operational log (or global system log) is always enabled, and it can write rare but really useful operational stuff, like if the hardware is malfunctioning.

Jan

From: on behalf of Jan Bottorff
Reply-To: Windows List
Date: Thursday, October 13, 2016 at 12:31 AM
To: Windows List
Subject: [ntdev] TraceLogging events in event viewer

I’ve been using the TraceLogging ETW wrapper and can make pretty nice detailed traces using the Windows Performance Recorder.

I’m wondering if anybody knows if you can get TraceLogging events to show up in a driver specific ETW log viewable in event viewer, and/or the global system log. TraceLogging has this concept of channels, but I haven’t found the correct magic to make them work yet. I would like to enable an operational log that’s just always recording things like errors detected by the driver, and perhaps send some events to the global system log if a really bad error is detected. In the past I’ve created XML manifest files with full ETW event metadata to interface with these ETW logs, but have so far not had success getting TraceLogging self-described events to show up. It would be ideal if I could also automatically get the event manifest to register when the drivers is installed, much like the WMI MOF resource gets automagically installed.

Thanks,
Jan