TraceProcessor 0.2.0

TraceProcessor version 0.2.0 is now available on NuGet with the following package ID:

Microsoft.Windows.EventTracing.Processing.All

This release contains minor feature additions and bug fixes since version 0.1.0. (A full changelog is below).

There are a couple of project settings we recommend using with TraceProcessor:

1. We recommend running exes as 64-bit. The Visual Studio default for a new C# console application is Any CPU with Prefer 32-bit checked. Trace processing can be memory-intensive, especially with larger traces, and we recommend changing Platform target to x64 (or unchecking Prefer 32-bit) in exes that use TraceProcessor. To change these settings, see the Build tab under Properties for the project. To change these settings for all configurations, ensure that the Configuration dropdown is set to All Configurations, rather than the default of the current configuration only.
2. We also suggest using NuGet with the newer-style PackageReference mode rather than the older packages.config mode. To change the default for new projects, see Tools, NuGet Package Manager, Package Manager Settings, Package Management, Default package management format.

TraceProcessor supports loading symbols and getting stacks from several data sources. The following console application looks at CPU samples and outputs the estimated duration that a specific function was running (based on the trace’s statistical sampling of CPU usage):

using Microsoft.Windows.EventTracing; 
using Microsoft.Windows.EventTracing.Cpu; 
using Microsoft.Windows.EventTracing.Symbols; 
using System; 
using System.Collections.Generic; 

class Program 
{ 
    static void Main(string[] args) 
    { 
        if (args.Length != 3) 
        { 
            Console.Error.WriteLine("Usage: GetCpuSampleDuration.exe <trace.etl> <imageName> <functionName>"); 
            return; 
        } 

        string tracePath = args[0]; 
        string imageName = args[1]; 
        string functionName = args[2]; 

        Dictionary<string, Duration> matchDurationByCommandLine = new Dictionary<string, Duration>(); 

        using (ITraceProcessor trace = TraceProcessor.Create(tracePath)) 
        { 
            IPendingResult<ISymbolDataSource> pendingSymbolData = trace.UseSymbols(); 
            IPendingResult<ICpuSampleDataSource> pendingCpuSamplingData = trace.UseCpuSamplingData(); 

            trace.Process(); 

            ISymbolDataSource symbolData = pendingSymbolData.Result; 
            ICpuSampleDataSource cpuSamplingData = pendingCpuSamplingData.Result; 

            symbolData.LoadSymbolsForConsoleAsync(SymCachePath.Automatic, SymbolPath.Automatic).GetAwaiter().GetResult(); 
            Console.WriteLine(); 

            IThreadStackPattern pattern = AnalyzerThreadStackPattern.Parse($"{imageName}!{functionName}"); 

            foreach (ICpuSample sample in cpuSamplingData.Samples) 
            { 
                if (sample.Stack != null && sample.Stack.Matches(pattern)) 
                { 
                    string commandLine = sample.Process.CommandLine; 

                    if (!matchDurationByCommandLine.ContainsKey(commandLine)) 
                    { 
                        matchDurationByCommandLine.Add(commandLine, Duration.Zero); 
                    } 
                    matchDurationByCommandLine[commandLine] += sample.Weight; 
                } 
            } 
        } 

        foreach (string commandLine in matchDurationByCommandLine.Keys) 
        { 
            Console.WriteLine($"{commandLine}: {matchDurationByCommandLine[commandLine]}"); 
        } 
    } 
}

Running this program produces output similar to the following:

C:\GetCpuSampleDuration\bin\Debug\> GetCpuSampleDuration.exe C:\boot.etl user32.dll LoadImageInternal
0.0% (0 of 1165; 0 loaded)
<snip>
100.0% (1165 of 1165; 791 loaded)

wininit.exe: 15.99 ms
C:\Windows\Explorer.EXE: 5 ms
winlogon.exe: 20.15 ms
“C:\Users\AdminUAC\AppData\Local\Microsoft\OneDrive\OneDrive.exe” /background: 2.09 ms

(Output details will vary depending on the trace).

Internally, TraceProcessor uses the SymCache format, which is a cache of some of the data stored in a PDB. When loading symbols, TraceProcessor requires specifying a location to use for these SymCache files (a SymCache path) and supports optionally specifying a SymbolPath to access PDBs. When a SymbolPath is provided, TraceProcessor will create SymCache files out of PDB files as needed, and subsequent processing of the same data can use the SymCache files directly for better performance.

The full changelog for version 0.2.0 is as follows:

Breaking Changes

• Multiple Timestamp properties are now TraceTimestamp instead (which implicitly converts to the former Timestamp return type).
• When a trace containing lost events is processed and AllowLostEvents was not set to true, a new TraceLostEventsException is thrown.

New Data Exposed

• ISymbolDataSource now exposes Pdbs. This list contains every PDB that LoadSymbols is capable of loading for the trace.
• IDiskActivity now exposes StorportDriverDiskServiceDuration and IORateData.
• IMappedFileLifetime and IPageFileSectionLifetime now expose CreateStacks and DeleteStacks.
• UseContextSwitchData and trace.UseReadyThreadData are now available individually rather than only as part of trace.UseCpuSchedulingData.
• Last Branch Record (LBR) data has been added and is available via trace.UseLastBranchRecordData.
• EventContext now provides access to original trace timestamp values.
• IEnergyEstimationInterval now exposes ConsumerId.

Bug Fixes

• A NullReferenceException inside of ICpuThreadActivity.WaitingDuration has been fixed.
• An InvalidOperationException inside of Stack Tags has been fixed.
• An InvalidOperationException inside of multiple file and registry path related properties has been fixed.
• A handle leak inside of TraceProcessor.Create has been fixed.
• A hang inside of ISymbolDataSource.LoadSymbolsAsync has been fixed.
• Support for loading local PDB files and transcoding them into symcache files has been fixed.
• Disks that were not mounted when the trace was recorded will now result in an IDisk that will throw on access to most properties instead of returning zeroes. Use the new IDisk.HasData property to check this condition before accessing these properties. This pattern is similar to how IPartition already functions.
• A COMException in IDiskActivityDataSource.GetUsagePercentages has been fixed.

Other

• IImageWeakKey has been deprecated as it can contain inaccurate data. IImage.Timestamp and IImage.Size should be used instead.
• OriginalImageName has been deprecated as it can contain inaccurate data. IImage.OriginalFileName should be used instead.
• Most primitive data types (Timestamp, FrequencyValue, etc) now implement IComparable.
• A new setting, SuppressFirstTimeSetupMessage, has been added to TraceProcessorSettings. When set to true, the message regarding our first time setup process running will be suppressed.
• SymbolPath and SymCachePath now include static helpers for generating commonly used paths.

As before, if you find these packages useful, we would love to hear from you, and we welcome your feedback. For questions using this package, you can post on StackOverflow with the tag .net-traceprocessing, and feedback can also be sent via email to [email protected].