Microsoft's hidden diagnostic tool unlocks Vista startup secrets

In researching a three-part series on Windows Vista start-up times here last month (Part 1, Part 2, Part 3), I spent hours with a stopwatch, documenting my experience with a handful of machines running a clean install of Windows Vista.

As it turns out, I didn't need the stopwatch, because all the data was right under my nose all the time. Vista's onboard monitors are constantly recording information about performance and storing it in the new, greatly expanded event logs. It's an overwhelming amount of information, in fact, and none of the details are documented anywhere.

To get to the bottom of the mystery, I sat down with a group of Microsoft engineers for a free-wheeling hour-long conversation about Vista boot times and performance, with a special emphasis on learning how to troubleshoot problems that you might experience. I also collected data from 104 Windows Vista startups and crunched it down to find out just how long Vista really takes to start up.

It all starts with Vista's Event Viewer program. I've put together an image gallery showing how you can access the same information on your system. so you can follow along. The key information is contained in the Diagnostics-Performance log, where event IDs 100-199 capture information about Boot Performance Monitoring. (The same log contains information about shutdown times and overall system performance, but for this project I chose to zero in exclusively on boot times.)

Want to see how your computer measures up? Click here for step-by-step instructions with detailed illustrations.

Every time you start your computer, Windows logs your boot time, starting as soon as the kernel loads (obviously, Windows can't track the time it takes for your hardware to enumerate itself and for the BIOS to hand off control to the OS loader) and ending after every background service and process has finished loading and the system has been idle for at least 10 seconds. The total boot time is divided into two parts

• MainPathBootTime measures the time it takes for the system to load all drivers and services that are critical to user interaction and get to the Windows desktop where the user can begin doing things.
• BootPostBootTime includes all the other drivers and processes that aren't critical to user interaction and can be loaded with low-priority I/O that always gives preference to user-initiated actions that execute using Normal I/O priority.

If you look in Event Viewer, you'll see a separate value called BootTime, which measures the sum of these two values. (Subtract 10 seconds from this value to account for the idle time that indicates the boot process is completely done.) In addition, the logs are filled with clues that can help you figure out what went wrong and why a specific startup (or shutdown) took longer than normal.

Because the Event Viewer logs save their data in standard XML, I was able to capture this data from 104 startup events on four separate machines and crunch it down to these bullet points:

• 35% of all starts took 30 seconds or less to return control to the user
• 83% of all starts took 60 seconds or less to return control to the user
• 70% of all starts completed all boot processes, including low-priority I/O activity, in two minutes or less
• 94% of all starts completed all boot processes within three minutes

I've created a scatter chart using the data from these systems that makes the point visually and used that chart to kick off the image gallery.

In conversations with engineers at Microsoft, I learned that these values are consistent with what they've observed over millions of installations monitored via opt-in data collection programs, on an incredibly diverse array of hardware installations.

In a follow-up, I'll explain what I learned about why some startups take longer than others and how you can diagnose and resolve startup problems on a Vista PC.