Wednesday, November 2, 2011

tracelog troubles fixed!

I had to do some tracelog stuff at work and it took me a couple of days to figure out how to enable tracelog for drivers at boot. Hopefully this will save time for the next guy who has to deal with this.



Scenario:
You're a conscientious developer who's sprinkled WPP_TRACING macros all over (and I mean, ALL OVER) your Windows driver. The driver goes out into the real world, and everything is fine, until one day you have a customer complaining that the driver is not working as it should. It's giving some cryptic (or worse, generic) error. You think, "Hmm... thank FSM that I used WPP. I'll just grab the tracing files from the offending computer & figure out what went wrong". That's where this blog post comes in handy.



Steps:

1. Substitute as needed. I've used these defaults to make the steps clear:

<arch> = x64.

<LoggerName> = MyDriverLogger. This is an arbitrary name that is used to register the autologger.

<ETL File> = MyDriverLog.etl. Arbitrary named WPP trace log file.

<Driver WPP GUID> = 144EBFEE-C4AD-4A88-B8AC-3B7F7E5AD442. This is from your WPP_DEFINE_CONTROL_GUID typically found in your trace.h file.

<Logger GUID> = C7A7ACEB-9A80-4898-98F0-E3F9A5F043FE. The logger name needs a unique GUID.



2. Send the customer three files. tracelog.exe (found in WinDDK\7600.16385.1\tools\tracing\<arch>\), a batch file called 'AddAutoLogger.bat'. This file contains a single line:



tracelog -addautologger MyDriverLogger -guid #144EBFEE-C4AD-4A88-B8AC-3B7F7E5AD442 -matchanykw 0x7FFFFFFF -sourceguid #144EBFEE-C4AD-4A88-B8AC-3B7F7E5AD442 -sessionguid #C7A7ACEB-9A80-4898-98F0-E3F9A5F043FE -flag 0xFFFF -level 0xFF -f %WINDIR%\Temp\MyDriverLog.etl -cir 2



Also send the customer a batch file called 'RemoveAutoLogger.bat' which contains:


tracelog -flush MyDriverLogger


tracelog -remove MyDriverLogger




2. Ask the customer to do the following:

a. Open an admin command prompt and cd to the location where the files are, and run 'AddAutoLogger.bat'.


Developer verification for step 2: If you are trying it on your system, you can open 'Regedit', Navigate to HKLM\System\CurrentControlSet\Control\WMI\AutoLogger. You should see a key called 'MyDriverLogger'. Verify:



  1. Start = 1
  2. GUID =C7A7ACEB-9A80-4898-98F0-E3F9A5F043FE
  3. File=%WINDIR%\Temp\MyDriverLog.etl

There will be a single sub-key in MyDriverLogger. This is the GUID '144EBFEE-C4AD-4A88-B8AC-3B7F7E5AD442'. Verify:

  1. Enabled=1
  2. EnableLevel=0xFF
  3. MatchAnyKeyword=0x7FFFFFFF


3. Ask the customer to perform the activity that causes the problem, or wait for a specified period of time.



4. Ask the customer to open command prompt again and cd to the directory and run RemoveAutoLogger.bat.



Developer verification for step 4: There should be a new file called %WINDIR%\Temp\MyDriverLog.etl.




5. Ask the customer to mail the file to you.



Developer verification for step 5: Check your email and see if the file is attached. :)




Now, the customer's job is done, and it's up to you to show off your debugging chops!




  1. Grab the source corresponding to the driver.
  2. Make a build (the configuration and architecture don't seem to matter).
  3. Run 7600.16385.1\tools\tracing\\tracepdb.exe -f . You get a brand new .TMF file.
  4. Run 7600.16385.1\tools\tracing\\traceview.exe. Select 'Open an Existing File'. Select the .etl file. In the next step, select the .TMF file and add the newly created .TMF file.
  5. Enjoy the WPP trace!!





References:
  1. ETW EtwRegister() provider list. [http://www.adras.com/ETW-EtwRegister-provider-list.t4828-192-1.html]. Thank you, thank you, Ivan
  2. Tracelog command syntax. [http://msdn.microsoft.com/en-us/windows/hardware/ff553012]
  3. Using TraceView. [http://msdn.microsoft.com/en-us/windows/hardware/ff556063%28v=VS.85%29]
  4. TracePDB [http://msdn.microsoft.com/en-us/windows/hardware/ff553043%28v=VS.85%29]