Custom WPP message 'flags' displayed as part of tracing prefix

NTDEV
1

Hi,

I am trying to make use of WPP for tracing a kernel driver.
Unfortunately, the built in macro (DoTraceMessage) for logging
messages is too limited as messages can only be differentiated using
one parameter (TraceFlagName). I have therefore created my own WPP
tracing function RzTraceEx(MODULE, TYPE, LEVEL, MSG, …);. I have
defined appropriate WPP_MODULE_TYPE_LEVEL_LOGGER and
WPP_MODULE_TYPE_LEVEL_ENABLED macros and the function works fine.

Now I wanted to be able to see MODULE, TYPE and LEVEL in formatted
trace messages (e.g. in WinDbg). I wanted to change the prefix, but to
my disappointment it seems that only a small set of tags can be used
in prefixes:

%1 - Module name
%2 - filename LineNumber
%3 - Thread ID
%4 - System Time
%5 - Kernel Time or User Time
%6 - User Time
%7 - Sequence Number
%8 - Process ID
%9 - CPU Number
%!FUNC!
%!LEVEL!
%!FLAGS!
%!COMPNAME!
%!SUBCOMP!

I noticed that in the tmf file for my driver there is an entry for
every message, which contains TYPE, MODULE and LEVEL with which this
message was tagged in the source code:

97f9abc6-5ba0-b797-2120-b9a0f218470b driver // SRC=driver.cpp MJ= MN=
#typev driver_cpp25 11 “%0Leaving %!FUNC!” // MODULE=RZ_DRIVER
TYPE=RZ_FUNC_EXIT LEVEL=RZ_INFO FUNC=EvtDriverUnload
{
}

I hoped that I might get away with using %!MODULE! in the prefix and
since exactly the same word is used in the TMF file the formatted
tracing messages will be displayed with proper module name (e.g
RZ_DRIVER). Unfortunately, this was only wishful thinking and I simply
got !MODULE! in front of every message.

Funnily enough when I tried using %!LEVEL! then I correctly got my
level name (e.g. RZ_INFO) in front of my messages (and not some built
in names of LEVELs).

The question is: What can I do to get my MODULE name and my TYPE name
to be displayed as part of tracing prefix?

Thanks very much in advance,
Rafal

2

Hi Rafal,

I believe there is no generic support from the decoding tools to display custom tags, except for the hardcoded ones like FUNC, LEVEL, COMPNAME…
You could do a hack, and take advantage of the ?spare? tags which you currently don?t use. E.g. MODULE->COMPNAME.

Thanks,
Zoran Dimov

Date: Wed, 10 Nov 2010 12:26:43 +0000
Subject: [ntdev] Custom WPP message ‘flags’ displayed as part of tracing prefix
From: xxxxx@googlemail.com
To: xxxxx@lists.osr.com

Hi,

I am trying to make use of WPP for tracing a kernel driver.
Unfortunately, the built in macro (DoTraceMessage) for logging
messages is too limited as messages can only be differentiated using
one parameter (TraceFlagName). I have therefore created my own WPP
tracing function RzTraceEx(MODULE, TYPE, LEVEL, MSG, …);. I have
defined appropriate WPP_MODULE_TYPE_LEVEL_LOGGER and
WPP_MODULE_TYPE_LEVEL_ENABLED macros and the function works fine.

Now I wanted to be able to see MODULE, TYPE and LEVEL in formatted
trace messages (e.g. in WinDbg). I wanted to change the prefix, but to
my disappointment it seems that only a small set of tags can be used
in prefixes:

%1 - Module name
%2 - filename LineNumber
%3 - Thread ID
%4 - System Time
%5 - Kernel Time or User Time
%6 - User Time
%7 - Sequence Number
%8 - Process ID
%9 - CPU Number
%!FUNC!
%!LEVEL!
%!FLAGS!
%!COMPNAME!
%!SUBCOMP!

I noticed that in the tmf file for my driver there is an entry for
every message, which contains TYPE, MODULE and LEVEL with which this
message was tagged in the source code:

97f9abc6-5ba0-b797-2120-b9a0f218470b driver // SRC=driver.cpp MJ= MN=
#typev driver_cpp25 11 “%0Leaving %!FUNC!” // MODULE=RZ_DRIVER
TYPE=RZ_FUNC_EXIT LEVEL=RZ_INFO FUNC=EvtDriverUnload
{
}

I hoped that I might get away with using %!MODULE! in the prefix and
since exactly the same word is used in the TMF file the formatted
tracing messages will be displayed with proper module name (e.g
RZ_DRIVER). Unfortunately, this was only wishful thinking and I simply
got !MODULE! in front of every message.

Funnily enough when I tried using %!LEVEL! then I correctly got my
level name (e.g. RZ_INFO) in front of my messages (and not some built
in names of LEVELs).

The question is: What can I do to get my MODULE name and my TYPE name
to be displayed as part of tracing prefix?

Thanks very much in advance,
Rafal

NTDEV is sponsored by OSR

For our schedule of WDF, WDM, debugging and other seminars visit:
http://www.osr.com/seminars

To unsubscribe, visit the List Server section of OSR Online at http://www.osronline.com/page.cfm?name=ListServer

3

Hi Zoran,

Thanks very much for the reply. That’s a pity that custom names are
not supported, but your suggestion of hijacking unused tags was great

  • it works marvellously.

Thanks a lot.
Rafal

On 10 November 2010 23:53, Zoran Dimov wrote:
> Hi Rafal,
>
> I believe there is no generic support from the decoding tools to display
> custom tags, except for the hardcoded ones like FUNC, LEVEL, COMPNAME…
> You could do a hack, and take advantage of the ?spare? tags which you
> currently don?t use. E.g. MODULE->COMPNAME.
>
> Thanks,
> Zoran Dimov
>
>
>
>
>> Date: Wed, 10 Nov 2010 12:26:43 +0000
>> Subject: [ntdev] Custom WPP message ‘flags’ displayed as part of tracing
>> prefix
>> From: xxxxx@googlemail.com
>> To: xxxxx@lists.osr.com
>>
>> Hi,
>>
>> I am trying to make use of WPP for tracing a kernel driver.
>> Unfortunately, the built in macro (DoTraceMessage) for logging
>> messages is too limited as messages can only be differentiated using
>> one parameter (TraceFlagName). I have therefore created my own WPP
>> tracing function RzTraceEx(MODULE, TYPE, LEVEL, MSG, …);. I have
>> defined appropriate WPP_MODULE_TYPE_LEVEL_LOGGER and
>> WPP_MODULE_TYPE_LEVEL_ENABLED macros and the function works fine.
>>
>> Now I wanted to be able to see MODULE, TYPE and LEVEL in formatted
>> trace messages (e.g. in WinDbg). I wanted to change the prefix, but to
>> my disappointment it seems that only a small set of tags can be used
>> in prefixes:
>>
>> %1 - Module name
>> %2 - filename LineNumber
>> %3 - Thread ID
>> %4 - System Time
>> %5 - Kernel Time or User Time
>> %6 - User Time
>> %7 - Sequence Number
>> %8 - Process ID
>> %9 - CPU Number
>> %!FUNC!
>> %!LEVEL!
>> %!FLAGS!
>> %!COMPNAME!
>> %!SUBCOMP!
>>
>> I noticed that in the tmf file for my driver there is an entry for
>> every message, which contains TYPE, MODULE and LEVEL with which this
>> message was tagged in the source code:
>>
>> 97f9abc6-5ba0-b797-2120-b9a0f218470b driver // SRC=driver.cpp MJ= MN=
>> #typev driver_cpp25 11 “%0Leaving %!FUNC!” // MODULE=RZ_DRIVER
>> TYPE=RZ_FUNC_EXIT LEVEL=RZ_INFO FUNC=EvtDriverUnload
>> {
>> }
>>
>> I hoped that I might get away with using %!MODULE! in the prefix and
>> since exactly the same word is used in the TMF file the formatted
>> tracing messages will be displayed with proper module name (e.g
>> RZ_DRIVER). Unfortunately, this was only wishful thinking and I simply
>> got !MODULE! in front of every message.
>>
>> Funnily enough when I tried using %!LEVEL! then I correctly got my
>> level name (e.g. RZ_INFO) in front of my messages (and not some built
>> in names of LEVELs).
>>
>> The question is: What can I do to get my MODULE name and my TYPE name
>> to be displayed as part of tracing prefix?
>>
>> Thanks very much in advance,
>> Rafal
>>
>> —
>> NTDEV is sponsored by OSR
>>
>> For our schedule of WDF, WDM, debugging and other seminars visit:
>> http://www.osr.com/seminars
>>
>> To unsubscribe, visit the List Server section of OSR Online at
>> http://www.osronline.com/page.cfm?name=ListServer
>
> —
> NTDEV is sponsored by OSR
>
> For our schedule of WDF, WDM, debugging and other seminars visit:
> http://www.osr.com/seminars
>
> To unsubscribe, visit the List Server section of OSR Online at
> http://www.osronline.com/page.cfm?name=ListServer