Driver Dev Guide: WPP Tracing in your WPD Driver

WPP Software Tracing is the recommended way to log trace and error messages in your WPD driver.  WPP, short for Windows Software Trace PreProcessor, provides an efficient real-time event logging mechanism.    In addition, WPP traces include the system timestamp and can be used as a way to measure performance, for example by calculating the elapsed time between function calls. 

 

From OutputDebugString to WPP

The WPD sample drivers in the Windows Driver Kit (WDK) log error messages using a CHECK_HR function that wraps around OutputDebugString.   While OutputDebugString is simple to use during development, it necessitates an active debugger connection in order to view the traces, and should be used minimally in shipping code.   WPP tracing is much more lightweight, flexible, and preferable for a range of tracing applications: logging errors for diagnosing failures, tracing code execution during development, to name a few.    

How to switch your WPD driver's tracing from OutputDebugString to WPP transparently:

Step 1. Remove the original CHECK_HR() function definition (it can be found in WpdHelloWorldDriver.cpp or WpdWudfSampleDriver.cpp for the WPD samples) and its declaration in stdafx.h.  

 

Step 2. Add the following code (include the WPP config comment blocks) to stdafx.h:

 // TODO: Choose a different trace ID for your WPD driver
#define MYDRIVER_TRACING_ID      L"Microsoft\\WPD\\MyWpdDriver"

// TODO: Choose a different trace control GUID for your WPD driver
// TODO: Define trace flag bits for your WPD driver

#define WPP_CONTROL_GUIDS                                                   \
    WPP_DEFINE_CONTROL_GUID(                                                \
        MyWpdDriverCtrlGuid, (da5fbdfd,1eae,4ecf,b426,a3818f325ddb),        \
                                                                            \
        WPP_DEFINE_BIT(TRACE_FLAG_ALL)                                      \
        WPP_DEFINE_BIT(TRACE_FLAG_DRIVER)                                   \
        WPP_DEFINE_BIT(TRACE_FLAG_DEVICE)                                   \
        )                             

//
// Prefer trace statement that is based on
//     - the standard trace LEVEL (evntrace.h), and
//     - specific flag bit.
//
#define WPP_LEVEL_FLAGS_LOGGER(lvl,flags) \
           WPP_LEVEL_LOGGER(flags)
               
#define WPP_LEVEL_FLAGS_ENABLED(lvl, flags) \
           (WPP_LEVEL_ENABLED(flags) && WPP_CONTROL(WPP_BIT_ ## flags).Level >= lvl)

//
// This comment block is scanned by the trace preprocessor to define our
// Trace and TraceEvents function.
//
// begin_wpp config
// FUNC Trace{FLAG=TRACE_FLAG_ALL}(LEVEL, MSG, ...);
// FUNC TraceEvents(LEVEL, FLAGS, MSG, ...);
// end_wpp
//

// MACRO: CHECK_HR
// Configuration block that defines trace macro. It uses the PRE/POST macros to include
// code as part of the trace macro expansion. CHECK_HR is equivalent to the code below:
//
// {if (hrCheck != S_OK){  // This is the code in the PRE macro
//     DoTraceMessage(TRACE_FLAG_ALL,  "%!STDPREFIX!" MSG " hr= %!HRESULT!", ..., hrCheck)
// ;}}                              // This is the code in the POST macro
//                                 

// begin_wpp config
// USEPREFIX (CHECK_HR,"%!STDPREFIX!");
// FUNC CHECK_HR{FLAG=TRACE_FLAG_ALL}(hrCheck, MSG, ...);
// USESUFFIX (CHECK_HR, " hr= %!HRESULT!", hrCheck);
// end_wpp

#define WPP_FLAG_hrCheck_PRE(FLAGS, hrCheck) {if(hrCheck != S_OK) {
#define WPP_FLAG_hrCheck_POST(FLAGS, hrCheck) ; } }
#define WPP_FLAG_hrCheck_ENABLED(FLAGS, hrCheck) WPP_FLAG_ENABLED(FLAGS)
#define WPP_FLAG_hrCheck_LOGGER(FLAGS, hrCheck) WPP_FLAG_LOGGER(FLAGS)

 

Step 3. Add a RUN_WPP directive to your sources file:

 RUN_WPP= $(SOURCES) -scan:stdafx.h

 

Step 4. Add the WPP initialization and cleanup routines to DllMain:

 // DLL Entry Point
extern "C" BOOL WINAPI DllMain(HINSTANCE hInstance, DWORD dwReason, LPVOID lpReserved)
{
    if(DLL_PROCESS_ATTACH == dwReason)
    {
        g_hInstance = hInstance;
      
         //<br>        // Initialize tracing.<br>        //<br>        WPP_INIT_TRACING(MYDRIVER_TRACING_ID); 
    }
    else if (DLL_PROCESS_DETACH == dwReason)
    {
         //<br>        // Cleanup tracing.<br>        //<br>        WPP_CLEANUP(); 
    }

    return _AtlModule.DllMain(dwReason, lpReserved);
}

Step 5. For each .cpp file, add a #include <filename>.tmh after the regular includes:

 //
// WpdBaseDriver.cpp
//

#include "stdafx.h"
#include "WpdBaseDriver.h"

 // Include the WPP generated Trace Message Header (tmh) file for this .cpp<br>#include "WpdBaseDriver.tmh" 

...

Repeat Step 5 for all other .CPP files. 

 

Step 6. Rebuild your driver.  Since we replaced the CHECK_HR function with an equivalent WPP macro that has the same signature (our WPP changes were "under the hood"), no changes are needed for any code that uses CHECK_HR.   You can continue to use CHECK_HR the same way as before :).

The WPP preprocessor will process stdafx.h for tracing macros, and generate a Trace Message Header (tmh) file for each cpp file in the obj folders.  

Inspecting the preprocessor output for each .CPP file that calls CHECK_HR (generated using make WpdBaseDriver.pp), you will notice that all CHECK_HR trace statements have been wrapped by WPP function calls, while the tracing text and WPP functions are defined in WpdBaseDriver.tmh.

The most common WPP-related compilation errors you may encounter are due to mismatched format identifiers and parameters  (e.g. if your format string contains an extra %d that does not match an argument) or missing entries in the WPP_CONTROL_GUIDS macro.

 

More WPP Tracing Macros

We've also defined TraceEvents and Trace functions in stdafx.h that are general purpose WPP trace macros wrapping DoTraceMessage.   These can be used for both error and non-error trace logging using a combination of levels and flags.   For examples on how to use them in your driver, refer to the UMDF sample drivers in the WDK.

To understand the WPP declarations used in stdafx.h, customize the CHECK_HR macro, or to define your own tracing macros, visit the WPP macros guide which describes the WDK tracedrv sample in detail.

 

Generating and Viewing Traces

To generate traces, you can use Traceview  (UI) or Tracelog (command line).   TraceView also allows you to view traces in real-time as they are logged. These are available in the WDK.   A quick way to get started is to create a new log session from Traceview using the PDB file that contains the private symbols for your driver.   Alternatively, you use a .CTL file that specifies your driver as a trace provider (replace own values below):

 da5fbdfd-1eae-4ecf-b426-a3818f325ddb    MyWpdDriverCtlGuid

 

Converting Binary Traces to A Human-Readable Form

WPP traces log to a binary ETL format.  To convert them to text, supply Trace Format (TMF and TMC) files that can be generated from the .PDB file using TracePDB.  For more details, refer to the tracing tools section in the MSDN docs.

 

This posting is provided "AS IS" with no warranties, and confers no rights.