Over the last few years I’ve written over forty blog posts that discuss ETW/xperf profiling. I’ve done this because it’s one of the best profilers I’ve ever used, and it’s been woefully undersold and under documented by Microsoft. My goal has been to let people know about this tool, make it easier for developers and users to record ETW traces, and to make it as easy as possible for developers to analyze ETW traces.
Some of those posts have aged poorly, and the rest are hidden amongst the 210+ posts (really? wow) I’ve written. The purpose of this page is to be a central hub that links to the ETW/xperf posts that are still relevant. Also, I’ve updated many of the older posts to reflect changes in the ETW toolset (technically known as the Windows Performance Toolkit). For convenience this page is accessible as https://tinyurl.com/etwcentral.
The most important post describes how to record ETW traces. This is important because ETW traces can be recorded on one machine, and analyzed on another. This means that your customers or relatives can record ETW traces and then you can analyze them. Remote diagnosis of issues is a wonderful superpower. The article describing how to record an xperf/ETW trace can be found here – share it with those who have performance problems:
Once you’ve got a trace you need to analyze it (or share it with someone who can). The most comprehensive resource I’ve created for learning how to analyze ETW traces is the series of three videos I created in 2014. More information and links to the videos can be found here:
For more details, or if you don’t want to watch videos, there are many tutorial blog posts available, listed here in rough order of importance:
- UIforETW – Windows Performance Made Easier
- WPA–Xperf Trace Analysis Reimagined – basics of WPA trace analysis
- Xperf for Excess CPU Consumption: WPA edition – basics of investigating CPU consumption
- Xperf Wait Analysis–Finding Idle Time – wait analysis (idle CPU investigations) with UIforETW and WPA 10
- New Xperf and new WPA in the new WPT – new features in WPT 10
- Graph All the Things (Using WPT 10) – graphing custom ETW data
- New Version of Xperf–Upgrade Now – new features in WPT 8.1
- ETW Heap Tracing–Every Allocation Recorded – tracing memory allocations
- ETW Heap Snapshots – tracing all outstanding allocations (much less data than ETW Heap Tracing)
- ETW Flame Graphs Made Easy – using WPA’s flame graphs to visualize CPU usage, and more
- Exporting Arbitrary Data from xperf ETL files
- CPU Performance Counters on Windows – recording per-process CPU performance counters using ETW
- Process Tree from an Xperf Trace – an example of exporting ETL data
- ETW Trace Compression (and xperf syntax refresher) – low-level details on how recording traces works, handy if you want to modify UIforETW
- Bulk ETW Trace Analysis in C#
Doing precise analysis of an ETW trace requires knowing exactly what the many columns in the tables mean. Some of those table columns are documented in these blog posts, updated in 2016 for the latest version of WPA:
- The Lost Xperf Documentation–CPU sampling
- The Lost Xperf Documentation—CPU Scheduling
- The Lost Xperf Documentation—Disk Usage
ETW investigation write-ups:
Some of my favorite blog posts are those that tell a tale of noticing some software that I use being slow, recording a trace, and figuring out the problem. In most cases this let me come up with a workaround, and in many cases the (ridiculously!) detailed bug reports or the attention the posts drew led to the problems being fixed.
Many of the articles linked to below have not yet been updated. It’s an ongoing process but I think it’s worth publishing this now without waiting for all of the updates to finish.
I’ve categorized the investigations by what product was investigated. And, as a reminder, with the exception of the fractal software investigation all of these are looking at problems in software that I don’t work on.
Visual Studio and VC++ code-gen:
- Xperf and Visual Studio: The Case of the Breakpoint Hangs
- Visual C++ Debug Builds–”Fast Checks” Cause 5x Slowdowns
- Visual Studio Single Step Performance Fixes
- Make VC++ Compiles Fast Through Parallel Compilation
- You Got Your Web Browser in my Compiler!
- Self Inflicted Denial of Service in Visual Studio Search
- 50 Bytes of Code That Took 4 GB to Compile
Windows Performance Toolkit (profiling the profiler!):
- Xperf Symbol Loading Pitfalls
- Slow Symbol Loading in Microsoft’s Profiler, Take Two
- Profiling the profiler: working around a six minute xperf hang
Windows:
- Delays in login to Windows due to thread rank – what outranks thread priority
- O(n^2), again, now in WMI
- Making VirtualAlloc Arbitrarily Slower – excessive CPU usage
- Hidden Costs of Memory Allocation – excessive CPU usage
- Taskbar Latency and Kernel Calls – excessive CPU usage (Windows bug)
- O(n^2) in CreateProcess – CFG causing problems again, excessive CPU usage (Windows bug, now fixed)
- A Not-Called Function Can Cause a 5X Slowdown – lock contention during process shutdown, caused by loading the wrong DLL (Windows quirk, triggered by llvm tests)
- Making Windows Slower Part 2: Process Creation – O(n^2) in CreateProcess due to Application Verifier
- 24-core CPU and I can’t type an email (part one) – lock contention during process shutdown (CFG, service workers, v8, WMI – it’s got everything, but it’s mostly Windows bugs)
- Making Windows Slower Part 1: File Access – slowing down Chrome builds with large notification buffers (Windows bug, now fixed)
- 24-core CPU and I can’t move my mouse – lock contention during process shutdown (Windows bug, now fixed)
- 63 Cores Blocked by Seven Instructions – NTFS lock contention bringing a build machine to its knees (Windows bug)
- Arranging Invisible Icons in Quadratic Time – this demonstrates how to use UI Delays to find where a hang is happening, CPU Usage (Precise) to prove that it’s a busy hand, and then CPU Usage (Sampled) to see where time is being spent. And then some surprisingly simple work to prove that it’s a quadratic algorithm.
- Why Modern Software is Slow–Windows Voice Recorder – this demonstrates how I investigated a twenty-second delay in the Windows 10 Voice Recorder
- Slower Memory Zeroing Through Parallelism – poorly implemented parallelism can actually make things slower, while wasting colossal amounts of CPU time. Case in point: the memory-zeroing in Windows uses about 24x as much CPU time as it should (on massively parallel machines), spending all the extra time fighting over locks
- No Start Menu for You – my Windows 10 start menu refused to come up and I eventually tracked this down to a crash in RuntimeBroker.exe plus poor internet connectivity plus a design that favored crash reporting over user responsiveness, all visible in an ETW trace
- 32 MiB Working Sets on a 64 GiB machine – this investigation shows the high cost of PROCESS_MODE_BACKGROUND_BEGIN – it’s undocumented behavior of having a hard-cap on working-set size of 32 MiB can make code run 250x to 800x slower. Ouch!
Windows Live Photo Gallery:
- Windows Live Photo Gallery—Poor Performance Peculiarities (xperfview used for analysis, but concepts are still solid)
- Fixing another Photo Gallery performance bug
Western Digital driver (initially thought to be Windows):
- Windows Slowdown, Investigated and Identified
-
Windows Slowdown, Investigated, Identified, and Now Fixed
Miscellaneous:
- Faster Fractals Through Better Scheduling
- PowerPoint Poor Performance Problem
- Defective Heat Sinks Causing Garbage Gaming
Other people’s ETW investigation write-ups:
- Interleaving small reads of multiple files – World of Tanks load times
- Multi-second delays in Word from inappropriate printer calls
Obsolete posts
Some of the blog posts are now completely obsolete and are listed here only for historical interest:
- Xperf Analysis Basics – obsolete or covered elsewhere
- Xperf Basics: Recording a Trace (the ultimate easy way) – third time’s the charm
- Xperf for Excess CPU Consumption: WPA edition
- Xperf Basics: Recording a Trace (the ultimate easy way)
- The New WPA Xperf Trace Viewer–New Bugs and Old – the reported bugs are generally fixed
- here
Pingback: Summarizing Xperf CPU Usage with Flame Graphs | Random ASCII
Pingback: UIforETW – Windows Performance Made Easier | Random ASCII
Pingback: Xperf Analysis Basics | Random ASCII
Pingback: Exporting Arbitrary Data from xperf ETL files | Random ASCII
Pingback: The New WPA Xperf Trace Viewer–New Bugs and Old | Random ASCII
Pingback: WPA–Xperf Trace Analysis Reimagined | Random ASCII
Pingback: Process Tree from an Xperf Trace | Random ASCII
Pingback: Xperf Wait Analysis–Finding Idle Time | Random ASCII
Pingback: Xperf and Visual Studio: The Case of the Breakpoint Hangs | Random ASCII
Pingback: Thread Naming in Windows: Time for Something Better | Random ASCII
Did you use logman? Is it better/worse than xperf?
Not that it can do something different, but on my W10 installation it came with the system, C:\Windows\System32\logman.exe. Basically, if you install something on user system, looks like it is much better to run logman as an events watchman for your app
https://github.com/google/UIforETW/releases/download/v1.48/etwpackage1.48.zip
shows a malware in your file.
https://www.virustotal.com/en/file/896554acbe3983cd69e100f1e5867c8cfcc30510567e297c843c96ed6e11d986/analysis/
Hello,
Thanks for all your training material for WPA/WPR. I’m trying to learn more about Windows and Services in particular. I’m wondering how you would go about using WPA to find out what triggered a particular service to start? I know how to isolate a service into it’s own svchost.exe and I can zoom into where the service starts and I see that services.exe is the process that starts it, but I don’t know how to go about finding out who/what called upon the services.exe to actually start it up.
Thanks again for all your material!
Hi Bruce,
Please, Is it suitable to launch multiple apps on Windows then record them with WPR, also after a while, launch other apps and so on (every single time e.g. every 8min), then analyze them with WPA. will I get low-performance issues like low JIT compilation, memory consumption, etc? which apps are suitable for that?. Thank you.
I’m trying to identify Memory leak, looking for an increasing trend over a long period of time, Which means the application committing memory (referred to a private bytes) and releasing only small portions, and over a period of time it continue to accumulate Memory.
I’m asking to detect this pattern of Memory consumption Practically.
Thanks
Is it suitable to do it just in WPR/WPA toolkit? or I have to deal with your mentioned tools in Github? because I don’t have much experience to deal with what you explain in Github, maybe just through the tutorial!
Also, please, is there a way to detect that Memory leak while launching multiple apps, not specific ones? Thanks!
Hello Bruce,
How can I design and Implement an ETW-based Windows system Performance testing tool and give it a name, that system can implement a process collecting, analyzing, and visualizing various events that occur in the Windows system kernel by means of event tracking, and is used to detect the performance that occurs during system operations, and to make it quickly locate the bottleneck and improve the efficiency of the system operations.? I hope if there is a tutorial for this work. Thanks.
Thank you for the reply,
sorry, I mean to design that ETW diagnostic tool in .NET
hi Bruce
when i set the tracing to file the tool stops tracing after 5 minute. i need the whole story from the start, the circular buffer tracing is not enough. i get the message: “Tracing to disk ran excessively long. Auto-saving and stopping.”
The size of the file is between 300-500MB. How can I configure the max file size, or the time period of the trace?
thanks,
np
hi Bruce
I want to know how match related CSwitch and ReadyThread events?
the ReadyThread events also konwn as DispatcherReadyThreadTraceData,
it has no new thread id,only AwakenedThreadId,
how to get thr NewThredId?
Thank you so much!
Thank you very much for your reply and suggestion,I will keep trying your suggestion.
Now the problem is focused on getting this piece of ETW event, keyWords:0x800: dispatcher: Dispatcher operation. in Microsoft open source code PerfView,This event source is called DispatcherReadyThreadTraceData,the code show as below:
public sealed class DispatcherReadyThreadTraceData : TraceEvent
{
public int AwakenedThreadID { get; }
public int AwakenedProcessID { get; }
public AdjustReasonEnum AdjustReason { get; }
public int AdjustIncrement { get; }
public ReadyThreadFlags Flags { get; }
public override int ProcessID { get; }
public override string[] PayloadNames { get; }
protected internal override Delegate Target { get; set; }
public event Action Action;
public override object PayloadValue(int index);
public override StringBuilder ToXml(StringBuilder sb);
protected internal override void Dispatch();
protected internal override void SetState(object newState);
public enum AdjustReasonEnum
{
None = 0,
Unwait = 1,
Boost = 2
}
[Flags]
public enum ReadyThreadFlags : byte
{
ReadiedFromDPC = 1,
KernelSwappedOut = 2,
ProcessSwappedOut = 4
}
}
I can’t get the current thread id (New ThreadId), and only can get the AwakenedThreadID, no good solution.