Two Minute Drill: Introduction to XPerf

Two Minute Drill: Introduction to XPerf

  • Comments 6
  • Likes

Hi there, this is Mark with the Windows Performance Team.  This post is a quick introduction to a new performance tracing tool called XPerf.  Moving forward with Windows Vista and Windows Server 2008, this powerful tool will hopefully be utilized more often.  XPerf is part of the Windows Performance Toolkit (WPT) which can be downloaded from the Microsoft web site.

XPerf is designed for Windows Vista and Windows Server 2008, but will run on Windows XP and Windows Server 2003 by copying Xperf.exe and Perfctrl.dll to the target machine.  XPerf uses ETW (Event Tracing for Windows) and is very low overhead, requiring only about 1500-2000 clock cycles per log.  As an example, 20,000 calls per second is less than 2% CPU on a 2.0 GHz processor.  While the data collection is running, the XPerf tools are not even loaded - the kernel itself is collecting the data.  All analysis is done in post processing. Since Xperf is ETW based, sample profiling can be started and stopped at any time, without stopping or restating even a single process.  You can profile anything at any time on any system.  The traces are logged in a circular fashion, based on the buffer size that is set.  The basic process is this:

  1. ETW tracing is enabled by using XPerf.
  2. Operations are performed.
  3. ETW tracing is disabled by using XPerf, and the data is saved to an ETL trace file.
  4. Trace files can then be further processed by using XPerf or viewed by using Performance Analyzer (XPerfView).

Once a trace is taken, you can copy it to a Windows Vista or Windows Server 2008 machine for trace decode and viewing.  The traces are also cross-platform, so you can view them on Windows Vista or Windows Server 2008 (either x86 or x64) regardless of what type of machine they were taken on.

The following is a quick introduction and few examples. The image below shows the basic workflow:

 

image

 Some usage of this tool:

  1. If DPC isn't running in Idle, then we can see what driver is responsible for that.
  2. Stackwalk reports stack report and hierarchy module and function calls.
  3. XPerf can start a new process from a given command line and use its process ID for the duration of the trace (-pidnewprocess)
  4. Disk resource and activity including per process disk activities
  5. Looking at Hard Faults we can see when I/O's are blocking a process.
  6. Marks can be added during the trace for information. They can be viewed in the trace during the analysis.
  7. Outstanding I/O's for different processes can be observed
  8. Dynamic grouping capability when looking at the graphs
  9. Can be used to check all registry access during the trace
  10. All file activities can be traced
  11. Heap allocation tracing
  12. Using –i switch, specific items in trace can be parsed and saved into different formats including CSV, XML and plain text for further analysis. This switch also could be used to automate analyzing the XPerf trace files.
  13. XPerfview.exe can be used to view graphs of the .etl trace log. 
  14. Kernel and User providers can be used to take multiple traces. Using the merge switch, they can be merged into one .etl file.

In order to look at the modules and function calls from a trace that was taken with Stackwalk enabled, Symbols must be set in the environment variables. In order to configure symbols, you can use the following command:

   C:\>Set.exe  C:\WebSYMBOLS;srv*C:\WebSYMBOLS*HTTP://MSDL.MICROSOFT.COM/DOWNLOAD/SYMBOLS

To view all providers;

    Xperf.exe -providers

To view only Kernel Providers (including Kernel Groups and Kernel Flags);

   Xperf.exe –providers K

Here’s the list of all Kernel Flags

PROC_THREAD  Process and Thread create/delete
LOADER Kernel and user mode Image Load/Unload events
PROFILE CPU Sample profile
CSWITCH Context Switch
COMPACT_CSWITCH Compact Context Switch
DISPATCHER CPU Scheduler
DPC DPC Events
INTERRUPT Interrupt Events
SYSCALL System Calls
PRIORITY Priority Change Events
ALPC Advanced Local Procedure Call
PERF_COUNTER Process Performance Counters
DISK_IO Disk I/O
DISK_IO_INIT Disk I/O Initiation
FILE_IO File System Operation end times and results
FILE_IO_INIT File System operations (Create / Open / Close / Read / Write
HARD_FAULTS Hard Page Faults
FILENAME FileName (FileName create / delete / rundown)
SPLIT_IO Split I/O
REGISTRY Registry Tracing
DRIVERS Driver Events
POWER Power Management events
NETWORKTRACE Network Events (such as TCP / UDP send and receive)
VIRT_ALLOC Virtual Allocation reserve and release
MEMINFO Memory List Info
ALL_FAULTS All page faults

There are a ton of stack walking flags, so instead of listing them all, please refer to the following MSDN link for more info:

http://msdn.microsoft.com/en-us/library/windows/desktop/ff191012(v=vs.85).aspx

 Please note: the stackwalk feature currently doesn’t work on Windows Server 2003 and Windows XP since their older kernel doesn't support it.

Here are some examples:

Example 1 - Start a trace with BASE Kernel Group and cswitch Kernel Flag and then stop the trace and save it in mytrace.etl file;

                xperf -on base+cswitch

                 xperf -d mytrace.etl

    Then use this command to view the information about the trace itself (-detail at the end will give more detailed information about the trace)

                 xperf -i mytrace.etl -a tracestats -detail

    This will report the processes information(Start Time, End Time, Process, DataPtr, Process Name (PID), ParentPID, SessionID, UniqueKey) in the trace;

                 xperf -i mytrace.etl -a process

    Finally, redirect the output to a CSV file;

                xperf -i mytrace.etl -o C:\xperf-process.csv -a process

 

Example 2 - To start user mode logging and kernel logging at the same time:

               xperfinfo –on base+Network –f kernel.etl -start UserTrace -on Microsoft-Windows-MeetingSpace+Microsoft-Windows-Firewall -f user.etl

Explanation: A kernel trace is started. The kernel session does not need a session name to be specified because its name is unique. The groups Base and Network are enabled on the kernel provider. This trace will be collected in a file called Kernel.etl

At the same time, a user trace named UserTrace is started and the provider’s Microsoft-Windows-MeetingSpace and Microsoft-Windows-Firewall are enabled to it. This trace will be collected in a file called User.etl

Using the following command, the UserTrace session is stopped. The two user-mode providers no longer produce events to this session (they might still be generating events to other independent sessions).

                xperfinfo –stop UserTrace

   Stop the kernel session:

                xperf -stop

    Merge the user and kernel traces into a single trace called System.etl:

                xperf -merge user.etl kernel.etl system.etl

   Post-process the binary trace file System.etl into an ANSI text file called System.txt:

                xperf -i system.etl -o system.txt -a dumper 

Additional Resources:

We’ll be writing more about this tool and how to troubleshoot certain scenarios in future posts. There are several new powerful tools available for troubleshooting and diagnostics – XPerf is only one of them.  See you next time!

- Mark Ghazai

Share this post :
Your comment has been posted.   Close
Thank you, your comment requires moderation so it may take a while to appear.   Close
Leave a Comment
  • This blog is set up by commercial technical support windows server performance team. The blog is totally about technical stuff explained to the minute details. A Microsoft owned blog, this one has a Google page rank 5. Not many people who doesn’t like technical stuff will find this blog an interesting read.

  • Great article. How would I add my own providers via MOF files so that they are recognized and usable with .ETL files in WPT? I have the MOF file registered, but WPT does not recognize the provider in the UI.

  • Hi Jonathan, please see the MSDN link in here. Thanks, Mark

  • Hi!

    Thanks for article. I read this article and instructions on MSDN, but I don’t see  what need to do in cause: I want to trace processes  from moment of begin start PC to moment when user account is successful loaded.  

    If I run command "xperf -on DiagEasy" and then restart PC, trace finished after system shut down.

    Which command I have to run in my cause?

    sorry my English, I am from Russia.

    Thanks!!

  • The interrupts are pretty high on Print server. Examined via Xperf and found that the ndis.sys is the highest consumer.

    OS: win2003 SP2 R2 32bit.

    NDIS version : 5.2.3790.3959

    Type : Virtual machine with updated vmtools installed.

    Used procmon and traced network activity – found idle process established a connection to several client machines.

    Examined from manage>Mycomputer sessions and openfiles – users opened \PIPE\spoolss.

    Used another tool pipelist.exe – the highest pipes are used by spools process.

    Can you help me?

  • is there a possibility to monitor disk io for each process ?

    Thanks !