To instrument a driver for software tracing, you must:
Modify the Sources file to run the WPP preprocessor.
Include TMH files.
Define the control GUID and message trace flags.
Add macros to initialize and clean up tracing.
Instrument the driver code to generate trace messages at appropriate points.
This section examines the mechanics of implementing WPP software tracing in a WDF driver. Both UMDF and KMDF drivers require essentially the same procedures, although some of the WPP macros are defined differently for user mode than for kernel mode.
WPP is integrated into the WDK build environment, but you must explicitly instruct the WDK build utility to run the WPP preprocessor. To do so, add a RUN_WPP directive to the end of the driver's Sources file. This directive is also used to specify custom trace message functions. RUN_WPP has the following form:
RUN_WPP= $(SOURCES) Option1 Option2…
The options you use depend on whether you're building a UMDF or a KMDF driver and how you have implemented tracing in your driver. Table 11-1 summarizes the RUN_WPP options that are most useful for KMDF and UMDF drivers.
Option | Description |
---|---|
-km | Required for KMDF drivers. By default, only user-mode components are traced. This option defines the WPP_KERNEL_MODE macro, which traces kernel-mode components. |
-func:funcname (param1, param2, …) | Optional. Defines a custom trace function. You can repeat this argument if you have more than one such function. |
-scan:filename | Optional. Scans filename to find the definition of a custom trace function. The format for the definition is given in the next section. |
-dll | Required for UMDF drivers; not used for KMDF drivers. Defines the WPP_DLL macro, which causes the WPP data structures to be initialized whenever WPP_INIT_TRACING is called. Otherwise, the structures are initialized only once. |
-gen:{filename.tpl}*.tmh | Optional. Instructs the WPP preprocessor to create a TMH file from a template named filename.tpl. This template is used only by KMDF drivers. |
Tip | The func and scan options are used only for projects that have one or more custom trace message functions. If you use only DoTraceMessage to generate trace messages, omit these options. If you define a custom trace message function, -func and -scan are optional only to the extent that you must use one or the other to provide WPP with the function prototype. |
The following two sections show how RUN_WPP is configured in the Fx2_Driver and Osrusbfx2 samples.
Tip See "WPP Software Tracing" in the WDK for more details about RUN_WPP options-online at http://go.microsoft.com/fwlink/?LinkId=80090.
The following example shows the RUN_WPP directive from the Fx2_Driver sample's Sources file:
RUN_WPP= $(SOURCES) -dll -scan:internal.h
Because this is a UMDF driver, the -dll option must be set. Fx2_Driver defines its custom trace message functions in Internal.h. RUN_WPP uses the -scan option to direct the WPP preprocessor to Internal.h for the function definitions, which are shown in the following example.
Custom Trace Message Function Definitions for Fx2_Driver
// begin_wpp config // FUNC Trace{FLAG=MYDRIVER_ALL_INFO}(LEVEL, MSG, ...); // FUNC TraceEvents(LEVEL, FLAGS, MSG, ...); // end_wpp
Custom trace message definitions have the following characteristics:
All elements of the definition are commented, to prevent the compiler from trying to parse them.
The definition begins with begin_wpp config and ends with end_wpp statements.
Each function definition is preceded by a FUNC keyword, followed by the function name.
The function name is followed by a definition of the input parameters.
Tip See "Can I customize DoTraceMessage?" in the WDK for details about the format of trace message definitions-online at http://go.microsoft.com/fwlink/?LinkId=80061.
Fx2_Driver defines a custom trace message function, TraceEvents, which supports the following conditions:
Condition | Description |
---|---|
LEVEL | Takes the standard trace levels. |
FLAGS | Has four user-defined values that indicate which driver component generated the message. |
The FLAG values are defined in the WPP_CONTROL_GUIDS macro, as discussed in "Define the Control GUID and Trace Flags" later in this chapter.
When you define a custom trace message function, you must also define custom versions of the following WPP macros:
Macro | Description |
---|---|
WPP_LEVEL_LOGGER | Determines which session enabled the driver as a provider and returns the session handle. |
WPP_LEVEL_ENABLED | Determines whether logging is enabled for a particular flag value. |
The custom versions of these macros must have their names in a standard format that includes the conditions that the custom trace message function supports. The general form of the macro names are as follows:
Macro name format | Description |
---|---|
WPP_CONDITIONS_ENABLED | Replaces WPP_LEVEL_ENABLED. |
WPP_CONDITIONS_LOGGER | Replaces WPP_LEVEL_LOGGER. |
CONDITIONS is a list of the conditions that the function supports in the order in which they appear in the function's parameter list, separated by underscore characters. For example, in a custom trace message function that supports LEVEL and FLAGS conditions, the custom version of WPP_LEVEL_ENABLED must be named WPP_LEVEL_FLAGS_ENABLED.
You typically define custom versions of these macros in terms of the default versions. For most drivers, you must provide a substantive definition only for WPP_CONDITIONS_ENABLED. You can usually just set WPP_CONDITIONS_LOGGER to WPP_LEVEL_LOGGER.
The Internal.h header file defines the macros for TraceEvents as shown in Listing 11-1.
Listing 11-1: WPP macros for Fx2_Driver
#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)
The macros define the order of the TraceEvents parameters as LEVEL, followed by FLAGs. The definitions are as follows:
Macro | Description |
---|---|
WPP_LEVEL_FLAGS_LOGGER | Is identical to WPP_LEVEL_LOGGER. |
WPP_LEVEL_FLAGS_ENABLED | Returns TRUE if logging is enabled for the specified FLAG value and the enabled LEVEL value is greater than the level argument. |
The Osrusbfx2 sample also uses the custom TraceEvents trace message function. The message is discussed in detail in "Fx2_Driver Custom Trace Message" earlier in this chapter. The following example shows the RUN_WPP directive from the Osrusbfx2 sample's Sources file.
RUN_WPP for Osrusbfx2
RUN_WPP= $(SOURCES) \ -km \ -func:TraceEvents(LEVEL,FLAGS,MSG,...) \
This example uses a continuation character ("\") to break the directive across several lines. The directive includes two options:
Option | Description |
---|---|
-km | Indicates that the driver runs in kernel mode. |
-func | Specifies one custom trace message function-TraceEvents-that supports LEVEL and FLAGS conditions. |
Tip | The Osrusbfx2 source code also includes a definition of TraceEvents in the Trace.h header file. Tracing is enabled for Osrusbfx2 only if EVENT_TRACING is defined as TRUE. The TraceEvents definition is in a block of code that is conditionally compiled only when EVENT_TRACING is not set to TRUE. The purpose is to provide a default definition for the TraceEvents function when tracing is not enabled and the WPP preprocessor does not produce a TraceEvents function. |
The Sources file also defines custom versions of WPP_LEVEL_LOGGER and WPP_LEVEL_ENABLED, as discussed earlier.
Every source file that contains WPP macros must include a corresponding TMH file. That file contains the code that the WPP preprocessor generates and must be compiled with the associated source file. The TMH file must have the same name as the corresponding source file, with a .tmh file name extension. For example, the TMH file for Driver.c is Driver.tmh and the #include directive is as follows:
#include driver.tmh
The TMH file must be included after the WPP_CONTROL_GUIDS macro and before any other WPP macro calls.
In the Fx2_Driver sample, the WPP_CONTROL_GUIDS macro is in Internal.h. To ensure that WPP_CONTROL_GUIDS comes first, the source files include Internal.h before the TMH file. For example, ReadWriteQueue.cpp includes the files as follows.
Including a TMH File for ReadWriteQueue.cpp from Fx2_Driver
#include "internal.h" #include "ReadWriteQueue.tmh"
The Osrusbfx2 driver defines the control GUID and trace flags in the Trace.h file, which in turn is included in the Osrusbfx2.h header file. Consequently, the source files for this driver include Osrusbfx2.h before the TMH file, as Interrupt.c does in the following example.
Including a TMH File for Interrupt.c from Osrusbfx2
#include <osrusbfx2.h> #if defined(EVENT_TRACING) #include "interrupt.tmh" #endif
The KMDF sample includes the TMH file only if event tracing is included. The sample defines the EVENT_TRACING environment variable in the Sources file along with the ENABLE_EVENT_TRACING variable. When ENABLE_EVENT_TRACING is defined, the Sources file also defines EVENT_TRACING and includes the RUN_WPP directive, which invokes the WPP preprocessor. This technique allows you to include or exclude WPP tracing at build time.
Each trace message provider must have a control GUID that trace controllers use to identify the driver as a trace message provider. Typically, each driver has a separate control GUID. However, a one-to-one relationship between control GUID and driver is not a requirement because:
A driver can have multiple control GUIDs.
Each GUID must identify a unique trace message provider, but a driver can be broken into multiple providers, each with its own GUID. For example, if a driver has a shared library, the driver could define two control GUIDS: one for the driver and one for the library. However, each provider must define its own set of flags. The trace consumer could then choose to enable either or both as trace message providers for the session.
Multiple drivers can use the same control GUID, and different drivers can be user mode or kernel mode.
All components that use the same GUID operate as a single provider. If the provider is enabled, the trace messages from every component are interleaved in the trace log in the order in which they are generated. This approach can be useful for handling drivers that interact during execution, such as a function driver and a related filter driver or a hybrid driver with both UMDF and KMDF components.
Tip | Use the UuidGen tool from the Platform SDK to generate a new control GUID specifically for that purpose. Do not copy the examples in this book or use one generated for another purpose such as identifying a device interface. See "Using UUIDGEN.EXE" in the MSDN library-online at http://go.microsoft.com/fwlink/?LinkId=79587. |
Trace flags are used to define different classes of messages. Each driver can define its own set of trace flags by using the WPP_DEFINE_CONTROL_GUID macro. A particular trace message function call generates a trace message only if a trace controller has enabled the specified trace flag. To specify the control GUID and trace flags, you must define a WPP_CONTROL_GUIDS macro for each source file that generates trace messages, typically in a common header file. Each flag must have a name and a value that specifies the bit with which the flag is associated. The general form of the macro definition is shown in Listing 11-2.
Listing 11-2: Macro definition format for WPP_CONTROL_GUIDS
#define WPP_CONTROL_GUIDS \ WPP_DEFINE_CONTROL_GUID(CtlGuid, \ (aaaaaaaa, bbbb, cccc, dddd, eeeeeeeeeeee), \ WPP_DEFINE_BIT(TRACELEVELONE) \ WPP_DEFINE_BIT(TRACELEVELTWO) )
The meanings of the different components of the definition are as follows:
CtlGuid is a friendly name for the GUID.
(aaaaaaaa, bbbb, cccc, dddd, eeeeeeeeeeee) represent the control GUID itself.
The letters represent the five fields of the standard string form of a GUID, but they are separated by commas instead of hyphens and bracketed by parentheses rather than curly braces.
TRACELEVELONE and TRACELEVELTWO are trace flags.
WPP assigns a bit value to each trace flag in the order in which they appear in the WPP_CONTROL_GUIDS definition, beginning with 1.
The Fx2_Driver sample has a single control GUID and four trace flags that are defined in the Internal.h header file as shown in the following example.
WPP_DEFINE_CONTROL_GUID for Fx2_Driver
#define WPP_CONTROL_GUIDS \ WPP_DEFINE_CONTROL_GUID(WudfOsrUsbFx2TraceGuid, \ (da5fbdfd,1eae,4ecf,b426,a3818f325ddb), \ WPP_DEFINE_BIT(MYDRIVER_ALL_INFO) \ WPP_DEFINE_BIT(TEST_TRACE_DRIVER) \ WPP_DEFINE_BIT(TEST_TRACE_DEVICE) \ WPP_DEFINE_BIT(TEST_TRACE_QUEUE) \ )
In this example:
WudfOsrUsbFx2TraceGuid is the friendly name for the {} GUID.
The WPP_DEFINE_BIT macros specify four flags that the TraceEvents function's FLAG parameter uses.
These flags are used to distinguish between messages that are generated by the driver object, the device object, the queue objects, and all other driver components.
The function's LEVEL parameter is automatically mapped to the standard trace levels.
The Osrusbfx2 driver sample has a single control GUID and seven trace flags. They are defined in the Trace.h header file, as shown in the following example.
WPP_DEFINE_CONTROL_GUID for Osrusbfx2
#define WPP_CONTROL_GUIDS \ WPP_DEFINE_CONTROL_GUID(OsrUsbFxTraceGuid, \ (d23a0c5a,d307,4f0e,ae8e,E2A355AD5DAB), \ WPP_DEFINE_BIT(DBG_INIT) /* bit 0 = 0x00000001 */ \ WPP_DEFINE_BIT(DBG_PNP) /* bit 1 = 0x00000002 */ \ WPP_DEFINE_BIT(DBG_POWER) /* bit 2 = 0x00000004 */ \ WPP_DEFINE_BIT(DBG_WMI) /* bit 3 = 0x00000008 */ \ WPP_DEFINE_BIT(DBG_CREATE_CLOSE) /* bit 4 = 0x00000010 */ \ WPP_DEFINE_BIT(DBG_IOCTL) /* bit 5 = 0x00000020 */ \ WPP_DEFINE_BIT(DBG_WRITE) /* bit 6 = 0x00000040 */ \ WPP_DEFINE_BIT(DBG_READ) /* bit 7 = 0x00000080 */ \ )
In this example:
OsrUsbFxTraceGuid is the friendly name for the {} GUID.
The trace flags are used to differentiate between trace messages that are generated when handling different types of I/O requests.
You must initialize tracing early in the driver loading process and deactivate it just before the driver shuts down.
The WPP_INIT_TRACING macro initializes tracing and must be called early in the loading process, before any trace messages are generated. WPP_INIT_TRACING is defined differently for user-mode and kernel-mode drivers and takes different arguments.
A UMDF driver should initialize tracing in its DllMain function by calling WPP_INIT_TRACING when the function is first called. In that case, the function's Reason parameter is set to DLL_PROCESS_ATTACH.
Important | Be sure to verify that the Reason parameter is set to DLL_PROCESS_ATTACH before enabling tracing. Otherwise, you could be attempting to enable tracing every time a thread is attached or detached. |
For user-mode drivers, WPP_INIT_TRACING has a single argument: a pointer to a UNICODE string that identifies the driver. In the Fx2_Driver sample, the string is defined in Internal.h as shown in the following example.
Definition of MYDRIVER_TRACING_ID
#define MYDRIVER_TRACING_ID L"Microsoft\\UMDF\\OsrUsb"
The constant makes it possible to copy the Dllsup.cpp file and use it without change in another driver. However, you should redefine MYDRIVER_TRACING_ID to use an appropriate string for your driver.
DllMain uses MYDRIVER_TRACING_ID when it initializes tracing. The following example shows an edited version of the Fx2_Driver sample's DllMain implementation, from Dllsup.cpp.
Initializing WPP Tracing in DllMain
BOOL WINAPI DllMain(HINSTANCE ModuleHandle, DWORD Reason, PVOID /* Reserved */) { UNREFERENCED_PARAMETER(ModuleHandle); if (DLL_PROCESS_ATTACH == Reason) { WPP_INIT_TRACING(MYDRIVER_TRACING_ID); } ... return TRUE; }
A KMDF driver should initialize tracing in its DriverEntry routine. For kernel-mode drivers, WPP_INIT_TRACING takes two arguments: a pointer to the WDM driver object and the registry path, both of which are passed in as parameters to DriverEntry.
Note In general, the procedures for initializing and cleaning up WPP tracing are different for Windows 2000 than for later versions of Windows. KMDF handles these differences internally, so you can use the following examples on any version of Windows that supports KMDF.
The following example shows the first few lines of the Osrusbfx2 sample's DriverEntry routine, from Device.c.
Initializing WPP Tracing in DriverEntry
NTSTATUS DriverEntry(__in PDRIVER_OBJECT DriverObject, __in PUNICODE_STRING RegistryPath) { WDF_DRIVER_CONFIG config; NTSTATUS status; WDF_OBJECT_ATTRIBUTES attributes; WPP_INIT_TRACING( DriverObject, RegistryPath ); TraceEvents(TRACE_LEVEL_INFORMATION, DBG_INIT, "OSRUSBFX2 Driver Sample - Driver Framework Edition.\n"); ... }
Drivers must call the WPP_CLEANUP macro to deactivate software tracing. The driver cannot generate trace messages after this macro is called, so it should be called just before the driver unloads.
Important | If you fail to call WPP_CLEANUP, you leave an outstanding reference on the driver object. This reference causes subsequent attempts to load the driver to fail-which requires users to reboot their system-or generates a bug check when ETW attempts to reference the driver. Be aware that Build.exe does not generate a compiler error if you do not call WPP_CLEANUP. |
The UMDF version of WPP_CLEANUP takes no arguments. The macro is usually called in a UMDF driver's DllMain function, which is called when the driver is unloaded as well as when it is loaded. When the driver is being unloaded, the Reason parameter is set to DLL_PROCESS_DETACH. The following example shows an edited version of the Fx2_Driver sample's DllMain implementation, from Dllsup.cpp.
Cleaning Up WPP Tracing in DllMain
BOOL WINAPI DllMain(HINSTANCE ModuleHandle, DWORD Reason, PVOID /* Reserved */) { UNREFERENCED_PARAMETER(ModuleHandle); ... else if (DLL_PROCESS_DETACH == Reason) { WPP_CLEANUP(); } return TRUE; }
A KMDF driver should register an EvtCleanupCallback function for the WDFDRIVER object in its DriverEntry routine and call WPP_CLEANUP from that function. The framework invokes EvtCleanupCallback immediately before it deletes the driver object, and thus immediately before it unloads the driver.
Because the framework calls EvtCleanupCallback only if the driver object is successfully created, you should initialize WPP only after you have successfully created the driver object. That way, if the driver object is not successfully created, WPP is not initialized and cleanup is not required. If the driver object is created, the framework is guaranteed to call EvtCleanupCallback, which runs the cleanup code.
The kernel-mode version of WPP_CLEANUP requires one argument that is a pointer to the WDM driver object. The following example shows the Osrusbfx2 sample's EvtCleanupCallback implementation from Device.c.
Cleaning Up WPP Tracing in EvtCleanupCallback
VOID OsrFxEvtDriverContextCleanup( IN WDFDRIVER Driver ) { PAGED_CODE (); TraceEvents(TRACE_LEVEL_INFORMATION, DBG_INIT, "<-- OsrFxEvtDriverUnload\n"); WPP_CLEANUP( WdfDriverWdmGetDriverObject( Driver )); }
EvtCleanupCallback receives a pointer to the driver's WDF driver object. To get a pointer to the underlying WDM driver object, the sample passes a WDF object handle to WdfDriver-WdmGetDriverObject, which returns a pointer to the underlying WDM driver object.
Tip | Cleaning up tracing in EvtCleanupCallback is sufficient for most scenarios, but not all. If the driver fails to create a WDF driver object in its DriverEntry routine, the framework has no driver object to delete and does not invoke EvtCleanupCallback. To ensure that tracing is cleaned up in this case, a KMDF driver must include a WPP_CLEANUP call when the driver handles the failure to create a driver object. |
The following example shows how the Osrusbfx2 DriverEntry routine registers the EvtCleanupCallback and cleans up tracing if a driver object is not successfully created.
Cleaning up WPP Tracing in DriverEntry
NTSTATUS DriverEntry( IN PDRIVER_OBJECT DriverObject, IN PUNICODE_STRING RegistryPath ) { ... attributes.EvtCleanupCallback = OsrFxEvtDriverContextCleanup; status = WdfDriverCreate( DriverObject, RegistryPath, &attributes, &config, &driver ); if (!NT_SUCCESS(status)) { TraceEvents(TRACE_LEVEL_ERROR, DBG_INIT, "WdfDriverCreate failed with status 0x%X\n", status); WPP_CLEANUP(DriverObject); return status; }
Trace message calls in the driver code generate the trace messages that the trace consumer views. The messages can be placed anywhere that they are useful. Typical locations are at the beginning of routines or in error paths.
The following example from Dllsup.cpp shows the use of a custom trace function-Trace-to return information about an error condition.
Adding a Trace Message to Fx2_Driver
if (IsEqualCLSID(ClassId, CLSID_MyDriverCoClass) == false) { Trace( TRACE_LEVEL_ERROR, L"ERROR: Called to create instance of unrecognized class" "(%!GUID!)", &ClassId ); return CLASS_E_CLASSNOTAVAILABLE; }
This Trace call generates a trace message only if the consumer has enabled the TRACE_LEVEL_ERROR flag.
The following example shows how the Osrusbfx2 driver uses its TraceEvents function in a portion of the code devoted to handling read requests.
Adding a Trace Message to Osrusbfx2
if (Length > TEST_BOARD_TRANSFER_BUFFER_SIZE) { TraceEvents(TRACE_LEVEL_ERROR, DBG_READ, "Transfer exceeds %d\n", TEST_BOARD_TRANSFER_BUFFER_SIZE); status = STATUS_INVALID_PARAMETER; }
The call to TraceEvents generates a trace message if the TRACE_LEVEL_ERROR flag is enabled and the DBG_READ bit is set. The message includes the value of the constant TEST_BOARD_TRANSFER_BUFFER_SIZE.