Event Tracing in HTTP.sys: Part 1 - Capturing a Trace

Hi, I'm Jeff Balsley a test developer in the HTTP.sys team in Windows Networking. In this series I will be showing you how to use and interpret ETW tracing in HTTP.sys.

Http.sys

Http.sys is the kernel-mode HTTP listener that first debuted in Windows 2003 Server. We are often closely associated with IIS6 as they are our most visible customer. The second version of our APIs will debut with Vista. Along with new features and extended functionality, we’ve also vastly improved our event tracing using the new Crimson APIs. (An intro to Crimson can viewed on the .NET Show.)

What is ETW?

Crimson is the next generation of the Windows Event Log shipping in Windows Vista and Longhorn Server. It is a high-performance, low overhead and highly scalable tracing facility provided by the Windows Operating System. Or, more simply, Event Tracing is similar to placing a series of “printf” statements throughout your code to aid in debugging and troubleshooting. ETW can be enabled or disabled dynamically and uses an efficient event buffering system for increased performance.

Why is it useful for Http.sys?

When Http.sys first appeared in Windows Server 2003, it lacked basic diagnosing and analyzing tools. While it did include some event traces, they were often unhelpful in identifying common customer issues. Often, customers had to rely on a packet sniffer and/or a kernel debugger to probe their Http.sys issues. For Vista and Longhorn Server, it was a goal of the Http.sys dev and test team to include ETW events that would aid customers in analyzing their Http problems. To do so, we analyzed customer issues and complaints occurring after the release of Windows 2003 server and included events that would easily reveal the problem at hand.

Creating an ETW trace

Creating an Http.sys ETW trace is similar to creating one for wininet. To start tracing events in Http.sys use the logman.exe tool. Logman.exe ships with every Windows installation, and can be used right out of the box. To enable ETW, type:

C:> logman start httptrace -p Microsoft-Windows-HttpService 0xFFFF -o httptrace.etl -ets

Here httptrace is the name of our trace. This will be used to identify this particular event trace in further commands. Logman needs to know which components of Windows to trace. Since we are only interested in tracing Http.sys, we pass the provider name, "Microsoft-Windows-HttpService". The 0xFFFF signifies we want full tracing, or all trace events. Our event trace will be written to a raw binary file, httptrace.etl. Please note that you must be an elevated Admin to use the logman command.

That's all that's needed to turn tracing on. Recycling services is not required as ETW is dynamic. Now, any activity in http.sys will be logged in our binary trace file, httptrace.etl.

To stop tracing we use the logman tool again:

C:> logman stop httptrace -ets

 

This will flush the event cache to your .etl output file, httptrace.etl in this case. By itself, the .etl file is of little use. We can create a human readable file in either XML or .csv format by using the tracerpt command (admin privs not necessary here):

For .csv output:

C:> tracerpt.exe httptrace.etl –of CSV -o httptrace.csv

For XML output:

C:> tracerpt.exe httptrace.etl -of XML -o httptrace.xml

To maximize the amount of useful information in each trace I would advise the XML format. However, the XML trace file can grow rather large quickly. For these traces, it may be best to stick with a simple .csv format.

In the next ETW Post I will look at multiple ways to consume and view this binary tracing data.

   -- Jeff Balsley

Comments

• Anonymous
  January 18, 2007
  The Crimson APIs link has a "Content not found". And when I type logman start httptrace -p Microsoft-Windows-HttpService 0xFFFF -o httptrace.etl –ets I get Argument '-ets' is unknown. Argument 'o' is not allowed with the other arguments specified. Argument 'p' is not allowed with the other arguments specified. Error: The parameter is incorrect.

• Anonymous
  January 19, 2007
  The commands have been edited to remove some character munging.  Probably due to converting from different version of Word and what not.

• Anonymous
  February 08, 2007
  In my last post I discussed an issue with paged pool exhaustion and MUP. One of the pieces of data collect

• Anonymous
  May 14, 2008
  hi, I have windows 2003 server when i try to enable event log im getting following message Warning: Could not decode "Microsoft-Windows-HttpService" from the currently registered providers. any solution ? Thanks in advance.

• Anonymous
  May 20, 2008
  The comment has been removed

• Anonymous
  June 23, 2008
  IIS Trace Logging in Windows Server 2003 SP1 This post will briefly describe how to enable IIS trace

• Anonymous
  March 12, 2009
  When I run the below command logman start W3wpTrace -p "IIS: Request Monitor" -ets the trace does not start Any idea what the reason could be?