The Xperf viewer (aka Windows Performance Analyzer) will display a list of charts and graphs that you can view to start parsing through the data. As Figure 3 shows, once the viewer is opened, you can select the area of concern.
Figure 3: Viewing the summary table
To help make the graph less cluttered, you can uncheck all but the particular process you want to explore, as I've done. In this case, the process spiking the CPU is WMIPrvse.exe. Next, select the time of concern, right-clicked on the selected area, and choose Summary Table.
Once the Summary Table is open, click the chevron fly-out arrow at the far left. Make sure the Stack option is checked. This may take a few seconds as the symbols and stack load. Uncheck the Module and Function check boxes to make the view appear as it does in Figure 4.
Figure 4: Summary table detail
Notice the yellow line in Figure 4. Columns to the left of the yellow line determine the sort order. So, since the Process column is the furthest left, with the Stack column next, basically this indicates that you want to sort CPU time by process, then by stack. You could also sort by process, then by module if you didn't have access to symbols and only wanted to see which module consumed the most CPU time.
Here's the key to understanding this data. The time interval you selected appears in the title bar of the Summary Table. Thus, in Figure 4, we can see that our selected area encompassed 2.5 seconds. The highest-consuming process during this time period was WMIPrvse.exe, which we know because it has the topmost position in the graph. The numbers in the Weight column represent how many samples were collected during the selected time window. So, for example, we selected a time window of 2.5 seconds, and during that time we can expect to have approximately 2,500 events firing to collect event tracing information—the total of all the values in the Weight column. In this example, then, the CPU was in the context of the WMIPrvse.exe process 1,859.971 times, which represents a weight of 73.8 percent relative to all processes during that same time.
Furthermore, by expanding the plus (+) signs, we can start to unroll the stack and find out what functions consumed the most CPU time. You can also interpret the numbers under the Weight column as 1ms per event, so 1,859 translates to approximately 1.8 seconds. As you start to unroll the stack, you're looking for big drop-offs in time as the areas you'll investigate. In our example, Figure 5 shows a drop-off from 1.14 seconds to .57 seconds.
Figure 5: Finding the time drop-off in the summary table
If I were a developer, I'd start to investigate the cimwin32.dll function calls into kernel32!FindFirstFileW. If I were an administrator, I'd immediately do two things:
- Search online for an update to cimwin32.dll.
- Provide this information to the application's vendor; doing so will significantly reduce the time required to resolve the issue if an update isn't available.
The Anti-Debugger
Sometimes debugging is the only way to get to the root cause of a system performance problem. However, by using Xperf, you can uncover an application's behavior by scanning the names of the function calls and also determine exactly where all the system time is being spent—all without knowing a single debugging command or opening a dump file or being an expert in Windows architecture (although it wouldn't hurt!). Next month, I'll expand on the Xperf topic by digging into the multiple ways you can use the tool to help diagnose some common performance issues.
Special thanks to Tate Calhoun, a Microsoft senior escalation engineer, who contributed significantly to this article.