ETW in the Windows 7 USB core stack


Hi, my name is Philip Ries and I’m also a developer on the USB core team. I’d like to tell you about the instrumentation that our team added to the USB core drivers for Windows 7, and how you can make use of this instrumentation.

The USB Hub and USB Port drivers are instrumented with Event Tracing for Windows events. What does this mean? In brief, anyone running Windows 7 can activate a USB trace on a live system and record what’s going on in our drivers. The recorded log can help troubleshoot USB issues.  Anyone can read the log because the events were compiled using a manifest.

Driver development: Manifested ETW

You might see this kind of event instrumentation referred to as “Manifested ETW” to distinguish it from other ETW-related technologies. Manifested ETW allows you to log well-defined events with structured data payloads. If you’re interested in instrumenting your own driver this way, the WDK instructions for manifested ETW will help you get it working.

In the rest of this post, I’ll describe the steps to record and view a USB ETW log. The recording steps use the “Logman” command-line tool that comes with Windows; the viewing steps include instructions to download a log viewing tool.

Record the log

Are you ready to start the log? A shorter log is more readable, so try to narrow down the start and end of the log as much as possible around an operation you want to examine. I’ll call this operation the “scenario” that you’ll be tracing. Tip: You can also reduce the log size by disconnecting USB devices that aren’t related to the scenario, as well as by entering the trace commands via Remote Desktop instead of on a USB keyboard.

You’ll need to open an elevated command prompt: Open the start menu, type “cmd” (without the quotes), right click on cmd.exe, and select “Run as administrator”.

In the command prompt window, enter these 2 commands.

  • Logman start Usbtrace -p Microsoft-Windows-USB-USBPORT -o usbtrace.etl -ets -nb 128 640 -bs 128
  • Logman update Usbtrace -p Microsoft-Windows-USB-USBHUB -ets

After each command logman should display “The command completed successfully.”

Now perform the USB scenario that you want to examine.

When you’re done, stop the log with this command:

  • Logman stop Usbtrace -ets

The log has been saved as usbtrace.etl in the current directory (often C:\Windows\system32). We’re done with the command prompt window now.

View the log

Make sure to note the path and filename of the log file you created. We’ll use Netmon (Microsoft Network Monitor) to view the log. You might not guess it from the program’s name, but Netmon can handle ETW traces in addition to network traffic logs. Here’s how to install it with our ETW parser.

  1. Determine whether you have 32-bit Windows or 64-bit Windows:
    1. Open the Start Menu
    2. Right click “Computer” and select “Properties”
    3. Look at the “System type” field. (Note: 32-bit corresponds to “x86” for the downloads)
  2. Install Netmon:
    1. Go to the bottom of the download page and press the “Download” button for your system type
    2. Download and run the exe. When it asks about setup type, Typical is fine.
  3. Install Netmon’s parser set
    1. Go to the parsers CodePlex site
    2. Click “Downloads”
    3. Select the Microsoft Parsers package that matches your system type. For example, for x86 choose “Microsoft_Parsers_x86.msi”
    4. Download and run the MSI installer
    5. Select to upgrade the installed parsers
  4. Activate the Windows parsers:
    1. Run Netmon. It has a folder in the Start Menu like “Microsoft Network Monitor 3.3”
    2. Open Tools->Options
    3. Click the Parser tab
    4. Select “Windows” parsers
    5. Click “Stubs” button to deactivate stubs and use full parsers. See the image below for how the settings should look.
      Netmon options configuration
    6. Click OK
    7. Restart Netmon

Go ahead and open an ETW log (.etl) and explore it.

In future blog posts I’ll show some examples of diagnosing USB issues using USB ETW and Netmon.

Update: Here’s Part 2 of this post

netmon-options.png

Comments (26)

  1. ymhuang says:

    A quick question – by following instruction to install netmon and upgrade complete, the netmon only support .cap & .pcap in default.  

    It’s failed to open .etl file. Is that any step is missed?

    My environment is WinXP SP3.

  2. ymhuang says:

    never mind, it work well on my Win7 laptop.  

  3. gokuson says:

    it’s not working on Win XP.

    Netmon only support .cap & .pcap by default

  4. Chris says:

    Is there a possibility to run the trace while system is booting up ?

    I need this to trace a problem with a wireless usb stick. It does not work after booting the system, usb error 43 (unknown device). unplugging and plugging the device solves the problem, but it’s really annoying.

  5. USB Blog says:

    Yes it is possible to turn on tracing while booting using AutoLogging.Please refer to the following msdn page for further information

    http://msdn.microsoft.com/en-us/library/ms797180.aspx

  6. Andrew Loke says:

    "In future blog posts I’ll show some examples of diagnosing USB issues using USB ETW and Netmon."

    Do you have the article on this? I’m looking forward to see some USB ETW trace diagnosis sample in Netmon.

  7. JHoffman says:

    Won’t work on Server 2008 correct?

  8. USB Blog says:

    Right, you won’t find USB ETW in Windows Server 2008.  I believe these instructions work for Server 2008 R2 though.

  9. Nick Pron says:

    Firstly I’d like to thank you guys, this is a great nifty little tool to help debug. Never knew this existed until I googled usb stack tracing.

    Just a few questions

    1) Is there any resources or documentation on what to do when you do find issues, for example

    USBHUB_ETW_EVENT_HUB_PAST_EXCEPTION: USB Hub Past Exception Logged

    fid_DebugText: HubErr_SetUsbWakeFailed

    Where can I go to learn more on how to resolve this issue?

  10. JHoffman says:

    What does this mean?

    USBHUB_ETW_EVENT_HUB_PAST_EXCEPTION

    Is this error occuring everytime or is it as indicated, a past exception that is shown each time I log usb events?

  11. USB Blog says:

    Yes, past exception events indicate exceptions that happened earlier, and the same past exception may be shown multiple times in the log.

    If you fully capture the repro or scenario in the log then the past exception events are usually not needed.

  12. Network Monitor 3.3 and above can only open .etl files on Vista and above due to a system dependency.

  13. Hunter says:

    I am writing a firmware for a costum device and I am trying to debug the USB Interface.

    Right after the Endpoint Information from my Device. (Its the Frist Endpoint 0) I get a USB Hub Information and after that a Past Exception Information Logged.

    But I can see all Descriptors correctly in the USB Device viewer. I am using the winusb driver. And from winusb trace I get Unable to Create IO Target.

    Can somebody give me a hint what could be wrong?

    I really begin to despair

  14. satish Kumar says:

    Can anybody provide a way to track the activity of a usb device. I want to know at a particualr time whether my usb device is active or suspended.

  15. Yuvraj Huge says:

    Can I use this in a windows xp embedded image.? If yes, which components i need to copy from windows 7?

  16. USB Blog says:

    @Yuvraj – Sorry, USB ETW was introduced in Win7 and can't be used on earlier OSes.

  17. Mark says:

    Great Post!  Having examined the output from logs for a driver I'm working on I noticed that, at least in the case of control transfers, only the device-to-host data payloads seem to be logged.  Is there any way to view the data payload sent to the device as well, or are these not logged?

  18. Simon says:

    I have the same question as Mark: Is it possible to inspect the transfers from the host to the device?

    And one question regarding the device-to-host traffic: Is it possible to see the entire payload? In my case, 275 bytes are received, as also indicated here:

    Urb: success, Function = URB_FUNCTION_BULK_OR_INTERRUPT_TRANSFER, Length = 275, Flags 0x3,

    but fid_URB_TransferDataLength: 32 (0x20) and fid_URB_TransferData contains only those 32 bytes.

    Thanks in advance, Simon

  19. USB Blog says:

    Mark and Simon: Not all transfer data is logged.  The maximum amount logged depends on the transfer type and direction, and in some cases the maximum is 0.

  20. JVB says:

    Is there a utility program to split up a large usbtrace.etl file into several smaller ones?

    I received a usbtrace.etl file from a customer that is 14 GB.   I tried to open it in netmon but netmon reports it is corrupted.  I think it is just too larger for netmon to open.

    If a utility program does not exist for this, what APIs can be used to read one event record at a time and write them out to a set of smaller files?

  21. USB Blog says:

    I am only aware of the Relogger API for manipulation of .etl files: msdn.microsoft.com/…/Hh706657(v=vs.85).aspx

    You can also try opening the trace in Event Viewer and see if it thinks it's corrupted.

  22. JVB says:

    I tired the -max and -cnf options on the logman start command.   -cnf does not seem to work.

    Can you provide an example of how to use these two options with the logman start command when tracing events for USB?

  23. JVB says:

    I was able to open the trace file in Event Viewer.   Does that mean it is a problem with netmon when opening large capture files?

  24. liaoo says:

    Does this way can log USB 3.0 traffic ?

  25. Help please says:

    Hi

    I have an USB STICK DRIVE (Kingston G2 DataTraveler 8 Gb) that is ”scrambeld”…. windows recognized it as ”USBDEVICE_DESCRIPTOR_FAILURE” (ALL windows version – XP, 7, 8).

    There is any way to ”rewrite the firmware” of USB STICK to try to recover my data?

    The information about disk is:

    USB Device ID: VID = 0951 PID = 1624

    Please e-mail to me at dinu.laurentiu@gmx.com

    Thk