Can't get TRACE_LEVEL_VERBOSE WPP trace statements to show up

scott_smith

Here's a pared-down version of my Trace.h file (included by each .cpp file in my UMDF IddCx project). No matter how I set LEVEL in TraceView, WinDbg, etc., I never see VERBOSE logs:

// Trace.h - define 'DEFAULT_TRACE_FLAGS' prior to including this header in your .cpp file, e.g.:
//
// #define DEFAULT_TRACE_FLAGS TraceBaz // Default WPP Trace flag for Trace*() macros/functions in this file
// #include "Trace.h"                   // Instrument for tracing using WPP (Windows Software Trace Preprocessor)
// #include "BazModule.tmh"             // Trace Message Header file (AUTO-GENERATED)

#if !defined(WPP_MACRO_USE_KM_VERSION_FOR_UM)
#  define WPP_MACRO_USE_KM_VERSION_FOR_UM
#endif

//
// Define the tracing flags
//
// Tracing GUID: "ImmersedVirtualDisplayDriver" ==> {7C1B839F-DC1B-4898-B333-55DCFE62943C}
//
#define WPP_CONTROL_GUIDS                                                     \
    WPP_DEFINE_CONTROL_GUID(                                                  \
        ImmersedVirtualDisplayDriver, (7c1b839f,dc1b,4898,b333,55dcfe62943c), \
                                                                              \
        WPP_DEFINE_BIT(TraceFoo)   /* bit 0 = 0x01 */                         \
        WPP_DEFINE_BIT(TraceBar)   /* bit 1 = 0x02 */                         \
        WPP_DEFINE_BIT(TraceBaz)   /* bit 2 = 0x04 */                         \
        WPP_DEFINE_BIT(TraceDummy) /* bit 3 = 0x08 */                         \
    )

#define WPP_LEVEL_FLAGS_ENABLED(LEVEL, FLAGS) \
        (WPP_LEVEL_ENABLED(DEFAULT_TRACE_FLAGS) && WPP_CONTROL(WPP_BIT_ ## DEFAULT_TRACE_FLAGS).Level >= (LEVEL))
#define WPP_LEVEL_FLAGS_LOGGER(LEVEL, FLAGS) WPP_LEVEL_LOGGER(DEFAULT_TRACE_FLAGS)

// begin_wpp config
// USEPREFIX(TraceError,   "%!STDPREFIX!!!  ERROR-");
// FUNC TraceError{LEVEL=TRACE_LEVEL_ERROR, FLAGS=TraceDummy}(MSG, ...);
//
// USEPREFIX(TraceWarning, "%!STDPREFIX!! WARNING-");
// FUNC TraceWarning{LEVEL=TRACE_LEVEL_WARNING, FLAGS=TraceDummy}(MSG, ...);
//
// USEPREFIX(TraceInfo,    "%!STDPREFIX!     INFO-");
// FUNC TraceInfo{LEVEL=TRACE_LEVEL_INFORMATION, FLAGS=TraceDummy}(MSG, ...);
//
// USEPREFIX(TraceVerbose, "%!STDPREFIX!  VERBOSE-");
// FUNC TraceVerbose{LEVEL=TRACE_LEVEL_VERBOSE, FLAGS=TraceDummy}(MSG, ...);
// end_wpp

// begin_wpp config
// USEPREFIX(TraceFuncEntry, "%!STDPREFIX!==>%!FUNC!(");
// FUNC TraceFuncEntry{LEVEL=TRACE_LEVEL_VERBOSE, FLAGS=TraceDummy}();
// USESUFFIX(TraceFuncEntry, ")");
//
// USEPREFIX(TraceFuncExit, "%!STDPREFIX!<==%!FUNC!");
// FUNC TraceFuncExit{LEVEL=TRACE_LEVEL_VERBOSE, FLAGS=TraceDummy}();

The TraceFuncEntry and TraceFuncExit functions/macros don't generate any output (that I can see) unless I replace TRACE_LEVEL_VERBOSE with TRACE_LEVEL_INFORMATION in the header file above.

Scott_Noone_(OSR)

Your WPP_LEVEL_ and WPP_FLAGS_ macros don't look correct (they're always checking DEFAULT_TRACE_FLAGS instead of the flag for the specific message). Try this and see if it helps:

#define WPP_LEVEL_FLAGS_LOGGER(__LEVEL__,__FLAGS__)     \
                WPP_LEVEL_LOGGER(__FLAGS__)

#define WPP_LEVEL_FLAGS_ENABLED(__LEVEL__, __FLAGS__)   \
            (WPP_LEVEL_ENABLED(__FLAGS__) &&            \
                WPP_CONTROL(WPP_BIT_ ## __FLAGS__).Level >= __LEVEL__)

scott_smith

DEFAULT_TRACE_FLAGS is defined before including the Trace.h file:

#define DEFAULT_TRACE_FLAGS TraceBaz // Default WPP Trace flag for Trace*() macros/functions in this file
#include "Trace.h"                   // Instrument for tracing using WPP (Windows Software Trace Preprocessor)
#include "BazModule.tmh"             // Trace Message Header file (AUTO-GENERATED)

I did this so that my TraceXxxxx calls would be neater, and to reduce copy/paste errors; e.g., lower down in BazModule.cpp:

TraceInfo("Blah blah: 0x%p", ptr);

vs.

TraceInfo(TraceBaz, "Blah blah: 0x%p", ptr);

My flags enumerands were all module-specific (FooModule.cpp, BarModule.cpp, BazModule.cpp), so I made the FLAG param part of the macro.

Since the Trace Preprocessor doesn't (appear to) expand preprocessor symbols, I hard-coded those to TraceDummy, and then ignore the FLAGS parameter in the WPP_LEVEL_FLAGS_ENABLED and WPP_LEVEL_FLAGS_LOGGER macros and substituted DEFAULT_TRACE_FLAGS in the definition.

So, given my definition, shouldn't this invocation:

WPP_LEVEL_FLAGS_ENABLED(TRACE_LEVEL_VERBOSE, TraceDummy)

...resolve to this?

(   WPP_LEVEL_ENABLED(TraceBaz)
 && WPP_CONTROL(WPP_BIT_ ## TraceBaz).Level >= TRACE_LEVEL_VERBOSE)

That output looks identical to what you're proposing. What am I'm missing?

scott_smith

DEFAULT_TRACE_FLAGS is defined before including the Trace.h file:

#define DEFAULT_TRACE_FLAGS TraceBaz // Default WPP Trace flag for Trace*() macros/functions in this file
#include "Trace.h"                   // Instrument for tracing using WPP (Windows Software Trace Preprocessor)
#include "BazModule.tmh"             // Trace Message Header file (AUTO-GENERATED)

I did this so that my TraceXxxxx calls would be neater, and to reduce copy/paste errors; e.g., lower down in BazModule.cpp:

TraceInfo("Blah blah: 0x%p", ptr);

vs.

TraceInfo(TraceBaz, "Blah blah: 0x%p", ptr);

My flags enumerands were all module-specific (FooModule.cpp, BarModule.cpp, BazModule.cpp), so I made the FLAGS param part of the macro.

Since the Trace Preprocessor doesn't (appear to) expand preprocessor symbols, I hard-coded those to TraceDummy, and then ignore the FLAGS parameter passed into the WPP_LEVEL_FLAGS_ENABLED and WPP_LEVEL_FLAGS_LOGGER macros and substitute/hard-code DEFAULT_TRACE_FLAGS in the definition.

So, given my original definition, shouldn't this invocation:

WPP_LEVEL_FLAGS_ENABLED(TRACE_LEVEL_VERBOSE, TraceDummy)

...resolve to this?

(   WPP_LEVEL_ENABLED(TraceBaz)
 && WPP_CONTROL(WPP_BIT_ ## TraceBaz).Level >= TRACE_LEVEL_VERBOSE)

That output looks identical to what you're proposing. What am I'm missing?

Scott_Noone_(OSR)

WPP is a strange beast and it runs its own pre-processor over the code before the C pre-processor. Any time you try to incorporate C #defines in your WPP goo things usually don't work out the way you expect (digging through the TMFs should tell you what the actual result is of trying to put your own define in the WPP_LEVEL macros).

I've done a lot of hideous things with WPP but I've never tried to have one trace function that uses different flags based on the module. Maybe someone else has done this and can chime in, otherwise I'd say best bet is to go with the alternatives.