Performance Series Part 1 – How to collect an ETW/Xperf trace to capture general performance issues

Applies to: Windows 7+, Windows Server 2008 R2+
Target audience: People I support primarily. Anyone who wants to perf like a pro?

Step 1: Get the Windows Performance Toolkit, by way of the Windows Assessment and Deployment Kit. Since every iteration of the WPT happens to be distributed slightly differently than the previous version, I’ve included the MSFT guide on getting the most recent as a link. As it stands now, run through the web installer and uncheck everything but “Windows Performance Toolkit”.

It is worth noting that the resulting Windows Kits folder with the WPT in it is typically portable. Meaning once you install, you can usually copy/paste the folder to another host without going through the web installer again. There are also redist executables to install just the WPT for ‘next time/next system’ as well.

Step 2: Open WPRui (Start/WPRUI/enter)

Step 3: Expand the “More Options” caret.

  • Expand Resource Analysis.
    • Select “CPU Usage”,
    • Select “Disk I/O Activity”,
    • Select “File I/O Activity”
  • Expand Scenario Analysis.
    • Select “Minifilter I/O activity”

Step 3a: Optionally I may have you skip this and click “Add Profiles…” and add a custom XML instead of check individual boxes.

Step 4: Validate the Performance Scenario is “General”, Detail Level is “Verbose” and Logging mode is “Memory”.

Step 5: Click “Start” and then reproduce the ‘bad behavior’.

Step 6:  Let the collection run for the amount of time I gave you (or a couple minutes) and then click stop.

Step 7:  Wait.

Zip and upload the resulting ETL file and the same-named NGEN.PDB folder (if present) to me.

How To: Collect ETL/WPT tracing diagnostics when you can never logon to the host.

First, guess who's back?!

Me! I left Microsoft of my own accord last year. I came back. I wrote this about my experience, I hope you enjoy it.

There and back again, an IT tale…

Anyways, I was asked a few times recently, Dude, how do you collect an ETW trace for boot/logon if the machine never lets you logon? Is this a chicken/egg scenario?! We need the trace to find out why we never get to desktop, we can't get the trace because we can't get to desktop to stop it?!

Well friends, I'm here to say you can in fact collect your hard won trace!

For your problem node(s) just get a trace started. How if you can't logon to desktop? Easy, here are some options for you:

– Safe mode w/Network copy the Windows Performance Toolkit folder onto the troubled node.

Run Xbootmgr -trace boot -traceflags dispatcher+latency

If SafeMode doesn't work

– Boot up system. Don't logon. Copy WPT directory onto system.

PSExec / scheduled task as system/autoexec.bat the command (guess) "xbootmgr -trace boot -traceflags dispatcher+latency

Now that the system has a xbootmgr trace and is shutting down and rebooting….

Wait to logon, when prompted, do so.

wait 3-4 minutes

– PSExec to the machine. xperf -d C:\directory\merge.etl

If psexec didn't work

set a scheduled task remotely or locally in safe mode if that works, to run xperf -d C:\directory\merge.etl in some directory you made.

(tasks need to run in system context).

Problems with this? Don't get it? Ask questions/comment please. I'm here, for you.

Peace!

Xperf for the layman, performance analysis unchained, Windows Assessment Toolkit revealed.

If you have been following along in performance land the last year or three, you’d hear about xperf and the WPT (Windows Performance Toolkit).  Mayhap you’ve had some time to practice and you know what you are doing.  Cool.  This tool might still interest you.

If you, on the other hand, haven’t heard of these, or haven’t had the time to spend to get good at them, then this tool will definitely interest you.

It is the Windows Assessment Toolkit.  Unlike the Windows Assessment Server, which I’ll speak to later, Windows Assessment Toolkit it a stand alone, infrastructure-less toolkit designed to help layman and skilled professional alike with client performance analysis. 

This is an option for both Windows 7 and Windows 8 by the way.

So without further ado, lets get rolling…

Step 1 – Get the tool

Go here and run the web installer for the ADK.  Cycle through the installer until you get to the checkbox list of tools and pick 2 as seen below:

image

 

Let it install.

Step 2 – Use the tool (data collection and review)

Launch the Windows Assessment Console for the Toolkit like so:

image 

So here we have the Console Launching…and then, the console:

 

image

 

 

So, browser running slow can’t figure out why?  Want to see how long the battery will really last?  Does it take forever to startup and you want to know why?  Just some of the test cases at your finger tips.  Note all these in the default pane run only on Windows 8 or Windows RT.  But when you select “Run Individual Assessments”:

image

A fair amount of them can be run on Windows 7 as well as 8.  So if you don’t want to stand up the infrastructure of a Windows Assessment Server, use this to vet out the performance of hardware, your build, third party filter drivers like AV, DLP, NAC, etc.

The key to this UI though is to click “Configure” down at the bottom next to the Run button, because that’s what you can use to determine which of these ad-hoc test cases can be run against Windows 7 as well.

image

Note this test case can run on Windows 7.  If you wanted to make a test case to give to someone or to place on another machine, just click “Package…”

image

And then you can run it on a machine without having to install any console.

So click Run to do a test case.

image

 

And then it dumps you into a report view when it is complete.  All the items are clickable, and can take you into the ETW trace files if need be.  For example:

image

See below, we’re selected on one of the found issues and on the right hand pane we get an explanation of what the problem and recommendation are to remediate, along with a link to TechNet on what the ‘deal’ is.

image

Take the time to use this in your environment on workstations….why you are going to ask?  What does it get me?

 

Well, the driver certification and verification jobs will identify problem drivers in your build that could cause BSODs or other problems…

The File Handling test case will give you a crystal clear idea of DLP or AV’s ‘cost’ to performance in terms of file io.

Boot up is a general holistic view of the boot up process and the impact of everything on it.

Internet Explorer browsing experience is a collection of pages the job will hit locally for graphics rendering.  It’s pretty slick.  Run it and see.  How good is your GPU and GPU driver at hardware rendering?  Find out.

Check this out, see how it works, and it’ll even point you to issues in the ETW files and you can use this as a jump start to real ETW trace analysis on your own.

Hope you liked this post!

The Dude…

What does a good boot look like (aka, what should I be happy with)?

It’s a question I wasn’t prepared for in class last week, but one that made sense really.  For the IT Pro that doesn’t eat breath and sleep this stuff, what does a good or ‘fair’ trace look like?

Something like this:

image

What we are looking at here is a boot up that finishes before 45 seconds, with post boot delay quieting in the 60-ish range.  Not bad.  I like getting to a useable desktop in less than a minute, and this boot delivers that.

Do we see any boogeymen here?

image

Or here?

image

Nope, not yet.

image

Nah, not really.  This is a healthy boot.

 

Why?

 

CPU doesn’t spike and/or ride high through boot.  Disk doesn’t ride at 100% through it, so we’re not exceeding storage’s ability to deliver with the boot demand.  DPCs are low, we don’t have a bad driver, etc.

This is a good boot.

How to collect a trace for audio or video problems in Windows 7

Assume the following:  You have a Windows 7 host that you want to collect a trace from.  The user complains of audio issues, stuttering, latency, etc…or video frame rate is low.  Something annoying.

Like my previous post, lets cover a few basic rules here as we get started:

1.  If host = Windows 7 AND bitness = amd64 THEN Set DisablePagingExecutive to 1 and reboot:

http://technet.microsoft.com/en-us/library/cc959492.aspx

2.  Make sure the user account we want to trace is local administrator, even temporarily.

 

After we have that, install the Windows 8 ADK on the target machine, or copy the Windows Performance Toolkit from a machine it has already been installed on onto our target machine.

(We can install by running ADK Setup and deselecting EVERYTHING except Windows Performance Toolkit, by the way.)

installADK-WPT_thumb1

 

So, its there, somewhere.

 

1.  Run WPRUI elevated/as administrator

 

wprui1_thumb1

 

2.  Click More Options on the bottom left, revealing the window that looks like this:

 

image_thumb3

3.  For audio and video glitches that are easy to reproduce, check the scenario you are reproducing in the scenario analysis area.  Change Logging Mode to File based and hit start.

image

 

4.  Click “Start” and the reproduce the issue.  The window will look like this while you do so:

image

5.  When it reproduces, click Save and save the file off, review in xperfview or Windows Performance Analyzer to determine the cause of the glitches, probably DPCs from usbaudio drivers, but what do I know….

“But way Dude!  What if this isn’t easy to reproduce?” you may ask….

Step….

6.  If this is not easy to reproduce, get setup to collect a trace as above, but don’t use WPRUI.

Instead, elevate a command prompt, go to the root of a drive, I’ll use C: for the example, and do the following after you have DisablePagingExecutive set and WPT installed…make a trace directory and cd to it.

xperf -on dispatcher+latency+drivers -stackwalk readythread+threadcreate+cswitch+profile -f C:\trace\xperftrace.etl -minbuffers 1024 -maxbuffers 1024 -maxfile 512 -filemode circular

Then let it run in the background while you dork around trying to reproduce the issue.  Once it hits, simply do the following:

Xperf -d C:\trace\results.etl

Now you can open results.etl in xperfview.exe or Windows Performance Analyzer and look for DPCs and so forth that might be causing the issue….

Enjoy!

How to collect a good boot trace on Windows 7

Assume the following:  You have a Windows 7 host that you want to collect a trace from.  A good trace.  One that you know other people will be able to decipher as well as yourself.  Maybe I’ve asked you to collect a boot trace so I can look at it and pointed you to this blog.  Maybe your Sherpa of IT has decided you should learn this and you are doing it to learn….

(edited 11-2)

[You may also use xperf’s xbootmgr with a syntax similar to this:

xbootmgr -trace boot -traceflags base+latency+dispatcher -stackwalk profile+cswitch+readythread+threadcreate -notraceflagsinfilename -postbootdelay 30

]

 

In any event, you have a Windows 7 host.

Lets cover a few basic rules here as we get started:

1.  If host = Windows 7 AND bitness = amd64 THEN Set DisablePagingExecutive to 1 and reboot:

http://technet.microsoft.com/en-us/library/cc959492.aspx

2.  Make sure the user account we want to trace is local administrator, even temporarily.

3.  Set AutoLogon up in the registry for this user so we don’t flub a password input and invalidate a trace with bogus data:

http://support.microsoft.com/kb/324737

 

After we have that, install the Windows 8 ADK on the target machine, or copy the Windows Performance Toolkit from a machine it has already been installed on onto our target machine. (link http://www.microsoft.com/en-us/download/details.aspx?id=30652)

(We can install by running ADK Setup and deselecting EVERYTHING except Windows Performance Toolkit, by the way.)

installADK-WPT

 

So, its there, somewhere.

 

1.  Run WPRUI elevated/as administrator

 

wprui1

 

2.  For a boot trace, click More Options on the bottom left, revealing the window that looks like this:

 

image

3.  For the boot trace, I would like to see CPU Usage, Disk I/O Activity and File I/O Activity.  I would like you to change the Performance Scenario to “Boot” and number of iterations to “1”, as so:

image

 

4.  Click “Start” and then type something into the box and select a convenient place to store your trace and then hit “Save” which will reboot your machine and collect the trace.

image

 

5.  Let it reboot, let it logon as the user you specified in the auto logon, let it count down the normal boot process and end with the ETL trace in the directory you specified.  Get me that trace, stat!  Or if you are doing this to learn, poke around in it in XperfView.exe and WPA.exe, two entirely different ways to view the data set.

Hope this helps, after I stand up a VM or two I’m going to do some WPA examples….

Windows 8 ADK solves GPO Logon Delay questions, film at 11….

Symptoms:  Logons take forever and you’ve collected an xbootmgr/WPR/xperf123/xperfui trace.  What GPO can it be?  Easy!

 

Open Windows Performance Analyzer from the Windows 8 ADK:

image

Open Said Offending Trace:

 

image

Expand…System Activity and then find the Generic Events, click and drag the windows so its under “Analysis” tab…

image

AR me eyes!  Relax, its ok, we’re going to bring some good order out of this chaos.  Click this button in the top right:

image

And no, I can’t draw straight lines….

This trace should now look like this:

 

image

Slide down on the Provider Name area until you locate “Microsoft-Windows-GroupPolicy”.  Right Click and select “Filter to selection:

image

 

Sanity ensues…Now click the Carrot on Task Name (right of Provider Name in the middle of the screenshot above:

Anyway, this view looks like this (still too busy):

image

Notice the diamonds at the top by the way?  Highlight WinStop on the top and it’ll take you to the bottom area for WinStop.  Observe when each one ends and also, look for the column CSEElapsed Time:

 

image

 

Because it took 360453 ms to complete:

Next expand the CSEExtension Name field

image

Easy as pie.

What is Windows Performance Analyzer all about and why should you use it instead of xperfview?

Consider the following trace in xperfview:

image

This should be familiar to you, it’s the DPC storm / storport doorbell that looks like this:

image

So how does this trace look in WPA from the Windows 8 ADK (RP edition)?

image

A little different, but the Dude isn’t closed minded here, so lets give it a whirl:

image

Observe.  With that LSI_SAS selected, we see the time frame on the top middle where the CPU was doing work in that module.  and See the stack?  Which view is more in-depth?  WPA is the frickin future man.  I was a doubting Thomas 100%.  But WPA takes xperfview to a whole ‘nother level of magic.

And the Dude believes!

Hats off to Michael Milirud and the Windows Performance Toolkit team.  Seriously folks.  Job well done.

 

Another example, why does WINLOGON INIT take so long?

image

image

image

image

 

How cool is that?  We can see CCMEXEC took 8 seconds, its simple to just scroll down the list and see exactly why WINLOGON INIT took so long, and triage it.

 

I LOVE IT!

 

I’m going to build some broken scenarios in my lab and do some more examples of how-tos…

The dude does xperf…

So the Dude (that’s me) has gone over how to collect xperf traces a few times now, but what do we do after we’ve collected a solid .etl file you may ask?  Well, that’s what this post is all about.  This is how the Dude does it.  The Dude you see is listening to Simple Man by Lynyrd Skynyrd right now, in a loop while flying over the Atlantic on the way to TechEd Amsterdam, so he’s in a mentoring mood…

Ok, so the Dude opens his traces in xperfview from the Windows Performance Toolkit, from the Windows 8 RP ADK.  With me so far?  Good. 

 

So I open this trace for a slow boot machine in xperfview.exe, and it looks like this:

image

We are, of course, looking for patterns, as Clint Huffman would say.  Patterns of analysis that lead us to reproducible solutions.  That’s the win of course.

So what do we see in these first two graphs?  Any patterns, anything that stands out?  Maybe in the second graph we see that blue line running for a long time?  This trace, by the way, is of the Dude’s own machine, on a Seagate Momentus XT 500 GB drive.  So a boot time of 300 seconds – 120 for post boot delay = 180 seconds to get to the desktop.  Completely unacceptable.  The Dude is a busy man!

So what’s going on here?  Lets overlay the disk activity instead of just showing it to you…

image

Is it natural and expected during boot to see disk idle while CPU grinds on an SVCHOST (I’m having a hard time screen shotting it to show you the highlight of that process, but here’s the thread in question in the Thread Activity:

image

That’s a bit more damning isn’t it?  So what is that thread up to, right click on CPU Sampling by Thread and Select Summary Table and we’ll find out:

image

Ok, there’s our culprit, SVCHOST.EXE 1228, so we expand him:

image

This SVCHOST is spending all his time (and most of the time of CPU Scheduling on the box except that pesky IDLE process) grinding on REPDRVFS.DLL.  Anyone have their bell rung on that one?  It’s one of the classic SBSL hotfixes, http://support.microsoft.com/kb/2617858.

The Dude saw 2 members of Public Enemy at the Airport today, they still rock Europe.  The Dude knows what time it is!

RunAsRadio.com spot

Look for the Dudes’ interview with Richard Campbell on RunAsRadio, where I get into a discussion on Slow Boot/Slow Logon scenarios, tools to use and common culprits.  The spot appears on May the 18th!

Links discussed on the interview are:

http://social.technet.microsoft.com/wiki/contents/articles/10130.root-causes-for-slow-boots-and-logons-sbsl.aspx

http://blogs.technet.com/b/yongrhee/archive/2012/02/19/list-of-performance-hotfixes-post-sp1-for-windows-7-sp1.aspx

Thanks!

Jeff Stokes