Diagnostics with WPP

Industrial-strength tracing

WPP is similar to DbgPrint.  In fact, for NDIS.SYS, WPP and DbgPrint trace exactly the same messages.  However, WPP is easier to enable and works on retail versions of NDIS.SYS.  These advantages mean that WPP can be enabled by customers, without setting up a kernel debugger.  Additionally, because WPP can write directly to a file on disk, it is much faster than DbgPrint.

(Paragraph updated with Windows 8 information).  If you are targeting Windows 8 / Windows Server 2012 or later, you don't need to download any TMF files, as the public symbols for NDIS already include all the TMFs that you'll need.  Just point tracefmt.exe at the public symbol server.  However, if you are targeting Windows 7 or Windows Server 2008 R2, then you need to separately download the TMFs to decode NDIS traces.  Download the Windows 7 TMFs here.

Now that you've got the TMF files, I bet you're anxious to try it out.  Let's give it a shot.  To enable NDIS's WPP tracing, run these commands:

logman create trace ndis -o c:\ndis.etl  -ets
logman update ndis -p {DD7A21E6-A651-46D4-B7C2-66543067B869}  0x88035f3 5  -ets

We'll talk about the different parameters here in just a bit.  For now, let's cause NDIS to do something -- unplug and reinsert your Ethernet cable, so that the miniport sends up a couple status indications.  When you're done, run this command to stop the trace and flush log buffers:

logman stop ndis -ets

This will produce an ETL file (here, we called it C:\NDIS.ETL).  It's an (uncompressed) binary file containing all the trace data.  Before you can render it into readable messages, you'll need to combine it with the TMF files you downloaded above.  You can use TRACEFMT.EXE from the Windows SDK to decode them.  A typical run looks like this:

C:\tracing>tracefmt.exe c:\ndis.etl -p C:\tracing\ndistmf -o ndis.txt
Setting log file to: c:\ndis.etl
Examining C:\tracing\default.tmf for message formats,  none found, file not found
Searching for TMF files on path: C:\tracing\ndistmf
Logfile c:\ndis.etl:
OS version              6.1.7601  (Currently running on 6.1.7601)
Start Time              2011-04-01-00:47:24.949
End Time                Not set (Logger may not have been stopped).
Timezone is             @tzres.dll,-212 (Bias is 480mins)
BufferSize              8192 B
Maximum File Size       0 MB
Buffers  Written        Not set (Logger may not have been stopped).
Logger Mode Settings    (0) Logfile Mode is not set
ProcessorCount          2

Processing completed   Buffers: 2, Events: 116, EventsLost: 0 :: Format Errors: 0, Unknowns: 1

Event traces dumped to C:\tracing\ndis.txt
Event Summary dumped to C:\tracing\ndis.txt.sum

C:\tracing>type ndis.txt
[1]0004.0034::04/01/2011-00:47:37.768 [mp]==>ndisSwapFilterHandlers: Miniport FFFFFA80062E11A0, FakeStatus c023001f, Flags 2
[1]0004.0034::04/01/2011-00:47:37.768 [mp]<==ndisSwapMiniportHandlers: Miniport FFFFFA80062E11A0
[1]0424.0F80::04/01/2011-00:47:38.504 [mp]==>ndisHandleProtocolReconfigNotification: Protocol {4920C418-2EF0-4A77-9C3B-DCADB3D2B32F}
[1]0424.0F80::04/01/2011-00:47:38.504 [mp]==>ndisReferenceProtocolByName: Protocol: {4920C418-2EF0-4A77-9C3B-DCADB3D2B32F}

… etc.  Just unplugging my NIC generated 116 trace events in the log file, so you can get a sense of how detailed these are.

I promised to talk a little bit about the parameters to logman.exe.  Although you can just use the defaults above, sometimes you might want to get a little fancier:

Parameter	What it is	What you can do with it
{DD7A21E6-A651-46D4-B7C2-66543067B869}	The trace provider ID	The DD7A2…869 guid is specific to NDIS. You can always add in more GUIDs. For example, if you're debugging a USB NIC, you might want to use USB's provider too (it's the EF201…955 one in the USB team's handy script).
5	The log level	Select the verbosity of the logs. The various levels are listed on the TMF page.
0x31F3	The log flags	You can select which NDIS subsystem you're interested in. For example, if you are having a problem installing your filter driver, you don't need traces on sent packets, but you probably want traces on registry accesses. The various flags are listed on the TMF page.

 

Finally, one more note.  You may occasionally need to diagnose an issue that occurs early in boot.  You could use the Autologger to set this up.  But there’s an easy backdoor — all you have to do is give your trace session a name that begins with “autosession\”.  When you’re done, you’ll need to delete the session too, so it doesn’t start at the next boot.

logman create trace autosession\ndis -o c:\ndis.etl -ets
logman update autosession\ndis -p {DD7A21E6-A651-46D4-B7C2-66543067B869} 0x88035f3 5 -ets
logman stop ndis -ets
logman delete autosession\ndis -ets

(Note that “logman stop” omits the autosession prefix).

Comments

• Anonymous
  April 23, 2014
  Hi, I just want to thank you for providing this information and of course the necessary TMF files! Very useful! Bye, Sven