siemens-healthineers/etwanalyzer

Command line tool to analyze one/many ETW file/s with simple queries for common issues.

etwanalyzer's Issues

-LoadSymbol throws 0x806D000C

Describe the bug
When loading symbols from Json File one can get

Exception caught in main: System.Runtime.InteropServices.COMException (0x806D000C): Exception from HRESULT: 0x806D000C
at Dia2Lib.IDiaDataSource3.loadDataFromPdb(String pdbPath)
at Microsoft.Diagnostics.Symbols.SymbolModule.<>c__DisplayClass11_0.<.ctor>b__0(IDiaDataSource3 s) in C:\Builds\Git\ETWAnalyzer\ETWAnalyzer\LoadSymbol\TraceEvent\SymbolModule.cs:line 280
at Microsoft.Diagnostics.Symbols.SymbolModule..ctor(SymbolReader reader, String pdbFilePath, Action`1 loadData) in C:\Builds\Git\ETWAnalyzer\ETWAnalyzer\LoadSymbol\TraceEvent\SymbolModule.cs:line 252
at Microsoft.Diagnostics.Symbols.SymbolModule..ctor(SymbolReader reader, String pdbFilePath) in C:\Builds\Git\ETWAnalyzer\ETWAnalyzer\LoadSymbol\TraceEvent\SymbolModule.cs:line 280

To Reproduce
Load a symbols from a json file with a pdb whose format is ancient.

Expected behavior
No exception

-dump CPU calculates totals

By default ETWAnalyzer should not calculate CPU totals because it makes no sense for method inclusive times.

-Dump process should support filtering for parent process ids

ETWAnalyzer -dump Process should support filtering for multiple parent process ids.

PID: 11688  Start:                         Stop:                         Duration:     RCode:   Parent:  9128 vtm.exe vtm -r cmd
PID: 30968  Start:                         Stop:                         Duration:     RCode:   Parent:  9128 vtm.exe vtm -r cmd
PID: 32772  Start:                         Stop:                         Duration:     RCode:   Parent: 29336 vtm.exe vtm -r cmd
PID: 35864  Start:                         Stop:                         Duration:     RCode:   Parent:  9128 vtm.exe vtm -r cmd

Proposal

Add support for -Parent dd;dd;dd; where the parent process ids are separated like other filters with ;

Documentation

-Parent dd;dd2 Filter for processes which have parent process id dd or dd2. Multiple parent process ids are separated with ;

Considerations

This collides with -ProcessName filter where you filter for specific processes but if you add -processname it is not clear if one would need to extend that filter, or if parent processes should not be affected by -processname filter.
For now we should keep the current logic and filter everything out, but keep in mind that we could want to modify that behavior later.

exception when running etwanalyzer.exe

Describe the bug
exception when running etwanalyzer.exe

D:\WS\EtwAnalysis\CtAnalyzers\bin\Release>ETWAnalyzer.exe -dump CPU -filedir D:\Etw-Extract -debug

Error: Process renaming XML file not found. D:\WS\EtwAnalysis\CtAnalyzers\bin\Release\Configuration\ProcessRenameRules.xml Check D:\WS\EtwAnalysis\CtAnalyzers\bin\Release\ETWAnalyzer_Trace.log for full details, or use -debug switch to get full output.
System.IO.FileNotFoundException: Process renaming XML file not found. D:\WS\EtwAnalysis\CtAnalyzers\bin\Release\Configuration\ProcessRenameRules.xml
   at ETWAnalyzer.Extract.ProcessRenamer.LoadProcessRenamer() in D:\a\ETWAnalyzer\ETWAnalyzer\ETWAnalyzer\Extract\ProcessRenamer\ProcessRenamer.cs:line 49
   at System.Lazy`1.CreateValue()
   at System.Lazy`1.LazyInitValue()
   at ETWAnalyzer.Extract.ETWProcess.get_ProcessNamePretty() in D:\a\ETWAnalyzer\ETWAnalyzer\ETWAnalyzer\Extract\ETWProcess.cs:line 77
   at ETWAnalyzer.Extract.ETWProcess.GetProcessWithId(Boolean usePrettyProcessName) in D:\a\ETWAnalyzer\ETWAnalyzer\ETWAnalyzer\Extract\ETWProcess.cs:line 43
   at ETWAnalyzer.EventDump.DumpFileDirBase`1.IsMatchingProcessAndCmdLine(TestDataFile file, ProcessKey process) in D:\a\ETWAnalyzer\ETWAnalyzer\ETWAnalyzer\EventDump\DumpFileDirBase.cs:line 632
   at ETWAnalyzer.EventDump.DumpCPUMethod.<>c__DisplayClass98_0.<AddAndPrintTotalStats>g__ProcessFilter|0(KeyValuePair`2 procCPU) in D:\a\ETWAnalyzer\ETWAnalyzer\ETWAnalyzer\EventDump\DumpCPUMethod.cs:line 418
   at System.Linq.Enumerable.WhereEnumerableIterator`1.MoveNext()
   at System.Linq.Buffer`1..ctor(IEnumerable`1 source)
   at System.Linq.OrderedEnumerable`1.<GetEnumerator>d__1.MoveNext()
   at System.Linq.Buffer`1..ctor(IEnumerable`1 source)
   at System.Linq.Enumerable.ToArray[TSource](IEnumerable`1 source)
   at ETWAnalyzer.Infrastructure.EnumerableSorterExtensions.SortAscendingGetTopNLast[TData,V](IEnumerable`1 data, Func`2 keyselector, Action`1 sortStatePreparer, SkipTakeRange topN) in D:\a\ETWAnalyzer\ETWAnalyzer\ETWAnalyzer\Infrastructure\EnumerableSorterExtensions.cs:line 41
   at ETWAnalyzer.EventDump.DumpCPUMethod.AddAndPrintTotalStats(List`1 matches, TestDataFile file) in D:\a\ETWAnalyzer\ETWAnalyzer\ETWAnalyzer\EventDump\DumpCPUMethod.cs:line 448
   at ETWAnalyzer.EventDump.DumpCPUMethod.ExecuteInternal() in D:\a\ETWAnalyzer\ETWAnalyzer\ETWAnalyzer\EventDump\DumpCPUMethod.cs:line 235
   at ETWAnalyzer.Commands.DumpCommand.Run() in D:\a\ETWAnalyzer\ETWAnalyzer\ETWAnalyzer\Commands\DumpCommand.cs:line 1769
   at ETWAnalyzer.Program.MainCore(String[] args) in D:\a\ETWAnalyzer\ETWAnalyzer\ETWAnalyzer\Program.cs:line 109
   at ETWAnalyzer.Program.Main(String[] args) in D:\a\ETWAnalyzer\ETWAnalyzer\ETWAnalyzer\Program.cs:line 69

To Reproduce
install etwanalyzer via nuget, run "ETWAnalyzer.exe -dump CPU -filedir D:\Etw-Extract"

Expected behavior
no exception shall happen

Screenshots
n.a.

-Dump Memory does not support -ShowTotal File

Describe the bug
To see the total consumed memory of several etl files one wants to sum up all processes but does not want to print all processes in a long list.

To Reproduce
ETWAnalyzer -dump Memory -fd file1.json -fd file2.json -ShowTotal File

Expected behavior
Only totals per file are printed but not all processes.

-ShowTotal can have 3 modes for -Dump Memory:

• null
• None
• Process (Default)
• Total

All other values for -ShowTotal are invalid and should be reject for -Dump Memory.

Reduce test output

Test output of unit tests is not really readable in Github Actions.
In case of green tests no output should be printed in the best case.
For starters we remove the longest console output from our test.

• ETWAnalyzer\Commands\AnalyzeCommand.cs
  Remove PrintProcessBar method
• ETWAnalyzer\Analyzers\ScreenshotBitmapping\SampleBitmapGenerator.cs
  Remove void Print() method
• ETWAnalyzer\Analyzers\TestCount\TestCountAnalyzer.cs
  Remove public override void Print()
• ETWAnalyzer\Analyzers\TestCount\TestCountAnalyzer.cs
  call public override void Print() only if test is exited with an Exception

Test Failure

Describe the bug

[xUnit.net 00:00:21.60]     ETWAnalyzer_uTest.EventDump.DumpCPUMethodTests.ReadyAverage_Filter [FAIL]
[xUnit.net 00:00:21.60]       System.NullReferenceException : Object reference not set to an instance of an object.
[xUnit.net 00:00:21.60]       Stack Trace:
[xUnit.net 00:00:21.60]         D:\a\ETWAnalyzer\ETWAnalyzer\ETWAnalyzer\EventDump\DumpFileDirBase.cs(553,0): at ETWAnalyzer.EventDump.DumpFileDirBase`1.<>c__DisplayClass111_2.<GetTestRuns>b__3()
[xUnit.net 00:00:21.60]            at System.Lazy`1.ViaFactory(LazyThreadSafetyMode mode)
[xUnit.net 00:00:21.60]            at System.Lazy`1.ExecutionAndPublication(LazyHelper executionAndPublication, Boolean useDefaultConstructor)
[xUnit.net 00:00:21.60]            at System.Lazy`1.CreateValue()
[xUnit.net 00:00:21.60]         D:\a\ETWAnalyzer\ETWAnalyzer\ETWAnalyzer\EventDump\DumpCPUMethod.cs(283,0): at ETWAnalyzer.EventDump.DumpCPUMethod.ExecuteInternal()
[xUnit.net 00:00:21.60]         D:\a\ETWAnalyzer\ETWAnalyzer\ETWAnalyzer\EventDump\DumpBase_T.cs(43,0): at ETWAnalyzer.EventDump.DumpBase`1.Execute()
[xUnit.net 00:00:21.60]         D:\a\ETWAnalyzer\ETWAnalyzer\ETWAnalyzer\Commands\DumpCommand.cs(2248,0): at ETWAnalyzer.Commands.DumpCommand.Run()
[xUnit.net 00:00:21.60]         D:\a\ETWAnalyzer\ETWAnalyzer\ETWAnalyzer_uTest\EventDump\DumpCPUMethodTests.cs(701,0): at ETWAnalyzer_uTest.EventDump.DumpCPUMethodTests.ReadyAverage_Filter()
[xUnit.net 00:00:21.60]            at System.RuntimeMethodHandle.InvokeMethod(Object target, Void** arguments, Signature sig, Boolean isConstructor)
[xUnit.net 00:00:21.60]            at System.Reflection.MethodBaseInvoker.InvokeWithNoArgs(Object obj, BindingFlags invokeAttr)
  Passed ETWAnalyzer_uTest.EventDump.DumpCPUMethodTests.File_TotalSortOrder_Default [< 1 ms]
  Passed ETWAnalyzer_uTest.EventDump.DumpCPUMethodTests.ZeroPoint_ProcessEnd_Shifts_Time_Correctly [2 ms]
  Passed ETWAnalyzer_uTest.EventDump.DumpCPUMethodTests.SortByReadyAverage_IsProperlySorting [2 ms]
  Passed ETWAnalyzer_uTest.EventDump.DumpCPUMethodTests.TotalMode_Total_CPU_MethodLevel [< 1 ms]
  Passed ETWAnalyzer_uTest.EventDump.DumpCPUMethodTests.Process_Summary_CanPrint_ByProcessStartTime [< 1
ms]

To Reproduce
Sporadic during prefetching things. The completedOrNot task array has been resized, but the task
has not been added yet.
completedOrNot[i].Result;
did cause a NullReferencException.

Expected behavior
No NullReferenceException.

ETWAnalyzer.exe -dump version -missingpdb * reports too many PDBs as missing

Describe the bug
ETWAnalyzer.exe -dump version -missingpdb *
reports all pdbs for which no symbols could be located during extraction.

Not all unresolved pdbs are needed to display method names in CPU Sampling/CSWitch data.

Expected behavior
When CPU Sampling/CSwitch data is present only report the pdbs as missing which would lead to unresolved
methods in the output of -Dump CPU ....

IETWExtract.MemoryUsage does not return only read only properties.

IETWExtract.MemoryUsage does not return interfaces.

MemoryStats MemoryUsage { get; }

This should become

IMemoryStats MemoryUsage { get; }

When reading consumers access the IETWExtract interface they should not be able to alter the returned static data. Currently there are objects returned which have public set properties because Json.NET needs them to de/serialize the data to from json files.
The implementing object needs to support both. See other examples how it is done in ETWExtract.cs

MemoryStats should implemement a IMemoryStats interface with

public interface IMemoryStats 
    /// <summary>
    /// Machine wide committed memory in MiB at Trace Start
    /// </summary>
    ulong MachineCommitStartMiB
    {
        get;
    }

    /// <summary>
    /// Machine wide committed memory in MiB at Trace End
    /// </summary>
    ulong MachineCommitEndMiB
    {
        get;
    }

    /// <summary>
    /// MachineCommitEndMiB-MachineCommitStartMiB Calculated property to make it easier to analyze with text processing tools a bunch of Json files without the need to extract and calculate the diff manually
    /// </summary>
    long MachineCommitDiffMiB
    {
        get;
    }

    /// <summary>
    /// Machine wide active memory in MiB at Trace Start
    /// </summary>
    ulong MachineActiveStartMiB
    {
        get;
    }

    /// <summary>
    /// Machine wide active memory in MiB at Trace End
    /// </summary>
    ulong MachineActiveEndMiB
    {
        get;
    }

    /// <summary>
    /// MachineActiveEndMiB-MachineActiveStartMiB Calculated property to make it easier to analyze with text processing tools a bunch of Json files without the need to extract and calculate the diff manually
    /// </summary>
    long MachineActiveDiffMiB
    {
        get;
    }

    /// <summary>
    /// Collection of working sets at ETW trace start
    /// </summary>
    IReadOnlyList<IProcessWorkingSet> WorkingSetsAtStart
    {
        get;set;
    }

    /// <summary>
    /// Collection of working sets at ETW Trace end.
    /// </summary>
    IReadOnlyList<IProcessWorkingSet> WorkingSetsAtEnd
    {
        get;
        set;
    }

ProcessWorkingSet needs to implement IProcessWorkingSet which only supports only read only properties

public interface IProcessWorkingSet 
       /// <summary>
       /// Working Set in MiB = bytes/(1024*1024) rounded to next bigger MiB when greater x.5
       /// </summary>
       ulong WorkingSetInMiB {  get; }

       /// <summary>
       /// Committed memory in MiB  = bytes/(1024*1024) rounded to next bigger MiB when greater x.5
       /// </summary>
       public ulong CommitInMiB  {  get;  }

       /// <summary>
       /// Process private working set in MiB = bytes/(1024*1024) rounded to next bigger MiB when greater x.5
       /// </summary>
       public ulong WorkingsetPrivateInMiB {  get;  }

       /// <summary>
       /// This is the size of file mapping data e.g. Page file or other file mapped data
       /// in MiB = bytes/(1024*1024) rounded to next bigger MiB when greater x.5
       /// </summary>
       public ulong SharedCommitSizeInMiB { get; }

       /// <summary>
       /// Process for which the data was gathered.
       /// </summary>
       public ProcessKey Process { get; }

Concurrent Stacktag Extraction is not supported by TraceProcessing

ETWAnalyzer sometimes hangs when stacktags are concurrently extracted because the underlying data structures used by TraceProcessing are not thread safe. This would result sometimes in stuck ETWAnalyzer calls during extraction which would never terminate.

Remove concurrent extraction.

-Dump Process -ProcessName xx.exe prints more than xx.exe

Describe the bug
ETWAnalyzer -dump Process -pn xx.exe prints also parent processes even if the process name
filter should filter them away. This was added with ETWAnalyzer 2.5.12.0.
This also breaks session ID filtering because parents are not filtered by session id when a filter is applied.

Expected behavior
Only processes which match given query.

Screenshots

Add Dump Command Tests

ETWAnalyzer has currently these dump commmands.

• DumpCPUMethod
• DumpDisk
• DumpDns
• DumpExceptions
• DumpFile
• DumpLBR
• DumpMarks
• DumpMemory
• DumpModuleVersions
• DumpPMC
• DumpProcesses
• DumpStats
• DumpTcp
• DumpThreadPool
• TestRunDumper

In the unit test ETWAnalyzer_uTest\EventDump
have currently only tests for

• DumpBaseTests
• DumpCPUMethodTests
• DumpExceptionTests
• DumpFileDirBaseTests
• DumpMemoryTests
• DumpProcessesTests

We are missing generic dump level tests for

• DumpDisk
• DumpDns
• DumpFile
• DumpLBR
• DumpMarks
• DumpMemory
• DumpModuleVersions
• DumpPMC
• DumpStats
• DumpTcp
• DumpThreadPool
• TestRunDumper

For the high level command parameter parsing we need addtional tests to cover the proper propagation of all passed input arguments.

An example for a specific dump command is

 KeyValuePair<string, MinMaxRange<int>>[] RangeValues = new KeyValuePair<string, MinMaxRange<int>>[]
            {
                new KeyValuePair<string, MinMaxRange<int>>("1", new MinMaxRange<int>(1, int.MaxValue)),
                new KeyValuePair<string, MinMaxRange<int>>("1ms", new MinMaxRange<int>(1, int.MaxValue)),
                new KeyValuePair<string, MinMaxRange<int>>("0.5s", new MinMaxRange<int>(500, int.MaxValue)),
                new KeyValuePair<string, MinMaxRange<int>>("1s-2s", new MinMaxRange<int>(1000, 2000)),
                new KeyValuePair<string, MinMaxRange<int>>("1ms-5000", new MinMaxRange<int>(1, 5000)),
                new KeyValuePair<string, MinMaxRange<int>>("500-1000", new MinMaxRange<int>(500, 1000)),
            };


        [Fact]
        public void CPUMs_Filter()
        {

            foreach (var input in RangeValues)
            {
                var args = new string[] { "-dump", "cpu", "-MinMaxCPUms",input.Key };
                DumpCommand dump = (DumpCommand)CommandFactory.CreateCommand(args);
                dump.Parse();
                dump.Run();
                DumpCPUMethod cpuDumper = (DumpCPUMethod)dump.myCurrentDumper;

                Assert.Equal(input.Value.Min, cpuDumper.MinMaxCPUMs.Min);
                Assert.Equal(input.Value.Max, cpuDumper.MinMaxCPUMs.Max);
            }
        }

to test if the passed units which are now supported at dump command level are properly translated into the filter settings.

Feature: Add CPU timeline data for all processes with a configurable granularity during extraction

Feature Request
Some analysis needs a CPU timeline view which is not possible with aggregated data.

Feature Description
Add during extraction to the CPU extractor an additional option like -timeline xx where xx is the sampling time in s.
Extend the interface

    public interface ICPUStats
    {
        /// <summary>
        /// Simple stat which contains the total CPU in ms per process
        /// </summary>
        IReadOnlyDictionary<ProcessKey, uint> PerProcessCPUConsumptionInMs { get; }

        /// <summary>
        /// Lists all methods which have > 10ms (default) 
        /// </summary>
        ICPUPerProcessMethodList PerProcessMethodCostsInclusive { get; }
    }

with a new Property ICPUTimeLine CPUTimeLine { get; }

Example

ETWAnalyzer -extract CPU -fd xx.etl -symserver ms -timeline 1

-Dump Process should support -Details flag and print and a filter for Session Ids

Processes run in a session which is now also extracted.

-Dump Process should print in -Details mode also the SessionId field.
Also a filter -SessionId 1;2;3;4 should be supported to filter for one or multiple session ids
-Dump Process -SessionId 43 e.g. should print all processes which are running in session 43.

This is useful in container environments where each process isolated container is running in an extra session.

Add summary to -dump Process command

-Dump Process Change

• -Dump Process does currently not print a summary like the other commands
• The output should be controlled like in the other commands with -Showtotal None, File, Total to print
  • None No summary like it is today.
  • File Print a per file summary if multiple files are printed each file will get it summary.
  • Total Print an aggregate across all files additionally to the per file summary line, but omit the printed process list.
  • The new default should be File.

If just one file is printed the global summary can be omitted.

• Summary contents
  • Process Count
  • Session Count
  • Unique User count
  • Number of started/exited/eternal processes

Additionally a -SortBy Session would be nice to sort the process list by session.

Proposed Summary Format
39 Processes, 5 new, 7 exited, 8 permanent in 5 sessions of 3 users.

TCPExtractor: retrans.Connection can be null

foreach (var sent in sentByConnection[retrans.Connection].OrderBy(x => x.Timestamp))

leading to Exception

System.ArgumentNullException: Value cannot be null. (Parameter 'key')
at System.Collections.Generic.Dictionary2.FindValue(TKey key) at System.Collections.Generic.Dictionary2.get_Item(TKey key)
at ETWAnalyzer.Extractors.TCP.TCPExtractor.Extract(ITraceProcessor processor, ETWExtract results) in C:\Source\Git\ETWAnalyzer\ETWAnalyzer\Extractors\TCP\TCPExtractor.cs:line 191
at ETWAnalyzer.Extractors.ExtractSingleFile.Execute(OutDir outputDirectory, Boolean haveToDeleteTemp) in C:\Source\Git\ETWAnalyzer\ETWAnalyzer\Extractors\ExtractSingleFile.cs:line 202
at ETWAnalyzer.Commands.ExtractCommand.ExtractSingleFileInProcess(TestDataFile fileToAnalyze) in C:\Source\Git\ETWAnalyzer\ETWAnalyzer\Commands\ExtractCommand.cs:line 739
at ETWAnalyzer.Commands.ExtractCommand.<>c__DisplayClass97_0.b__2(Int32 i) in C:\Source\Git\ETWAnalyzer\ETWAnalyzer\Commands\ExtractCommand.cs:line 650
at System.Threading.Tasks.Parallel.<>c__DisplayClass19_0`1.b__1(RangeWorker& currentWorker, Int32 timeout, Boolean& replicationDelegateYieldedBeforeCompletion)

-dump Process should support a user name filter -User

Describe the bug
ETWAnalyzer -dump process -ShowUser can display user names but not filter for them.

Expected behavior
A new filter flag is needed to be able to filter for displayed user names.
The flag should be names -User xxxx

-Dump CPU does not show Headers

Since Total support was added the Headers are missing in some cases:

When I add -Showtotal None they show up again. This is confusing:

Add session Filter to other commands

It is useful to select processes not only via name, but also via session ID. All commands which support -ProcessName filter should also support -Session filter to select processes.