WPP and Traceview with WinDbg

I’ve already posted this on microsoft.public.windbg but got no response, I
wondered if anyone on this list had any ideas:

I’m trying to debug a WPP-enabled driver on a target XP machine using WinDbg
over IEEE 1394. I switched to WPP as the overhead of KdPrint messages over
the 1394 was slowing the driver down too much. The WPP is great and works
fine, I can output massively verbose amounts of trace statements BUT if I
have the WinDbg attached whenever a message is displayed on traceview on the
target I get a message on the WinDbg stating:

Invalid parameter passed to C runtime function.

This is clearly being generated by some library on the Target when the WPP
data is formatted - it happens both “live” from the driver or if I’m viewing
a log file using TraceView. A message is generated for each line when the
traceview window refreshes and it slows the target machine down in the same
way KdPrint messages did. Without WinDbg attached it runs fine but then I
can’t catch any BSOD faults for debugging.

Is there a way to either configure WinDbg to ignore this message or, better
still, stop it being generated?


Graeme Griffiths
Image Processing Techniques Ltd.
+44 1256 345 927
*****************************************************************************
The contents of this Email and any files transmitted with it are confidential
and intended solely for the use of the individual or entity to whom it is
addressed.
The views stated herein do not necessarily represent the view of the company.
If you are not the intended recipient of this Email you may not copy, forward,
disclose or otherwise use it or any part of it in any form whatsoever.
If you have received this mail in error please Email the sender.
*****************************************************************************
Omnitek/Image Processing Techniques Ltd
Tel : +44(0)1256345900
Fax : +44(0)1256345901
Website : www.omnitek.tv
Registered Office : Unit 3, Intec 2, Wade Road, Basingstoke, Hampshire, RG24 8NE
Registration Number : 3564291
Place of Registration : England
VAT Registration : 709198411

Hi ;

I had the same problem looked at it some and did not find any answer. I
think it is a bug in vista , traceview, etc. I just collected the trace info
in traceview. I added a switch to use regular Debug output statement in my
print debug function but as you said traceview is good and I would go that
way except it you need to support windows prior to vista. By the way the
nearest 100th nanosecond timing granularity is great. Note that you need to
do both timing outputs as the 100th nano only gives the significant digits
to be appended to get this timing info.

-Mike Jones

-----Original Message-----
From: xxxxx@lists.osr.com
[mailto:xxxxx@lists.osr.com] On Behalf Of Graeme Griffiths
Sent: Thursday, February 14, 2008 5:08 AM
To: Kernel Debugging Interest List
Subject: [windbg] WPP and Traceview with WinDbg

I’ve already posted this on microsoft.public.windbg but got no response, I
wondered if anyone on this list had any ideas:

I’m trying to debug a WPP-enabled driver on a target XP machine using WinDbg
over IEEE 1394. I switched to WPP as the overhead of KdPrint messages over
the 1394 was slowing the driver down too much. The WPP is great and works
fine, I can output massively verbose amounts of trace statements BUT if I
have the WinDbg attached whenever a message is displayed on traceview on the
target I get a message on the WinDbg stating:

Invalid parameter passed to C runtime function.

This is clearly being generated by some library on the Target when the WPP
data is formatted - it happens both “live” from the driver or if I’m viewing
a log file using TraceView. A message is generated for each line when the
traceview window refreshes and it slows the target machine down in the same
way KdPrint messages did. Without WinDbg attached it runs fine but then I
can’t catch any BSOD faults for debugging.

Is there a way to either configure WinDbg to ignore this message or, better
still, stop it being generated?


Graeme Griffiths
Image Processing Techniques Ltd.
+44 1256 345 927
****************************************************************************
*
The contents of this Email and any files transmitted with it are
confidential
and intended solely for the use of the individual or entity to whom it is
addressed.
The views stated herein do not necessarily represent the view of the
company.
If you are not the intended recipient of this Email you may not copy,
forward,
disclose or otherwise use it or any part of it in any form whatsoever.
If you have received this mail in error please Email the sender.
****************************************************************************
*
Omnitek/Image Processing Techniques Ltd
Tel : +44(0)1256345900
Fax : +44(0)1256345901
Website : www.omnitek.tv
Registered Office : Unit 3, Intec 2, Wade Road, Basingstoke, Hampshire, RG24
8NE
Registration Number : 3564291
Place of Registration : England
VAT Registration : 709198411


You are currently subscribed to windbg as: unknown lmsubst tag argument: ‘’
To unsubscribe send a blank email to xxxxx@lists.osr.com

Thanks Mike,

I’ve seen the question asked before elsewhere with no answer and the only
response I’ve got so far on the MS newsgroup is someone asking if I can post any
answer I find. I’m assuming it’s a bug in one of the libraries used. It’s not
Vista-specific as I’m using XP.

Your comments re. the 100 ns clock are simply annoying, though :slight_smile: I’ve tried
my damndest to get it to work - the 16ms granularity of the system clock is
cave-man-like these days. I have a 4ns clock available on my hardware which I
use to time-stamp important mesages but it would be so much better if I could
get the viewer to use a different clock. The docs say the PerfCounter is
available from XP on but if I use the command

tracelog -start mydriver -guid mydriver.ctl -f log.etl -flags 0xff -level 5
-UsePerfCounter

it notes the clock to be used is PerfCounter but the timestamps are still 16ms
granular. It’s doubly annoying as on a two processor system the two CPUs seem to
batch their trace messages and so they come out-of-sequence. This can be fixed
if I run Traceview on the target as the sequence count is then sensible (it is
pretty-much a random number if I use tracelog and view the results on my host)
but this brings me back to the original problem…

On Thu, 14 Feb 2008 09:01:12 -0500, Mike Jones wrote:

I had the same problem looked at it some and did not find any
answer. I think it is a bug in vista , traceview, etc. I just
collected the trace info in traceview. I added a switch to use
regular Debug output statement in my print debug function but as
you said traceview is good and I would go that way except it you
need to support windows prior to vista. By the way the nearest
100th nanosecond timing granularity is great. Note that you need
to do both timing outputs as the 100th nano only gives the
significant digits to be appended to get this timing info.

-----Original Message-----
From: xxxxx@lists.osr.com
[mailto:xxxxx@lists.osr.com] On Behalf Of Graeme
Griffiths Sent: Thursday, February 14, 2008 5:08 AM To: Kernel
Debugging Interest List Subject: [windbg] WPP and Traceview with
WinDbg

I’ve already posted this on microsoft.public.windbg but got no
response, I wondered if anyone on this list had any ideas:

I’m trying to debug a WPP-enabled driver on a target XP machine
using WinDbg over IEEE 1394. I switched to WPP as the overhead of
KdPrint messages over the 1394 was slowing the driver down too
much. The WPP is great and works fine, I can output massively
verbose amounts of trace statements BUT if I have the WinDbg
attached whenever a message is displayed on traceview on the target
I get a message on the WinDbg stating:

Invalid parameter passed to C runtime function.

This is clearly being generated by some library on the Target when
the WPP data is formatted - it happens both “live” from the driver
or if I’m viewing a log file using TraceView. A message is
generated for each line when the traceview window refreshes and it
slows the target machine down in the same way KdPrint messages did.
Without WinDbg attached it runs fine but then I can’t catch any
BSOD faults for debugging.

Is there a way to either configure WinDbg to ignore this message
or, better still, stop it being generated?


Graeme Griffiths
Image Processing Techniques Ltd.
+44 1256 345 927
*****************************************************************************
The contents of this Email and any files transmitted with it are confidential
and intended solely for the use of the individual or entity to whom it is
addressed.
The views stated herein do not necessarily represent the view of the company.
If you are not the intended recipient of this Email you may not copy, forward,
disclose or otherwise use it or any part of it in any form whatsoever.
If you have received this mail in error please Email the sender.
*****************************************************************************
Omnitek/Image Processing Techniques Ltd
Tel : +44(0)1256345900
Fax : +44(0)1256345901
Website : www.omnitek.tv
Registered Office : Unit 3, Intec 2, Wade Road, Basingstoke, Hampshire, RG24 8NE
Registration Number : 3564291
Place of Registration : England
VAT Registration : 709198411

(1) I used the nearest 100th nanosecond stamping ok on vista. If I recall
correctly it gave the digits from 10-7 on. I know it was not all the
digits. I will be using it soon though as I will need this feature in
developing a kernel streaming driver.

(2) Yes they should be out of sequence. We are using SMP “Symmetric
Multiprocessing Machines”. I would output the processor number with the
trace program. Very important when finding multiprocessor synchronization
bugs.

-Mike Jones

-----Original Message-----
From: xxxxx@lists.osr.com
[mailto:xxxxx@lists.osr.com] On Behalf Of Graeme Griffiths
Sent: Thursday, February 14, 2008 9:11 AM
To: Kernel Debugging Interest List
Subject: RE: [windbg] WPP and Traceview with WinDbg

Thanks Mike,

I’ve seen the question asked before elsewhere with no answer and the only
response I’ve got so far on the MS newsgroup is someone asking if I can post
any
answer I find. I’m assuming it’s a bug in one of the libraries used. It’s
not
Vista-specific as I’m using XP.

Your comments re. the 100 ns clock are simply annoying, though :slight_smile: I’ve
tried
my damndest to get it to work - the 16ms granularity of the system clock is
cave-man-like these days. I have a 4ns clock available on my hardware which
I
use to time-stamp important mesages but it would be so much better if I
could
get the viewer to use a different clock. The docs say the PerfCounter is
available from XP on but if I use the command

tracelog -start mydriver -guid mydriver.ctl -f log.etl -flags 0xff -level 5
-UsePerfCounter

it notes the clock to be used is PerfCounter but the timestamps are still
16ms
granular. It’s doubly annoying as on a two processor system the two CPUs
seem to
batch their trace messages and so they come out-of-sequence. This can be
fixed
if I run Traceview on the target as the sequence count is then sensible (it
is
pretty-much a random number if I use tracelog and view the results on my
host)
but this brings me back to the original problem…

On Thu, 14 Feb 2008 09:01:12 -0500, Mike Jones wrote:

I had the same problem looked at it some and did not find any
answer. I think it is a bug in vista , traceview, etc. I just
collected the trace info in traceview. I added a switch to use
regular Debug output statement in my print debug function but as
you said traceview is good and I would go that way except it you
need to support windows prior to vista. By the way the nearest
100th nanosecond timing granularity is great. Note that you need
to do both timing outputs as the 100th nano only gives the
significant digits to be appended to get this timing info.

-----Original Message-----
From: xxxxx@lists.osr.com
[mailto:xxxxx@lists.osr.com] On Behalf Of Graeme
Griffiths Sent: Thursday, February 14, 2008 5:08 AM To: Kernel
Debugging Interest List Subject: [windbg] WPP and Traceview with
WinDbg

I’ve already posted this on microsoft.public.windbg but got no
response, I wondered if anyone on this list had any ideas:

I’m trying to debug a WPP-enabled driver on a target XP machine
using WinDbg over IEEE 1394. I switched to WPP as the overhead of
KdPrint messages over the 1394 was slowing the driver down too
much. The WPP is great and works fine, I can output massively
verbose amounts of trace statements BUT if I have the WinDbg
attached whenever a message is displayed on traceview on the target
I get a message on the WinDbg stating:

Invalid parameter passed to C runtime function.

This is clearly being generated by some library on the Target when
the WPP data is formatted - it happens both “live” from the driver
or if I’m viewing a log file using TraceView. A message is
generated for each line when the traceview window refreshes and it
slows the target machine down in the same way KdPrint messages did.
Without WinDbg attached it runs fine but then I can’t catch any
BSOD faults for debugging.

Is there a way to either configure WinDbg to ignore this message
or, better still, stop it being generated?


Graeme Griffiths
Image Processing Techniques Ltd.
+44 1256 345 927
****************************************************************************
*
The contents of this Email and any files transmitted with it are
confidential
and intended solely for the use of the individual or entity to whom it is
addressed.
The views stated herein do not necessarily represent the view of the
company.
If you are not the intended recipient of this Email you may not copy,
forward,
disclose or otherwise use it or any part of it in any form whatsoever.
If you have received this mail in error please Email the sender.
****************************************************************************
*
Omnitek/Image Processing Techniques Ltd
Tel : +44(0)1256345900
Fax : +44(0)1256345901
Website : www.omnitek.tv
Registered Office : Unit 3, Intec 2, Wade Road, Basingstoke, Hampshire, RG24
8NE
Registration Number : 3564291
Place of Registration : England
VAT Registration : 709198411


You are currently subscribed to windbg as: unknown lmsubst tag argument: ‘’
To unsubscribe send a blank email to xxxxx@lists.osr.com

Mike Jones wrote:

(1) I used the nearest 100th nanosecond stamping ok on vista. If I recall
correctly it gave the digits from 10-7 on. I know it was not all the
digits.

What do you mean by that? System time is in 100 nanosecond units, which
is 10^-7 – a tenth of a microsecond. The timing is NOT in “100ths of a
nanosecond”, which would be 10^-11.

I will be using it soon though as I will need this feature in
developing a kernel streaming driver.

There is simply no way to do accurate timing at the sub-microsecond
level in Windows. It’s just not possible. You’re either using the tick
counter, which bumps at the multi-millisecond level, or you use the
performance counter/cycle counter, which has multiprocessor issues.

Fortunately, kernel streaming drivers don’t really need accurate
sub-microsecond timing.


Tim Roberts, xxxxx@probo.com
Providenza & Boekelheide, Inc.

(1) Thanks sorry a topo I meant to say the nearest 100 nanoseconds which is
10^-7 sec. We where talking about using the trace facilities in Windows
(WPP) to time stamp the log files.

(2)> You’re either using the tick counter, which bumps at the
multi-millisecond level, or you use the

performance counter/cycle counter, which has multiprocessor issues.

We will be using WPP and its tracing facilities. Come to think of it I was
using a single processor machine.

“Tim Roberts” wrote in message news:xxxxx@windbg…
> Mike Jones wrote:
>> (1) I used the nearest 100th nanosecond stamping ok on vista. If I recall
>> correctly it gave the digits from 10-7 on. I know it was not all the
>> digits.
>
> What do you mean by that? System time is in 100 nanosecond units, which
> is 10^-7 – a tenth of a microsecond. The timing is NOT in “100ths of a
> nanosecond”, which would be 10^-11.
>
>> I will be using it soon though as I will need this feature in
>> developing a kernel streaming driver.
>>
>
> There is simply no way to do accurate timing at the sub-microsecond level
> in Windows. It’s just not possible. You’re either using the tick
> counter, which bumps at the multi-millisecond level, or you use the
> performance counter/cycle counter, which has multiprocessor issues.
>
> Fortunately, kernel streaming drivers don’t really need accurate
> sub-microsecond timing.
>
> –
> Tim Roberts, xxxxx@probo.com
> Providenza & Boekelheide, Inc.
>
>

Sorry about that I setup my account to have “OSR News Group” for a name.
Anyway I changed to my name “William Michael Jones”. Such is tangential
thinking. It can only get better.

-William Michael Jones

“OSR news groups” wrote in message
news:xxxxx@windbg…
> (1) Thanks sorry a topo I meant to say the nearest 100 nanoseconds which
> is 10^-7 sec. We where talking about using the trace facilities in Windows
> (WPP) to time stamp the log files.
>
>
>
> (2)> You’re either using the tick counter, which bumps at the
> multi-millisecond level, or you use the
>
> > performance counter/cycle counter, which has multiprocessor issues.
>
>
>
> We will be using WPP and its tracing facilities. Come to think of it I was
> using a single processor machine.
>
>
>
>
>
> “Tim Roberts” wrote in message news:xxxxx@windbg…
>> Mike Jones wrote:
>>> (1) I used the nearest 100th nanosecond stamping ok on vista. If I
>>> recall
>>> correctly it gave the digits from 10-7 on. I know it was not all the
>>> digits.
>>
>> What do you mean by that? System time is in 100 nanosecond units, which
>> is 10^-7 – a tenth of a microsecond. The timing is NOT in “100ths of a
>> nanosecond”, which would be 10^-11.
>>
>>> I will be using it soon though as I will need this feature in
>>> developing a kernel streaming driver.
>>>
>>
>> There is simply no way to do accurate timing at the sub-microsecond level
>> in Windows. It’s just not possible. You’re either using the tick
>> counter, which bumps at the multi-millisecond level, or you use the
>> performance counter/cycle counter, which has multiprocessor issues.
>>
>> Fortunately, kernel streaming drivers don’t really need accurate
>> sub-microsecond timing.
>>
>> –
>> Tim Roberts, xxxxx@probo.com
>> Providenza & Boekelheide, Inc.
>>
>>
>
>