From d42806c4e0b124df006cd8b9d28012f5c3761ac5 Mon Sep 17 00:00:00 2001 From: Alois Kraus <101576413+AloisKraus@users.noreply.github.com> Date: Thu, 18 Jul 2024 16:40:42 +0200 Subject: [PATCH] Configurable columns, -TimeDigits and -Console load files (#90) Added -TimeDigits flag to configure with how many digits time is displayed (0-6) Added to -Console option to pass input files on input command line which are directly loaded TCP reset time is now also extracted if socket is closed because other side did not respond. Dump TCP columns are configurable with -column ... option Dump Process columns are configurable with -column ... option --- ETWAnalyzer/Commands/ConsoleCommand.cs | 120 +++++-- ETWAnalyzer/Commands/DumpCommand.cs | 203 ++++++++++-- ETWAnalyzer/Commands/HelpCommand.cs | 2 +- .../Documentation/DumpProcessCommand.md | 2 + ETWAnalyzer/Documentation/DumpTCPCommand.md | 7 +- ETWAnalyzer/ETWAnalyzer.csproj | 2 +- ETWAnalyzer/EventDump/DumpBase.cs | 126 +++++-- ETWAnalyzer/EventDump/DumpExceptions.cs | 2 +- ETWAnalyzer/EventDump/DumpModuleVersions.cs | 2 +- ETWAnalyzer/EventDump/DumpObjectRef.cs | 3 +- ETWAnalyzer/EventDump/DumpProcesses.cs | 247 +++++++++++--- ETWAnalyzer/EventDump/DumpTcp.cs | 308 +++++++++++++++--- .../Extract/Network/Tcp/ITcpConnection.cs | 15 + .../Extract/Network/Tcp/TcpConnection.cs | 30 +- ETWAnalyzer/Extractors/TCP/TCPExtractor.cs | 44 ++- .../TCP/TcpDisconnectTcbRtoTimeout.cs | 38 +++ .../Extractors/TCP/TcpRequestConnect.cs | 8 +- .../Infrastructure/ColumnDefinition.cs | 57 ++++ ETWAnalyzer/Infrastructure/ColumnFormatter.cs | 5 +- .../Infrastructure/MultilineFormatter.cs | 178 ++++++++++ ETWAnalyzer/Properties/AssemblyInfo.cs | 2 +- .../TraceProcessorHelpers/TcpETWConstants.cs | 5 + ETWAnalyzer_uTest/EventDump/DumpBaseTests.cs | 4 +- .../EventDump/DumpProcessesTests.cs | 48 +-- .../Extract/TcpExtractorTests.cs | 10 +- .../Infrastructure/MultilineFormatterTests.cs | 296 +++++++++++++++++ 26 files changed, 1539 insertions(+), 225 deletions(-) create mode 100644 ETWAnalyzer/Extractors/TCP/TcpDisconnectTcbRtoTimeout.cs create mode 100644 ETWAnalyzer/Infrastructure/ColumnDefinition.cs create mode 100644 ETWAnalyzer/Infrastructure/MultilineFormatter.cs create mode 100644 ETWAnalyzer_uTest/Infrastructure/MultilineFormatterTests.cs diff --git a/ETWAnalyzer/Commands/ConsoleCommand.cs b/ETWAnalyzer/Commands/ConsoleCommand.cs index 673d664a..8203d622 100644 --- a/ETWAnalyzer/Commands/ConsoleCommand.cs +++ b/ETWAnalyzer/Commands/ConsoleCommand.cs @@ -4,11 +4,8 @@ using ETWAnalyzer.Extract; using ETWAnalyzer.Infrastructure; using ETWAnalyzer.ProcessTools; -using Microsoft.Diagnostics.Tracing.Parsers.Kernel; using System; using System.Collections.Generic; -using System.Data; -using System.IO; using System.Linq; using System.Text; @@ -21,28 +18,44 @@ internal class ConsoleCommand : ArgParser { public override string Help => ""; + string TimeFormatString = null; + string TimeDigitString = null; + string ProcessFmt = null; + + bool ShowFullFileNameFlag { get; set; } + /// + /// Currently loaded files + /// + Lazy[] myInputFiles; + class ConsoleHelpCommand : ArgParser { public override string Help => - ".cls "+ Environment.NewLine + + ".cls"+ Environment.NewLine + " Clear screen." + Environment.NewLine + - $".dump xxx [ -fd *usecase1* ] " + Environment.NewLine + + $".dump xxx [ -fd *usecase1* ]" + Environment.NewLine + " Query loaded file/s. Options are the same as in -Dump command. e.g. .dump CPU will print CPU metrics." + Environment.NewLine + " -fd *filter* Filter loaded files which are queried. Filter is applied to full path file name." + Environment.NewLine + $" Allowed values are {DumpCommand.AllDumpCommands}" + Environment.NewLine + - ".load [-all] file1.json file2.json ... " + Environment.NewLine + + ".load [-all] file1.json file2.json .." + Environment.NewLine + " -all Fully load all json files during load. By default the files are fully loaded during the dump command." + Environment.NewLine + " Load one or more data files. Use . to load all files in current directory. Previously loaded files are removed." + Environment.NewLine + - ".load+ file.json " + Environment.NewLine + + ".load+ file.json" + Environment.NewLine + " Add file to list of loaded files but keep other files." + Environment.NewLine + - ".list " + Environment.NewLine + + ".list" + Environment.NewLine + " List loaded files" + Environment.NewLine + - ".quit or .q "+Environment.NewLine + + ".processfmt timefmt" + Environment.NewLine + + " Display for process start/end marker not +- but actual time and duration." + Environment.NewLine + + ".quit or .q"+Environment.NewLine + " Quit ETWAnalyzer" + Environment.NewLine + - ".unload "+Environment.NewLine + + ".unload"+Environment.NewLine + " Unload all files if no parameter is passed. Otherwise only the passed files are unloaded from the file list." + Environment.NewLine + - ".sffn " +Environment.NewLine + + ".sffn" +Environment.NewLine + " Enable/disable -ShowFullFileName to display full path of output files." + Environment.NewLine + + ".timedigits n" + Environment.NewLine + + " Set time precision (0-6)." + Environment.NewLine + + ".timefmt fmt [precision]" + Environment.NewLine + + $" Set time display format ({String.Join(" ", Enum.GetNames(typeof(EventDump.DumpBase.TimeFormats)).Where(x=>x!="None"))}) and precision (0-6) where default is 3." + Environment.NewLine + "Pressing Ctrl-C will cancel current command, Ctrl-Break will terminate"; public override void Parse() @@ -58,11 +71,6 @@ public ConsoleHelpCommand(string[] args) : base(args) { } } - /// - /// Currently loaded files - /// - Lazy[] myInputFiles; - public override void Run() { @@ -92,8 +100,6 @@ public override void Run() } } - bool ShowFullFileNameFlag { get; set; } - /// /// Command syntax is first string is command name and all following arguments are arguments for that command like in the command line /// @@ -112,7 +118,10 @@ bool RunCommand(string[] parts) ".dump" => CreateDumpCommand(args), ".exit" => new QuitCommand(args), ".list" => ListFiles(args), + ".processfmt" => SetProcessFmt(args), ".sffn" => ShowFullFileName(args), + ".timedigits" => SetTimeDigits(args), + ".timefmt" => SetTimeFormat(args), ".quit" => new QuitCommand(args), ".q" => new QuitCommand(args), "q" => new QuitCommand(args), @@ -176,6 +185,51 @@ ICommand ShowFullFileName(string[] args) return lret; } + private ICommand SetTimeDigits(string[] args) + { + ICommand lret = null; + TimeDigitString = null; + + if (args.Length > 0) + { + TimeDigitString = args[0]; + } + return lret; + } + + private ICommand SetTimeFormat(string[] args) + { + ICommand lret = null; + TimeFormatString = null; + TimeDigitString = null; + + if ( args.Length > 1 ) + { + TimeFormatString = args[0]; + + if( args.Length > 1 ) + { + TimeDigitString = args[1]; + } + } + return lret; + } + + + private ICommand SetProcessFmt(string[] args) + { + ICommand lret = null; + ProcessFmt = null; + + if (args.Length > 0) + { + ProcessFmt = args[0]; + } + + return lret; + } + + /// /// /// @@ -203,7 +257,7 @@ ICommand ListFiles(string[] args) return lret; } - + /// /// Create dump command from filtered list of arguments. /// @@ -212,7 +266,26 @@ ICommand ListFiles(string[] args) DumpCommand CreateDumpCommand(string[] args) { var argsAndTests = ApplyFileDirFilter(args); - return new DumpCommand(argsAndTests.Item1, argsAndTests.Item2) + List filteredArgs = argsAndTests.Item1.ToList(); + if( this.TimeDigitString != null ) + { + filteredArgs.Add("-TimeDigits"); + filteredArgs.Add(TimeDigitString); + } + + if( this.TimeFormatString != null ) + { + filteredArgs.Add("-TimeFmt"); + filteredArgs.Add(TimeFormatString); + } + + if (ProcessFmt != null) + { + filteredArgs.Add("-ProcessFmt"); + filteredArgs.Add(ProcessFmt); + } + + return new DumpCommand(filteredArgs.ToArray(), argsAndTests.Item2) { ShowFullFileName = ShowFullFileNameFlag, }; @@ -420,7 +493,12 @@ public override void Parse() /// public ConsoleCommand(string[] args) : base(args) { - + // skip -console argument and treat rest as input file names + string[] fileCandidates = args.Skip(1).Where(x => x.ToLowerInvariant() != "-fd").ToArray(); + if( fileCandidates.Length > 0 ) + { + Load(fileCandidates, false); + } } diff --git a/ETWAnalyzer/Commands/DumpCommand.cs b/ETWAnalyzer/Commands/DumpCommand.cs index 58a84cda..f0f37a0e 100644 --- a/ETWAnalyzer/Commands/DumpCommand.cs +++ b/ETWAnalyzer/Commands/DumpCommand.cs @@ -1,25 +1,18 @@ //// SPDX-FileCopyrightText: © 2022 Siemens Healthcare GmbH //// SPDX-License-Identifier: MIT -using ETWAnalyzer.Infrastructure; using ETWAnalyzer.EventDump; using ETWAnalyzer.Extract; +using ETWAnalyzer.Infrastructure; using ETWAnalyzer.ProcessTools; +using ETWAnalyzer.TraceProcessorHelpers; using System; using System.Collections.Generic; using System.Globalization; using System.IO; using System.Linq; -using static ETWAnalyzer.Extract.ETWProcess; -using ETWAnalyzer.TraceProcessorHelpers; -using Microsoft.Windows.EventTracing.Metadata; -using System.Drawing; -using System.Numerics; -using System.Reflection.Emit; -using System.Reflection; -using System.Runtime.InteropServices; using System.Threading; -using Microsoft.Diagnostics.Tracing; +using static ETWAnalyzer.Extract.ETWProcess; namespace ETWAnalyzer.Commands { @@ -58,7 +51,7 @@ class DumpCommand : ArgParser " -VersionFilter filter Filter against module path and version strings. Multiple filters are separated by ;. Wildcards are * and ?. Exclusion filters start with !" + Environment.NewLine + " -ModuleFilter filter Extracted data from Config\\DllToBuildMapping.json. Print only version information for module. Multiple filters are separated by ;. Wildcards are * and ?. Exclusion filters start with !" + Environment.NewLine; static readonly string ProcessHelpStringHeader = - " Process -filedir/fd x.etl/.json7z [-recursive] [-csv xx.csv] [-NoCSVSeparator] [-TimeFmt s,Local,LocalTime,UTC,UTCTime,Here,HereTime] [-ProcessName/pn xx.exe(pid)] [-Parent xx.exe(pid)]" + Environment.NewLine + + " Process -filedir/fd x.etl/.json7z [-recursive] [-csv xx.csv] [-NoCSVSeparator] [-TimeFmt s,Local,LocalTime,UTC,UTCTime,Here,HereTime] [-TimeDigits d] [-Column xx;yy] [-ProcessName/pn xx.exe(pid)] [-Parent xx.exe(pid)]" + Environment.NewLine + " [-CmdLine *xx*] [-Crash] [-ShowUser] [-Session dd] [-User abc] [-SortBy Tree/Time/StopTime/Default] [-ZeroTime/zt Marker/First/Last/ProcessStart filter] [-ZeroProcessName/zpn filter]" + Environment.NewLine + " [-NewProcess 0/1/-1/-2/2] [-PlainProcessNames] [-MinMaxStart xx-yy] [-ShowFileOnLine] [-ShowAllProcesses] [-NoCmdLine] [-Details] [-Clip] [-TestsPerRun dd -SkipNTests dd] " + Environment.NewLine + " [-TestRunIndex dd -TestRunCount dd] [-MinMaxMsTestTimes xx-yy ...] [-ShowFullFileName/-sffn]" + Environment.NewLine; @@ -84,6 +77,10 @@ class DumpCommand : ArgParser " UTCTime Same as UTC but without date string." + Environment.NewLine + " Here Print time as local time in the current system time zone." + Environment.NewLine + " HereTime Same as Here but without date string." + Environment.NewLine + + " -TimeDigits d By default time is formatted with ms (= 3 digits) precision. Supported values are from 0-6." + Environment.NewLine + + " -Column xx;yy Enable/disable specific columns which are printed, or exclude them by prepending them with !. E.g. -column !Duration;!Parentpid;!process will exclude these columns from " + Environment.NewLine + + $" the default enabled columns. Valid column names are {String.Join(";", DumpProcesses.ColumnNames.Take(7))}" + Environment.NewLine + + $" {String.Join(";", DumpProcesses.ColumnNames.Skip(7))}" + Environment.NewLine + " -ProcessName/pn x;y.exe Filter by process name or process id. Exclusion filters start with !, Multiple filters are separated by ;" + Environment.NewLine + " E.g. cmd;!1234 will filter for all cmd.exe instances excluding cmd.exe(1234). The wildcards * and ? are supported for all filter strings." + Environment.NewLine + " -Parent x;y.exe Same as -ProcessName but it will filter for parent process names/ids. Useful with -SortBy Tree to show child processes of specific parent processes as process tree." + Environment.NewLine + @@ -199,7 +196,7 @@ class DumpCommand : ArgParser " [-ShowFullFileName] refer to help of TestRun and Process. Run \'EtwAnalyzer -help dump\' to get more infos." + Environment.NewLine; static readonly string MemoryHelpStringHeader = - " Memory -filedir/fd Extract\\ or xx.json7z [-recursive] [-csv xx.csv] [-NoCSVSeparator] [-TopN dd nn] [-TimeFmt s,Local,LocalTime,UTC,UTCTime,Here,HereTime] [-ProcessFmt timefmt] [-TotalMemory] [-MinDiffMB dd] " + Environment.NewLine + + " Memory -filedir/fd Extract\\ or xx.json7z [-recursive] [-csv xx.csv] [-NoCSVSeparator] [-TopN dd nn] [-TimeFmt s,Local,LocalTime,UTC,UTCTime,Here,HereTime] [-TimeDigits d] [-ProcessFmt timefmt] [-TotalMemory] [-MinDiffMB dd] " + Environment.NewLine + " [-SortBy Commit/WorkingSet/SharedCommit/Diff] [-GlobalDiffMB dd] [-MinMaxWorkingSetMiB xx-yy] [-MinMaxWorkingSetPrivateMiB xx-yy] [-MinMaxCommitMiB xx-yy] [-MinMaxSharedCommitMiB xx-yy] [-Clip] [-NoCmdLine] [-Details] " + Environment.NewLine + " [-TestsPerRun dd -SkipNTests dd] [-TestRunIndex dd -TestRunCount dd] [-MinMaxMsTestTimes xx-yy ...] [-ProcessName/pn xx.exe(pid)] [-NewProcess 0/1/-1/-2/2] [-PlainProcessNames] [-CmdLine substring]" + Environment.NewLine + " [-ShowFullFileName/-sffn] [-ShowModuleInfo [Driver] or [filter]] [-ShowTotal [File,None]] [-ProcessFmt timefmt] "+ Environment.NewLine; @@ -223,7 +220,7 @@ class DumpCommand : ArgParser " [-ShowFullFileName] refer to help of TestRun, Process and CPU (-ProcessFmt, -ShowModuleInfo). Run \'EtwAnalyzer -help dump\' to get more infos." + Environment.NewLine; static readonly string ExceptionHelpStringHeader = " Exception -filedir/fd Extract\\ or xx.json7z [-Type xx] [-Message xx] [-Showstack] [-MaxMessage dd] [-CutStack dd-yy] [-Stackfilter xx] [-recursive] [-csv xx.csv] [-NoCSVSeparator] " + Environment.NewLine + - " [-TimeFmt s,Local,LocalTime,UTC,UTCTime,Here,HereTime] [-ProcessFmt timefmt] [-NoCmdLine] [-Clip] [-TestsPerRun dd -SkipNTests dd] [-TestRunIndex dd -TestRunCount dd] [-MinMaxMsTestTimes xx-yy ...]" + Environment.NewLine + + " [-TimeFmt s,Local,LocalTime,UTC,UTCTime,Here,HereTime] [-TimeDigits d] [-ProcessFmt timefmt] [-NoCmdLine] [-Clip] [-TestsPerRun dd -SkipNTests dd] [-TestRunIndex dd -TestRunCount dd] [-MinMaxMsTestTimes xx-yy ...]" + Environment.NewLine + " [-MinMaxExTime minS [maxS]] [-ZeroTime/zt Marker/First/Last/ProcessStart filter] [-ZeroProcessName/zpn filter]" + Environment.NewLine + " [-ProcessName/pn xx.exe(pid)] [-NewProcess 0/1/-1/-2/2] [-PlainProcessNames] [-CmdLine substring]" + Environment.NewLine + " [-ShowFullFileName/-sffn] [-ShowModuleInfo [filter]] [-Details]" + Environment.NewLine; @@ -251,7 +248,7 @@ class DumpCommand : ArgParser static readonly string DiskHelpStringHeader = " Disk -filedir/fd Extract\\ or xx.json7z [-DirLevel dd] [-PerProcess] [-filename *C:*] [-MinMax[Read/Write/Total][Size/Time] xx-yy] [-TopN dd nn] [-SortBy order] [-FileOperation op] [-ReverseFileName/rfn] [-Merge] [-recursive] [-csv xx.csv] [-NoCSVSeparator]" + Environment.NewLine + - " [-TopNProcesses dd nn] [-TimeFmt s,Local,LocalTime,UTC,UTCTime,Here,HereTime] [-Clip] [-TestsPerRun dd - SkipNTests dd] [-TestRunIndex dd - TestRunCount dd] [-MinMaxMsTestTimes xx-yy ...] [-ProcessName/pn xx.exe(pid)]" + Environment.NewLine + + " [-TopNProcesses dd nn] [-TimeFmt s,Local,LocalTime,UTC,UTCTime,Here,HereTime] [-TimeDigits d] [-Clip] [-TestsPerRun dd - SkipNTests dd] [-TestRunIndex dd - TestRunCount dd] [-MinMaxMsTestTimes xx-yy ...] [-ProcessName/pn xx.exe(pid)]" + Environment.NewLine + " [-NewProcess 0/1/-1/-2/2] [-PlainProcessNames] [-CmdLine substring]" + Environment.NewLine + " [-ShowFullFileName/-sffn]" + Environment.NewLine; static readonly string DiskHelpString = DiskHelpStringHeader + @@ -274,7 +271,7 @@ class DumpCommand : ArgParser static readonly string FileHelpStringHeader = " File -filedir/fd Extract\\ or xx.json7z [-DirLevel dd] [-PerProcess] [-filename *C:*] [-ShowTotal [Total/Process/File/None]] [-TopN dd nn] [-SortBy order] [-FileOperation op] [-ReverseFileName/rfn] [-Merge] [-Details] [-recursive] " + Environment.NewLine + - " [-TopNProcesses dd nn] [-csv xx.csv] [-NoCSVSeparator] [-TimeFmt s,Local,LocalTime,UTC,UTCTime,Here,HereTime] [-ProcessFmt timefmt] [-Clip] [-TestsPerRun dd -SkipNTests dd] " + Environment.NewLine + + " [-TopNProcesses dd nn] [-csv xx.csv] [-NoCSVSeparator] [-TimeFmt s,Local,LocalTime,UTC,UTCTime,Here,HereTime] [-TimeDigits d] [-ProcessFmt timefmt] [-Clip] [-TestsPerRun dd -SkipNTests dd] " + Environment.NewLine + " [-TestRunIndex dd -TestRunCount dd] [-MinMaxMsTestTimes xx-yy ...] [-ProcessName/pn xx.exe(pid)] [-NoCmdLine] [-NewProcess 0/1/-1/-2/2] [-PlainProcessNames] [-CmdLine substring]" + Environment.NewLine + " [-ShowFullFileName/-sffn] [-MinMax[Read/Write/Total][Size/Time] xx-yy] [-MinMaxTotalCount xx-yy] [-ShowModuleInfo [filter]]" + Environment.NewLine; static readonly string FileHelpString = FileHelpStringHeader + @@ -311,7 +308,7 @@ class DumpCommand : ArgParser ""; static readonly string ThreadPoolHelpStringHeader = - " ThreadPool -filedir/fd Extract\\ or xx.json7z [-TimeFmt s,Local,LocalTime,UTC,UTCTime,Here,HereTime] [-recursive] [-csv xx.csv] [-NoCSVSeparator] [-NoCmdLine] [-Clip] " + Environment.NewLine + + " ThreadPool -filedir/fd Extract\\ or xx.json7z [-TimeFmt s,Local,LocalTime,UTC,UTCTime,Here,HereTime] [-TimeDigits d] [-recursive] [-csv xx.csv] [-NoCSVSeparator] [-NoCmdLine] [-Clip] " + Environment.NewLine + " [-TestsPerRun dd - SkipNTests dd][-TestRunIndex dd - TestRunCount dd] [-MinMaxMsTestTimes xx-yy ...] [-ProcessName / pn xxx; yyy] [-NewProcess 0/1/-1/-2/2] [-PlainProcessNames] [-CmdLine substring]" + Environment.NewLine; static readonly string ThreadPoolHelpString = ThreadPoolHelpStringHeader + " Print Threadpool Starvation incidents. To get output -extract ThreadPoool or All must have been used during extraction. " + Environment.NewLine + @@ -319,7 +316,7 @@ class DumpCommand : ArgParser " -NoCmdLine Do not print command line arguments in process name at console output" + Environment.NewLine; static readonly string MarkHelpStringHeader = - " Mark -filedir/fd Extract\\ or xx.json7z [-MarkerFilter xx] [-ZeroTime marker filter] [-MinMaxMarkDiffTime min [max]] [-recursive] [-csv xx.csv] [-NoCSVSeparator] [-TimeFmt s,Local,LocalTime,UTC,UTCTime,Here,HereTime] [-NoCmdLine] [-Clip] " + Environment.NewLine + + " Mark -filedir/fd Extract\\ or xx.json7z [-MarkerFilter xx] [-ZeroTime marker filter] [-MinMaxMarkDiffTime min [max]] [-recursive] [-csv xx.csv] [-NoCSVSeparator] [-TimeFmt s,Local,LocalTime,UTC,UTCTime,Here,HereTime] [-TimeDigits d] [-NoCmdLine] [-Clip] " + Environment.NewLine + " [-TestsPerRun dd -SkipNTests dd] [-TestRunIndex dd -TestRunCount dd] [-MinMaxMsTestTimes xx-yy ...] [-ProcessName/pn xx.exe(pid)] [-NewProcess 0/1/-1/-2/2] [-PlainProcessNames] [-CmdLine substring]" + Environment.NewLine; static readonly string MarkHelpString = MarkHelpStringHeader + " Print ETW Marker events" + Environment.NewLine + @@ -351,7 +348,7 @@ class DumpCommand : ArgParser static readonly string DnsHelpStringHeader = " Dns -filedir/fd Extract\\ or xx.json7z [-DnsQueryFilter xx] [-Details] [-ShowProcess] [-ShowAdapter] [-ShowReturnCode] [-TopN dd nn] [-TopNDetails dd nn] [-SortBy Time/Count] [-MinMaxTotalTimeMs min [max]] [-MinMaxTimeMs min [max]] [-recursive] " + Environment.NewLine + - " [-TimeFmt s,Local,LocalTime,UTC,UTCTime,Here,HereTime] [-csv xx.csv] [-NoCSVSeparator] [-NoCmdLine] [-Clip] [-TestsPerRun dd -SkipNTests dd] [-TestRunIndex dd -TestRunCount dd] [-MinMaxMsTestTimes xx-yy ...] [-ProcessName/pn xx.exe(pid)] " + Environment.NewLine + + " [-TimeFmt s,Local,LocalTime,UTC,UTCTime,Here,HereTime] [-TimeDigits d] [-csv xx.csv] [-NoCSVSeparator] [-NoCmdLine] [-Clip] [-TestsPerRun dd -SkipNTests dd] [-TestRunIndex dd -TestRunCount dd] [-MinMaxMsTestTimes xx-yy ...] [-ProcessName/pn xx.exe(pid)] " + Environment.NewLine + " [-NewProcess 0/1/-1/-2/2] [-PlainProcessNames] [-CmdLine substring]" + Environment.NewLine; static readonly string DnsHelpString = DnsHelpStringHeader + " Print Dns summary and delay metrics. To see data you need to enable the Microsoft-Windows-DNS-Client ETW provider" + Environment.NewLine + @@ -367,11 +364,12 @@ class DumpCommand : ArgParser " -DnsQueryFilter xx Filter by host name. Multiple filters are separated by ;" + Environment.NewLine; static readonly string TcpHelpStringHeader = - " Tcp -filedir/fd Extract\\ or xx.json7z [-IpPort xx] [-ShowRetransmits] [-TopN dd nn] [-SortBy ReceivedCount/SentCount/ReceivedSize/SentSize/TotalCount/TotalSize/ConnectTime/DisconnectTime/RetransmissionCount/RetransmissionTime/MaxRetransmissionTime] " + Environment.NewLine + + " Tcp -filedir/fd Extract\\ or xx.json7z [-IpPort xx] [-ShowRetransmits] [-TopN dd nn] [-SortBy ReceivedCount/SentCount/ReceivedSize/SentSize/TotalCount/TotalSize/ConnectTime/DisconnectTime/RetransmissionCount/RetransmissionTime/MaxRetransmissionTime] " + Environment.NewLine + " [-SortRetransmitBy Delay/Time] [-MinMaxRetransDelayMs xx-yy] [-MinMaxRetransBytes xx-yy] [-MinMaxRetransCount xx-yy] [-MinMaxSentBytes xx-yy] [-MinMaxReceivedBytes xx-yy] [-TopNRetrans dd nn] [-OnlyClientRetransmit] [-Details] [-Tcb 0xdddddd] " + Environment.NewLine + - " [-TimeFmt s,Local,LocalTime,UTC,UTCTime,Here,HereTime] [-csv xx.csv] [-NoCSVSeparator] [-NoCmdLine] [-Clip] [-TestsPerRun dd -SkipNTests dd] [-TestRunIndex dd -TestRunCount dd] [-MinMaxMsTestTimes xx-yy ...] [-ProcessName/pn xx.exe(pid)] " + Environment.NewLine + + " [-Column xx;yy] [-Reset] [-MinMaxConnect xx yy] [-MinMaxDisconnect xx zz]" + Environment.NewLine + + " [-TimeFmt s,Local,LocalTime,UTC,UTCTime,Here,HereTime] [-TimeDigits d] [-csv xx.csv] [-NoCSVSeparator] [-NoCmdLine] [-Clip] [-TestsPerRun dd -SkipNTests dd] [-TestRunIndex dd -TestRunCount dd] [-MinMaxMsTestTimes xx-yy ...] [-ProcessName/pn xx.exe(pid)] " + Environment.NewLine + " [-NewProcess 0/1/-1/-2/2] [-PlainProcessNames] [-CmdLine substring] [-recursive] [-ZeroTime/zt Marker/First/Last/ProcessStart filter] [-ZeroProcessName/zpn filter] [-ShowTotal [File/None]] [-ProcessFmt timefmt] " + Environment.NewLine; - static readonly string TcpHelpString = TcpHelpStringHeader + + static readonly string TcpHelpString = TcpHelpStringHeader + " Print TCP summary and retransmit metrics. To see data you need to enable the Microsoft-Windows-TCPIP ETW provider. Data is sorted by retransmission count by default." + Environment.NewLine + " It can detect send retransmissions and duplicate received packets which show up as client retransmission events." + Environment.NewLine + " -IpPort xx Filter for substrings in source/destination IP and port." + Environment.NewLine + @@ -379,10 +377,16 @@ class DumpCommand : ArgParser " -TopN dd nn Show top n connection by current sort order" + Environment.NewLine + " -TopNRetrans dd nn Show top n retransmission events when -ShowRetransmit is used" + Environment.NewLine + " -SortBy [...] Default sort order is total bytes. Valid sort orders are ReceivedCount/SentCount/ReceivedSize/SentSize/TotalCount/TotalSize/ConnectTime/DisconnectTime/RetransmissionCount/RetransmissionTime/MaxRetransmissionTime" + Environment.NewLine + - " Sort applies to totals per connection. RetransmissionTime is the sum of all Delays. MaxRetransmissionTime sorts connections by highest max retransmission delay." + Environment.NewLine + - " -SortRetransmitBy [...] When -ShowRetransmit is used the events are sorted by Time. Valid values are Time/Delay" + Environment.NewLine + - " -ShowRetransmit Show single retransmission events with timing data. Use -timefmt s to convert time to WPA time. Use this or -Details to get all events into a csv file." + Environment.NewLine + - " -OnlyClientRetransmit Only show client retransmissions which are visible by duplicate received packets with a payload > 1 bytes." + Environment.NewLine + + " Sort applies to totals per connection. RetransmissionTime is the sum of all Delays. MaxRetransmissionTime sorts connections by highest max retransmission delay." + Environment.NewLine + + " -Column xx;yy Enable specific columns which are printed or exclude them by prepending them with !. Column wildards are supported. E.g. -column !Retrans* will hide all columns which start with Retrans in their name." + Environment.NewLine + + $" Valid column names are {String.Join(";", DumpTcp.ColumnNames.Take(10))}" + Environment.NewLine + + $" {String.Join(";", DumpTcp.ColumnNames.Skip(10))}" + Environment.NewLine + + " -SortRetransmitBy [...] When -ShowRetransmit is used the events are sorted by Time. Valid values are Time/Delay" + Environment.NewLine + + " -ShowRetransmit Show single retransmission events with timing data. Use -timefmt s to convert time to WPA time. Use this or -Details to get all events into a csv file." + Environment.NewLine + + " -OnlyClientRetransmit Only show client retransmissions which are visible by duplicate received packets with a payload > 1 bytes." + Environment.NewLine + + " -Reset Filter for connections which were reset by us due to connection establishment/send timeouts." + Environment.NewLine + + " -MinMaxConnect xx yy Connect time filter in ETW session time in seconds." + Environment.NewLine + + " -MinMaxDisconnect xx yy Disconnect time filter in ETW session time in seconds." + Environment.NewLine + " -MinMaxRetransDelayMs xx-yy Filter by retransmission delay in ms. By default all retransmissions are shown." + Environment.NewLine + " -MinMaxRetransBytes xx-yy Filter every retransmission event by retransmission size (sent/received) in bytes. Default is > 1 bytes because 0 and 1 byte packets are often just ACKs or timer based ping packets." + Environment.NewLine + " -MinMaxRetransCount xx-yy Show only connections which have at least xx retransmission events" + Environment.NewLine + @@ -395,7 +399,7 @@ class DumpCommand : ArgParser static readonly string ObjectRefHelpStringHeader = " ObjectRef -filedir/fd Extract\\ or xx.json7z" + Environment.NewLine + - " [-TimeFmt s,Local,LocalTime,UTC,UTCTime,Here,HereTime] [-csv xx.csv] [-NoCSVSeparator] [-NoCmdLine] [-Clip] [-TestsPerRun dd -SkipNTests dd] [-TestRunIndex dd -TestRunCount dd] [-MinMaxMsTestTimes xx-yy ...] [-ProcessName/pn xx.exe(pid)] " + Environment.NewLine + + " [-TimeFmt s,Local,LocalTime,UTC,UTCTime,Here,HereTime] [-TimeDigits d] [-csv xx.csv] [-NoCSVSeparator] [-NoCmdLine] [-Clip] [-TestsPerRun dd -SkipNTests dd] [-TestRunIndex dd -TestRunCount dd] [-MinMaxMsTestTimes xx-yy ...] [-ProcessName/pn xx.exe(pid)] " + Environment.NewLine + " [-RelatedProcess xx.exe(pid)] [-MinMaxDuration minS [maxS]] [-MinMaxId min [max]] [-CreateStack filter] [-DestroyStack filter] [-StackFilter filter] [-Object filter] [-ObjectName filter] [-Handle filter] [-ShowRef]" + Environment.NewLine + " [-ShowStack] [-Type filter] [-Leak] [-MultiProcess] [-Map [0,1]] [-PtrInMap 0x...] [-MinMaxMapSize min [max]] [-MinMaxTime min [max]] [-Overlapped] [-Showtotal Total,File,None]" + Environment.NewLine + " [-NewProcess 0/1/-1/-2/2] [-PlainProcessNames] [-CmdLine substring]" + Environment.NewLine; @@ -465,7 +469,12 @@ class DumpCommand : ArgParser "[green]Dump processes and user names abc and xyz.[/green]" + Environment.NewLine + " ETWAnalyzer -dump Process -fd xx.etl/.json7z -details" + Environment.NewLine + "[green]Dump processes as process tree where the parent process was cmd.exe and show process start/stop times as ETW trace session times in seconds.[/green]" + Environment.NewLine + - " ETWAnalyzer -dump Process -fd xx.etl/.json7z -sortby tree -parent cmd -timefmt s"; + " ETWAnalyzer -dump Process -fd xx.etl/.json7z -sortby tree -parent cmd -timefmt s" + Environment.NewLine + + "[green]Explicitly configure the displayed columns. Print start/stop/duration with ms precision.[/green]" + Environment.NewLine + + " ETWAnalyzer -dump Process -fd xx.etl/.json7z .dump process -timefmt s -timedigits 3 -column ProcessId;StartTime;StopTime;CommandLine" + ; + + static readonly string TestRunExamples = ExamplesHelpString + @@ -630,6 +639,8 @@ class DumpCommand : ArgParser " ETWAnalyzer -fd xx.json7z -dump Tcp -ShowRetransmit -csv Retransmissions.csv" + Environment.NewLine + "[green]Dump all TCP connections with duration ranging from 0-10s.[/green]" + Environment.NewLine + " ETWAnalyzer -fd xx.json7z -dump Tcp -MinMaxConnectionDurationS 0 10s" + Environment.NewLine + + "[green]Dump all connections which were reset because no connection could be made. Remove specific columns from output.[/green]" + Environment.NewLine + + " ETWAnalyzer -fd xx.json7z -dump Tcp -Reset -MinMaxReceivedBytes 0-0 -Column !*Bytes;!Template;!Retrans*;!TCB;!LastReceiveTime -Details -Timefmt s" + Environment.NewLine + "[green]Dump all all client retransmission events sorted by delay and omit connections which have no retransmissions in output.[/green]" + Environment.NewLine + " ETWAnalyzer -fd xx.json7z -dump Tcp -OnlyClientRetransmit -MinMaxRetransCount 1 -ShowRetransmit -SortRetransmitBy Delay" + Environment.NewLine ; @@ -794,6 +805,8 @@ internal enum ZeroTimeModes } + public Dictionary ColumnConfiguration { get; private set; } = new(StringComparer.OrdinalIgnoreCase); + SearchOption mySearchOption = SearchOption.TopDirectoryOnly; public Func ProcessNameFilter { get; private set; } = _ => true; @@ -827,6 +840,11 @@ internal enum ZeroTimeModes /// public DumpBase.TimeFormats TimeFormat { get; private set; } + /// + /// Overriden time precision. Default is 3. + /// + public int? TimeDigits { get; private set; } + /// /// Show full input file name. By default file name is printed without path and extension /// @@ -1033,6 +1051,10 @@ internal enum ZeroTimeModes public MinMaxRange MinMaxRetransBytes { get; private set; } = new(2, null); // by default filter retransmitted packets which are not 0 or 1 bytes which are often just ACKs or keepalive packets. public KeyValuePair> TcbFilter { get; private set; } = new(null, _ => true); + public MinMaxRange MinMaxDisconnect { get; private set; } = new MinMaxRange(); + public MinMaxRange MinMaxConnect { get; private set; } = new MinMaxRange(); + public bool Reset { get; private set; } + public MinMaxRange MinMaxRetransCount { get; private set; } = new(); public bool ShowRetransmit {get; private set; } @@ -1532,6 +1554,19 @@ public override void Parse() Tuple minMaxFirst = minFirst.GetMinMaxDouble(maxFirst, SecondUnit); MinMaxFirstS = new MinMaxRange(minMaxFirst.Item1, minMaxFirst.Item2); break; + case "-minmaxconnect": + string minConnect = GetNextNonArg("-minmaxconnect"); + string maxConnect = GetNextNonArg("-minmaxconnect", false); // optional + Tuple minmaxconnect = minConnect.GetMinMaxDouble(maxConnect, SecondUnit); + MinMaxConnect = new MinMaxRange(minmaxconnect.Item1, minmaxconnect.Item2); + break; + case "-minmaxdisconnect": + string minDisconnect = GetNextNonArg("-minmaxdisconnect"); + string maxDisconnect = GetNextNonArg("-minmaxdisconnect", false); // optional + Tuple minmaxdisconnect = minDisconnect.GetMinMaxDouble(maxDisconnect, SecondUnit); + MinMaxDisconnect = new MinMaxRange(minmaxdisconnect.Item1, minmaxdisconnect.Item2); + break; + case "-minmaxlast": string minLast = GetNextNonArg("-minmaxlast"); string maxLast = GetNextNonArg("-minmaxlast", false); // optional @@ -1689,6 +1724,12 @@ public override void Parse() case "-showtime": ShowTime = true; break; + case "-column": + ColumnConfiguration = ParseConfiguredColumns(GetNextNonArg("-column")); + break; + case "-reset": + Reset = true; + break; case "-totalmemory": case "-tm": TotalMemory = true; @@ -1713,6 +1754,14 @@ public override void Parse() string skipNTests = GetNextNonArg(SkipNTestsArg); SkipNTests = int.Parse(skipNTests, CultureInfo.InvariantCulture); break; + case "-timedigits": + string timedigits = GetNextNonArg("-timedigits"); + TimeDigits = int.Parse(timedigits, CultureInfo.InvariantCulture); + if( TimeDigits < 0 || TimeDigits > 6) + { + throw new NotSupportedException($"-Timedigits supports only values from 0-6. Value was: {TimeDigits}."); + } + break; case "-properties": Properties = GetNextNonArg("-properties"); break; @@ -1797,7 +1846,85 @@ public override void Parse() delayedThrower(); } - public override string Help + + Dictionary ParseConfiguredColumns(string cols) + { + Dictionary lret = new(StringComparer.OrdinalIgnoreCase); + + HashSet allowedColumnNames = myCommand switch + { + DumpCommands.TCP => new HashSet(DumpTcp.ColumnNames, StringComparer.OrdinalIgnoreCase), + DumpCommands.Process => new HashSet(DumpProcesses.ColumnNames, StringComparer.OrdinalIgnoreCase), + _ => throw new NotSupportedException($"The command {myCommand} does not support explicit column configuration (yet).") + }; + + string[] columns = cols.Split(new char[] {' ',';' }, StringSplitOptions.RemoveEmptyEntries); + foreach (string col in columns) + { + if( col.StartsWith("!") ) // exclude column, set enable flag to false + { + if( col.Length > 1 ) + { + string colName = col.Substring(1); + lret[colName] = false; + } + else + { + throw new NotSupportedException($"Column {col} in column set {cols} is not a column description."); + } + } + else // explicit enable over default values + { + lret[col] = true; + } + + // we need to expand on every run to be able to use ordered configs like + // !*;xx disable all enable xx + ExpandColumnWildCards(allowedColumnNames, lret); + } + + ThrowOnInvalidColumnName(myCommand, allowedColumnNames, lret); + + return lret; + } + + /// + /// Expand explicit column configurations like !*Retrans* to actual column names to be able to remove groups of columns. + /// + /// List of allowed columns. + /// overriden column names. + static void ExpandColumnWildCards(HashSet allowedColumnNames, Dictionary configuredColumns) + { + List toRemove = new(); + + foreach (var configcolumn in configuredColumns.Where(x => x.Key.Contains("*")).ToArray()) + { + toRemove.Add(configcolumn.Key); + Func wildCardColumn = Matcher.CreateMatcher(configcolumn.Key); + foreach (var matched in allowedColumnNames.Where(wildCardColumn)) + { + configuredColumns[matched] = configcolumn.Value; + } + } + + foreach(var todelete in toRemove) + { + configuredColumns.Remove(todelete); + } + } + + static void ThrowOnInvalidColumnName(DumpCommands current, HashSet allowedColumnNames, Dictionary configuredColumns) + { + foreach (var column in configuredColumns.Keys) + { + if (!allowedColumnNames.Contains(column)) + { + throw new NotSupportedException($"Column {column} is not supported by -Dump {current}. Allowed values are: {Environment.NewLine}{String.Join(";", allowedColumnNames)}"); + } + } + } + + public override string Help { get { @@ -1932,6 +2059,7 @@ public override void Run() CSVFile = CSVFile, NoCSVSeparator = NoCSVSeparator, TimeFormatOption = TimeFormat, + TimePrecision = TimeDigits, ProcessNameFilter = ProcessNameFilter, ProcessNameFilterSet = ProcessNameFilterSet, CommandLineFilter = CmdLineFilter, @@ -1966,6 +2094,8 @@ public override void Run() CSVFile = CSVFile, NoCSVSeparator = NoCSVSeparator, TimeFormatOption = TimeFormat, + TimePrecision = TimeDigits, + ColumnConfiguration = ColumnConfiguration, ProcessNameFilter = ProcessNameFilter, ProcessNameFilterSet = ProcessNameFilterSet, // Stay consistent and allow -processfmt or -timefmt as time format string for process tree visualization @@ -2009,6 +2139,7 @@ public override void Run() CSVFile = CSVFile, NoCSVSeparator = NoCSVSeparator, TimeFormatOption = TimeFormat, + TimePrecision = TimeDigits, ProcessNameFilter = ProcessNameFilter, ProcessNameFilterSet = ProcessNameFilterSet, ProcessFormatOption = ProcessFormat, @@ -2069,6 +2200,7 @@ public override void Run() CSVFile = CSVFile, NoCSVSeparator = NoCSVSeparator, TimeFormatOption = TimeFormat, + TimePrecision = TimeDigits, ProcessNameFilter = ProcessNameFilter, ProcessNameFilterSet = ProcessNameFilterSet, CommandLineFilter = CmdLineFilter, @@ -2109,6 +2241,7 @@ public override void Run() CSVFile = CSVFile, NoCSVSeparator = NoCSVSeparator, TimeFormatOption = TimeFormat, + TimePrecision = TimeDigits, ProcessNameFilter = ProcessNameFilter, ProcessNameFilterSet = ProcessNameFilterSet, ProcessFormatOption = ProcessFormat, @@ -2158,6 +2291,7 @@ public override void Run() CSVFile = CSVFile, NoCSVSeparator = NoCSVSeparator, TimeFormatOption = TimeFormat, + TimePrecision = TimeDigits, ShowDetails = ShowDetails, ShowDiff = ShowDiff, @@ -2180,6 +2314,7 @@ public override void Run() CSVFile = CSVFile, NoCSVSeparator = NoCSVSeparator, TimeFormatOption = TimeFormat, + TimePrecision = TimeDigits, ProcessNameFilter = ProcessNameFilter, ProcessNameFilterSet = ProcessNameFilterSet, ProcessFormatOption = ProcessFormat, @@ -2224,6 +2359,7 @@ public override void Run() CSVFile = CSVFile, NoCSVSeparator = NoCSVSeparator, TimeFormatOption = TimeFormat, + TimePrecision = TimeDigits, ProcessNameFilter = ProcessNameFilter, ProcessNameFilterSet = ProcessNameFilterSet, ProcessFormatOption = ProcessFormat, @@ -2266,6 +2402,7 @@ public override void Run() CSVFile = CSVFile, NoCSVSeparator = NoCSVSeparator, TimeFormatOption = TimeFormat, + TimePrecision = TimeDigits, ProcessNameFilter = ProcessNameFilter, ProcessNameFilterSet = ProcessNameFilterSet, ProcessFormatOption = ProcessFormat, @@ -2293,6 +2430,7 @@ public override void Run() CSVFile = CSVFile, NoCSVSeparator = NoCSVSeparator, TimeFormatOption = TimeFormat, + TimePrecision = TimeDigits, ProcessNameFilter = ProcessNameFilter, ProcessNameFilterSet = ProcessNameFilterSet, CommandLineFilter = CmdLineFilter, @@ -2321,6 +2459,7 @@ public override void Run() TestRunIndex = TestRunIndex, TestRunCount = TestRunCount, TimeFormatOption = TimeFormat, + TimePrecision = TimeDigits, IsVerbose = myIsVerbose, PrintFiles = myPrintFiles, @@ -2408,7 +2547,8 @@ public override void Run() NewProcessFilter = NewProcess, UsePrettyProcessName = UsePrettyProcessName, TimeFormatOption = TimeFormat, - + TimePrecision = TimeDigits, + NoCmdLine = NoCmdLine, TopN = TopN, TopNDetails = TopNDetails, @@ -2444,6 +2584,8 @@ public override void Run() NewProcessFilter = NewProcess, UsePrettyProcessName = UsePrettyProcessName, TimeFormatOption = TimeFormat, + TimePrecision = TimeDigits, + ColumnConfiguration = ColumnConfiguration, ShowTotal = ShowTotal, NoCmdLine = NoCmdLine, @@ -2461,6 +2603,9 @@ public override void Run() ShowRetransmit = ShowRetransmit, OnlyClientRetransmit = OnlyClientRetransmit, MinMaxRetransCount = MinMaxRetransCount, + MinMaxDisconnect = MinMaxDisconnect, + MinMaxConnect = MinMaxConnect, + Reset = Reset, TcbFilter = TcbFilter, ZeroTimeMode = ZeroTimeMode, ZeroTimeFilter = ZeroTimeFilter, diff --git a/ETWAnalyzer/Commands/HelpCommand.cs b/ETWAnalyzer/Commands/HelpCommand.cs index 9dfee164..894d79da 100644 --- a/ETWAnalyzer/Commands/HelpCommand.cs +++ b/ETWAnalyzer/Commands/HelpCommand.cs @@ -17,7 +17,7 @@ class HelpCommand : ICommand private static readonly string HelpString = $"ETWAnalyzer {FileVersionInfo.GetVersionInfo(Process.GetCurrentProcess().MainModule.FileName).FileVersion}" + Environment.NewLine + " ETWAnalyzer [green]-help[/green] [Extract, Dump, Console, Convert or LoadSymbol] Get further information about the specific sub command" + Environment.NewLine + - " ETWAnalyzer [green]-Console[/green]" + Environment.NewLine + + " ETWAnalyzer [green]-Console [input files] [/green]" + Environment.NewLine + " Interactive mode. Useful if working with bigger data sets without the need to reload data on every query. Enter .help to get more information." + Environment.NewLine + " ETWAnalyzer [green]-Convert[/green] -filedir xx.etl -pid dd [-perthread]" + Environment.NewLine + " Convert from an ETL File a process to a speedscope json file." + Environment.NewLine + diff --git a/ETWAnalyzer/Documentation/DumpProcessCommand.md b/ETWAnalyzer/Documentation/DumpProcessCommand.md index 86d13fdd..09ba4809 100644 --- a/ETWAnalyzer/Documentation/DumpProcessCommand.md +++ b/ETWAnalyzer/Documentation/DumpProcessCommand.md @@ -55,6 +55,8 @@ Supported values for *-TimeFmt* are: | UTC| 2022-02-04 08:56:34.670| | UTCTime| 08:56:34.670| +## Time Precision +The default time precision is ms, but it can be configured by using the ```-TimeDigits d``` flag to display time from 0-6 decimal places. ## Process Selection/Filters diff --git a/ETWAnalyzer/Documentation/DumpTCPCommand.md b/ETWAnalyzer/Documentation/DumpTCPCommand.md index 7d14fb7a..5ba9b307 100644 --- a/ETWAnalyzer/Documentation/DumpTCPCommand.md +++ b/ETWAnalyzer/Documentation/DumpTCPCommand.md @@ -121,9 +121,10 @@ On Windows Server you can change the Template settings with *Set-NetTCPSetting* TCP template if the automatic detection mechanism does not work for you. On client operating systems you cannot change the TCP template settings in a supported way (Windows 10,11). The most important setting is MinRto(ms) which defines the minimum retransmission timeout. It is the time the TCP stack of Windows will resend packets if after the MinRto time no ACK from the receiver was returned. -If that did not work Windows will resend the missing packet with a delay of RTO_i which is proportional to i^3 where i is th i-th resend try. -After n failed retransmits Windows resets the TCP connection by sending a RST packet and close the connection on his side. - +If that did not work Windows will resend the missing packet with a delay of MinRto where the delay is doubled on each round until ca. 9 retransmissions have occurred. +After n failed retransmits Windows waits additionally ca. 10s and then resets the TCP connection by sending a RST packet (TcpDisconnectTcbRtoTimeout event) and close the connection on his side. +If the connection could not be established after the initial SYN packet because no one did answer TcpConnectRestransmit events are logged which can be used to check +if invalid or not reachable hosts were tried to connect to. ## Recording Hints The *Microsoft-Windows-TCPIP* provider traces many events which are internal to how TCP works on Windows. To record data for some minutes you need to filter out the irrelevant events. diff --git a/ETWAnalyzer/ETWAnalyzer.csproj b/ETWAnalyzer/ETWAnalyzer.csproj index b3c8fbc8..0840a626 100644 --- a/ETWAnalyzer/ETWAnalyzer.csproj +++ b/ETWAnalyzer/ETWAnalyzer.csproj @@ -22,7 +22,7 @@ True https://github.com/Siemens-Healthineers/ETWAnalyzer ProgramaticAccess.md - 3.0.0.9 + 3.0.0.10 x64 true 1 diff --git a/ETWAnalyzer/EventDump/DumpBase.cs b/ETWAnalyzer/EventDump/DumpBase.cs index 821e51b6..a59090f4 100644 --- a/ETWAnalyzer/EventDump/DumpBase.cs +++ b/ETWAnalyzer/EventDump/DumpBase.cs @@ -18,6 +18,28 @@ namespace ETWAnalyzer.EventDump /// abstract class DumpBase : IDisposable { + /// + /// Explicitly enabled/disabled columns + /// + internal Dictionary ColumnConfiguration { get; set; } = new(StringComparer.OrdinalIgnoreCase); + + protected bool GetOverrideFlag(string column, bool defaultFlag) + { + // if only disable rules are active we leave the enabled defaults + // otherwise just the enabled/disabled columns are enabled + bool onlyDisableRules = ColumnConfiguration.Values.All(x => x == false); + + if(ColumnConfiguration.TryGetValue(column, out bool overrideFlag)) + { + return overrideFlag; + } + + // all other columns are disabled if explicit enable columns are configured. + return onlyDisableRules ? defaultFlag : false; + } + + + /// /// Specifies how time is formatted /// @@ -77,6 +99,30 @@ internal TimeFormats TimeFormatOption get;set; } + /// + /// Overriden Time Precision supplied at command line + /// + internal int? TimePrecision + { + get; set; + } + + /// + /// Default precision for this command which can be different, depending on what granularity time makes sense + /// + internal int DefaultTimePrecision + { + get; set; + } = 3; + + /// + /// Get effective time precision used for formatting strings + /// + internal int OverridenOrDefaultTimePrecision + { + get => TimePrecision == null ? DefaultTimePrecision : TimePrecision.Value; + } + internal TimeFormats? ProcessFormatOption { get;set; @@ -85,12 +131,35 @@ internal TimeFormats? ProcessFormatOption /// /// DateTime Format string used by various methods. /// - internal const string DateTimeFormat = "yyyy-MM-dd HH:mm:ss.fff"; + internal const string DateTimeFormat0 = "yyyy-MM-dd HH:mm:ss"; + internal const string DateTimeFormat1 = "yyyy-MM-dd HH:mm:ss.f"; + internal const string DateTimeFormat2 = "yyyy-MM-dd HH:mm:ss.ff"; + internal const string DateTimeFormat3 = "yyyy-MM-dd HH:mm:ss.fff"; + internal const string DateTimeFormat4 = "yyyy-MM-dd HH:mm:ss.ffff"; + internal const string DateTimeFormat5 = "yyyy-MM-dd HH:mm:ss.fffff"; + internal const string DateTimeFormat6 = "yyyy-MM-dd HH:mm:ss.ffffff"; + + internal static readonly string[] DateTimeFormatStrings = new string[] + { + DateTimeFormat0, DateTimeFormat1, DateTimeFormat2, DateTimeFormat3, DateTimeFormat4, DateTimeFormat5, DateTimeFormat6 + }; /// /// Time format string /// - internal const string TimeFormat = "HH:mm:ss.fff"; + internal const string TimeFormat0 = "HH:mm:ss"; + internal const string TimeFormat1 = "HH:mm:ss.f"; + internal const string TimeFormat2 = "HH:mm:ss.ff"; + internal const string TimeFormat3 = "HH:mm:ss.fff"; + internal const string TimeFormat4 = "HH:mm:ss.ffff"; + internal const string TimeFormat5 = "HH:mm:ss.fffff"; + internal const string TimeFormat6 = "HH:mm:ss.ffffff"; + + internal static readonly string[] TimeFormatStrings = new string[] + { + TimeFormat0, TimeFormat1, TimeFormat2, TimeFormat3, TimeFormat4, TimeFormat5, TimeFormat6 + }; + /// /// Default column width with which seconds are formatted. This needs to be at least 8, otherwise the header description will not fit @@ -98,12 +167,11 @@ internal TimeFormats? ProcessFormatOption protected const int SecondsColWidth = 8; /// - /// Related to string /// protected const int TimeFormatColWidth = 12; /// - /// Related to string + /// Related to strings with default precison 3 /// protected const int DateTimeColWidth = 23; @@ -139,20 +207,22 @@ protected internal string GetDateTimeString(DateTimeOffset? time, DateTimeOffset } } + int WidthDiffTo3 { get => OverridenOrDefaultTimePrecision - 3; } + protected int GetWidth(TimeFormats format) { return format switch { - TimeFormats.s => SecondsColWidth, - TimeFormats.second => SecondsColWidth, + TimeFormats.s => SecondsColWidth + WidthDiffTo3, + TimeFormats.second => SecondsColWidth + WidthDiffTo3, - TimeFormats.HereTime => TimeFormatColWidth, - TimeFormats.LocalTime => TimeFormatColWidth, - TimeFormats.UTCTime => TimeFormatColWidth, + TimeFormats.HereTime => TimeFormatColWidth+ WidthDiffTo3, + TimeFormats.LocalTime => TimeFormatColWidth + WidthDiffTo3, + TimeFormats.UTCTime => TimeFormatColWidth + WidthDiffTo3, - TimeFormats.Here => DateTimeColWidth, - TimeFormats.Local => DateTimeColWidth, - TimeFormats.UTC => DateTimeColWidth, + TimeFormats.Here => DateTimeColWidth + WidthDiffTo3, + TimeFormats.Local => DateTimeColWidth + WidthDiffTo3, + TimeFormats.UTC => DateTimeColWidth + WidthDiffTo3, _ => 0 // should not happen }; } @@ -181,9 +251,8 @@ protected virtual string GetAbbreviatedName(TimeFormats format) /// Local time /// Trace sessions start time /// Controls how time is formatted. - /// decimal numbers after second. Default is 3. /// Formatted time locale independent. - protected string GetTimeString(DateTimeOffset ?time, DateTimeOffset sessionStart, TimeFormats fmt, int precision=3) + protected string GetTimeString(DateTimeOffset ?time, DateTimeOffset sessionStart, TimeFormats fmt) { string lret = ""; @@ -192,15 +261,11 @@ protected string GetTimeString(DateTimeOffset ?time, DateTimeOffset sessionStart Tuple newTime = ConvertTime(time.Value, sessionStart, fmt); if (newTime.Item1.HasValue) // interpret as timespan { - lret = FormatAsSeconds(newTime.Item1.Value, precision); + lret = FormatAsSeconds(newTime.Item1.Value, OverridenOrDefaultTimePrecision); } else { - string preciseFormat = TimeFormat; - if( precision > 3) - { - preciseFormat += new string('f', precision - 3); - } + string preciseFormat = TimeFormatStrings[OverridenOrDefaultTimePrecision]; lret = newTime.Item2.Value.ToString(preciseFormat, CultureInfo.InvariantCulture); } } @@ -332,21 +397,16 @@ protected string GetDateTimeString(Tuple time) string lret = ""; if( time.Item1.HasValue) // interpret as timespan { - lret = FormatAsSeconds(time.Item1.Value,3); + lret = FormatAsSeconds(time.Item1.Value, OverridenOrDefaultTimePrecision); } else { - lret = time.Item2.Value.ToString(DateTimeFormat, CultureInfo.InvariantCulture); + lret = time.Item2.Value.ToString(DateTimeFormatStrings[OverridenOrDefaultTimePrecision], CultureInfo.InvariantCulture); } return lret; } - protected string GetDateTimeString(DateTime time) - { - return time.ToString(DateTimeFormat, CultureInfo.InvariantCulture); - } - protected string GetProcessTags(ETWProcess process, DateTimeOffset sessionStart) { if(process == null) @@ -382,6 +442,18 @@ protected string GetProcessTags(ETWProcess process, DateTimeOffset sessionStart) } + /// + /// Get maximum string length for column width calculation. + /// + /// + /// items to be formatted + /// String extractor + /// Maximum string length returned by getter for all items. + protected static int GetMaxLength(IList collection, Func getter) + { + return collection.Max(x => (getter(x)?.Length).GetValueOrDefault()); + } + #region IDisposable Support protected virtual void Dispose(bool disposing) diff --git a/ETWAnalyzer/EventDump/DumpExceptions.cs b/ETWAnalyzer/EventDump/DumpExceptions.cs index 0a53de7c..dccd3ace 100644 --- a/ETWAnalyzer/EventDump/DumpExceptions.cs +++ b/ETWAnalyzer/EventDump/DumpExceptions.cs @@ -189,7 +189,7 @@ private void WriteToCSVFile(List matches) string directory = match.Module?.ModulePath ?? ""; WriteCSVLine(CSVOptions, GetDateTimeString(match.TimeStamp, match.SessionStart, TimeFormatOption), match.Type, match.Message, match.Process.GetProcessWithId(UsePrettyProcessName), match.Process.GetProcessName(UsePrettyProcessName), match.Process.SessionId, match.Process.StartTime, - match.Process.CmdLine, match.Stack, match.TestCase, match.BaseLine, GetDateTimeString(match.PerformedAt), match.SourceFile, + match.Process.CmdLine, match.Stack, match.TestCase, match.BaseLine, match.PerformedAt, match.SourceFile, fileVersion, versionString, productVersion, productName, description, directory); } } diff --git a/ETWAnalyzer/EventDump/DumpModuleVersions.cs b/ETWAnalyzer/EventDump/DumpModuleVersions.cs index bb5a4063..94a027ea 100644 --- a/ETWAnalyzer/EventDump/DumpModuleVersions.cs +++ b/ETWAnalyzer/EventDump/DumpModuleVersions.cs @@ -88,7 +88,7 @@ private void WriteToCSV(List rowData) switch (Mode) { case PrintMode.Module: - string moduleBuildData = GetDateTimeString(MachineDetailsExtractor.GetBuildDate(new Version(data.ModuleVersion.Version))); + string moduleBuildData = MachineDetailsExtractor.GetBuildDate(new Version(data.ModuleVersion.Version)).ToString(); int diffDays = (int)(MachineDetailsExtractor.GetBuildDate(new Version(data.MainModuleVersion.Version)) - MachineDetailsExtractor.GetBuildDate(new Version(data.ModuleVersion.Version))).TotalDays; diffDays = Math.Abs(diffDays) > 400 ? 400 : diffDays; WriteCSVLine(CSVOptions, data.TestName, data.Duration, data.Machine, data.TestDate, data.MainModuleVersion.Version, data.ModuleVersion.Module, data.ModuleVersion.Version, moduleBuildData, diffDays, data.SourceFile); diff --git a/ETWAnalyzer/EventDump/DumpObjectRef.cs b/ETWAnalyzer/EventDump/DumpObjectRef.cs index 8e50bcc6..d6ec0949 100644 --- a/ETWAnalyzer/EventDump/DumpObjectRef.cs +++ b/ETWAnalyzer/EventDump/DumpObjectRef.cs @@ -87,6 +87,7 @@ public string HandleType public override List ExecuteInternal() { + DefaultTimePrecision = 6; // we need us time precision by default HarmonizeFilterSettings(); List lret = ReadFileData(); @@ -920,7 +921,7 @@ private void PrintMapEvent(MatchData ev) void PrintEventHeader(IStackEventBase ev, IETWExtract resolver, string name, string beforeProc = null) { - string timeStr = base.GetTimeString(ev.GetTime(resolver.SessionStart), resolver.SessionStart, this.TimeFormatOption, 6); + string timeStr = base.GetTimeString(ev.GetTime(resolver.SessionStart), resolver.SessionStart, this.TimeFormatOption); ColorConsole.WriteEmbeddedColorLine($"\t{timeStr} [magenta]{GetProcessId(ev.ProcessIdx, resolver),5}[/magenta]/{ev.ThreadId,-5} {name} {beforeProc}[magenta]{GetProcessAndStartStopTags(ev.ProcessIdx, resolver,false)}[/magenta] ", null, true); } diff --git a/ETWAnalyzer/EventDump/DumpProcesses.cs b/ETWAnalyzer/EventDump/DumpProcesses.cs index 9a2a0fb1..e5e88146 100644 --- a/ETWAnalyzer/EventDump/DumpProcesses.cs +++ b/ETWAnalyzer/EventDump/DumpProcesses.cs @@ -71,6 +71,36 @@ bool IsFileTotalMode _ => true, }; + /// + /// Process Id width used for formatting. + /// + const int PidWidth = 6; + + const string Col_Pid = "ProcessId"; + const string Col_StartTimeHeader = "StartTime"; + const string Col_StopTime = "StopTime"; + const string Col_Duration = "Duration"; + const string Col_ReturnCode = "ReturnCode"; + const string Col_Parent = "ParentPid"; + const string Col_SessionHeader = "Session"; + const string Col_User = "User"; + const string Col_ProcessHeader = "Process"; + const string Col_CommandLineHeader = "CommandLine"; + const string Col_FileNameHeader = "FileName"; + + /// + /// Valid column names which can be enabled for more flexible output + /// + public static string[] ColumnNames = + { + Col_Pid, Col_StartTimeHeader, Col_StopTime, + Col_Duration, Col_ReturnCode, Col_Parent, + Col_SessionHeader, Col_User, Col_ProcessHeader, + Col_CommandLineHeader, Col_FileNameHeader + }; + + string myCurrentSourceFile = null; + const string WerFault = "WerFault.exe"; public override List ExecuteInternal() @@ -98,7 +128,6 @@ public override List ExecuteInternal() return lret; } - /// /// Used by context sensitive help /// @@ -111,10 +140,33 @@ public override List ExecuteInternal() SortOrders.Default, }; + /// + /// Get column enabled status + /// + /// Column Name + /// ture if column is enabled, or false otherwise. + /// When a not existing column is found. + bool GetEnable(string columnName) + { + bool lret = columnName switch + { + Col_Pid => GetOverrideFlag(Col_Pid, true), + Col_StartTimeHeader => GetOverrideFlag(Col_StartTimeHeader, true), + Col_StopTime => GetOverrideFlag(Col_StopTime, true), + Col_Duration => GetOverrideFlag(Col_Duration, true), + Col_ReturnCode => GetOverrideFlag(Col_ReturnCode, true), + Col_Parent => GetOverrideFlag(Col_Parent, true), + Col_SessionHeader => GetOverrideFlag(Col_SessionHeader, ShowDetails), + Col_User => GetOverrideFlag(Col_User, ShowUser), + Col_ProcessHeader => GetOverrideFlag(Col_ProcessHeader, true), + Col_CommandLineHeader => GetOverrideFlag(Col_CommandLineHeader, !NoCmdLine), + Col_FileNameHeader => GetOverrideFlag(Col_FileNameHeader, ShowFileOnLine), + + _ => throw new NotSupportedException($"Column {columnName} is not handled by GetEnable method. Please add case for it."), + }; + return lret; + } - string myCurrentSourceFile = null; - - /// /// Print output to console /// @@ -164,20 +216,134 @@ public void Print(List data) return; } - - int userWidth = data.Max(x => x.User.Length); - int lifeTimeWidth = data.Max(x => x.LifeTimeString.Length); - int startTimeWidth = data.Max(x => x.StartTime.HasValue ? GetDateTimeString(x.StartTime.Value, x.SessionStart, TimeFormatOption).Length : 0); - int stopTimeWidth = data.Max(x => x.EndTime.HasValue ? GetDateTimeString(x.EndTime.Value, x.SessionStart, TimeFormatOption).Length : 0); - int returnCodeWidth = data.Max(x => (x.ReturnCodeString?.Length).GetValueOrDefault()); - + string timeSpanFormat = "hh\\:mm\\:ss\\." + new string('f', OverridenOrDefaultTimePrecision); + + + // column data extractors + Func getpid = m => m.ProcessId.ToString().WithWidth(PidWidth); + Func getStartTime = m => m.StartTime != null ? GetDateTimeString(m.StartTime.Value, m.SessionStart, TimeFormatOption) : ""; + Func getStopTime = m => m.EndTime != null ? GetDateTimeString(m.EndTime.Value, m.SessionStart, TimeFormatOption) : ""; + Func getDuration = m => (TimePrecision == null || m.LifeTime == null) ? m.LifeTimeString : m.LifeTime.Value.ToString(timeSpanFormat); + Func getReturnCode = m => m.ReturnCodeString; + Func getParent = m => m.ParentProcessId.ToString().WithWidth(PidWidth); + Func getSessionId = m => m.SessionId.ToString(); + Func getUser = m => m.User; + Func getProcess = m => m.ProcessName; + Func getCommandLine = m => " " + m.CmdLine; + Func getFileName = m => " " + Path.GetFileNameWithoutExtension(m.SourceFile); + + // calculate for each column the maximum width + int startTimeWidth = GetMaxLength(data, getStartTime); + int stopTimeWidth = GetMaxLength(data, getStopTime); + int lifeTimeWidth = GetMaxLength(data, getDuration); + int returnCodeWidth = GetMaxLength(data, getReturnCode); + int sessionIdWidth = GetMaxLength(data, getSessionId); + int userWidth = GetMaxLength(data, getUser); + + // declare columns, color and enabled status + MultiLineFormatter formatter = new( + new() + { + Title = "ProcessId", + Name = Col_Pid, + Enabled = GetEnable(Col_Pid), + Prefix = "", + DataWidth = PidWidth, + Color = ConsoleColor.Yellow, + }, + new() + { + Title = "Start Time", + Name = Col_StartTimeHeader, + Enabled = GetEnable(Col_StartTimeHeader), + Prefix = "Start: ", + DataWidth = startTimeWidth + "Start: ".Length, + Color = ConsoleColor.Green, + }, + new() + { + Title = "Stop Time", + Name = Col_StopTime, + Enabled = GetEnable(Col_StopTime), + Prefix = "Stop: ", + DataWidth = stopTimeWidth + "Stop: ".Length, + Color = ConsoleColor.Blue, + }, + new() + { + Title = "Duration", + Name = Col_Duration, + Enabled = GetEnable(Col_Duration), + Prefix = "Duration: ", + DataWidth = lifeTimeWidth + "Duration: ".Length, + Color = ConsoleColor.Blue, + }, + new() + { + Title = "Return Code", + Name = Col_ReturnCode, + Enabled = GetEnable(Col_ReturnCode), + Prefix = "RCode: ", + DataWidth = returnCodeWidth + "RCode: ".Length, + Color = null, + }, + new() + { + Title = "Session", + Name = Col_Session, + Enabled = GetEnable(Col_Session), + DataWidth = sessionIdWidth+3, + Color = null + }, + new() + { + Title = "User", + Name = Col_User, + Enabled = GetEnable(Col_User), + DataWidth = userWidth, + Color = null, + }, + new() + { + Title = "Parent", + Name = Col_Parent, + Enabled = GetEnable(Col_Parent), + Prefix = "Parent: ", + DataWidth = PidWidth + "Parent: ".Length, + Color = null, + }, + new() + { + Title = "Process", + Name = Col_ProcessHeader, + Enabled = GetEnable(Col_ProcessHeader), + DataWidth = 0, + Color = null, + }, + new() + { + Title = " Command Line", + Name = Col_CommandLineHeader, + Enabled = GetEnable(Col_CommandLineHeader), + Color = ConsoleColor.Yellow, + }, + new() + { + Title = " File Name", + Name = Col_FileName, + Enabled = GetEnable(Col_FileName), + Color = ConsoleColor.Magenta, + } + ); + var processTotals = new TotalCounter(); var globalProcessCounts = new TotalCounter(); + formatter.PrintHeader(); + foreach (var m in data) { - if ( currentSourceFile != m.SourceFile && !ShowFileOnLine ) { if (IsSummary || IsFileTotalMode) @@ -193,50 +359,23 @@ public void Print(List data) globalProcessCounts.Add(m); processTotals.Add(m); - string startTime = ""; - if (m.StartTime != null) + // get column data + string[] columnData = new string[] { - startTime = GetDateTimeString(m.StartTime.Value, m.SessionStart, TimeFormatOption); - } - - string stopTime = ""; - if (m.EndTime != null) - { - stopTime = GetDateTimeString(m.EndTime.Value, m.SessionStart, TimeFormatOption); - } - - string user = ""; - if (ShowUser) - { - user = m.User.WithWidth(-1 * userWidth) + " "; - } - - - string fileName = ""; - if( ShowFileOnLine ) - { - fileName = Path.GetFileNameWithoutExtension(m.SourceFile); - } - string cmdLine = m.ProcessName; - if (!NoCmdLine) - { - cmdLine = String.IsNullOrEmpty(m.CmdLine) ? m.ProcessName : m.CmdLine; - } - - string sessionId = ""; - if (ShowDetails) - { - sessionId = ShowDetails ? $" Session: { m.SessionId, 2}" : ""; - } - - string str = $"PID: [yellow]{m.ProcessId,-6}[/yellow] " + - $"Start: [green]{startTime.WithWidth(startTimeWidth)}[/green] " + - $"Stop: [darkcyan]{stopTime.WithWidth(stopTimeWidth)} Duration: {m.LifeTimeString.WithWidth(lifeTimeWidth)}[/darkcyan] " + - $"RCode: {m.ReturnCodeString.WithWidth(returnCodeWidth)} Parent: {m.ParentProcessId, 5} " + - $"[yellow]{sessionId}[/yellow] " + - $"[yellow]{user}[/yellow]{cmdLine} {fileName}"; - ColorConsole.WriteEmbeddedColorLine(str); + getpid(m), + getStartTime(m), + getStopTime(m), + getDuration(m), + getReturnCode(m), + getSessionId(m), + getUser(m), + getParent(m), + getProcess(m), + getCommandLine(m), + getFileName(m), + }; + formatter.Print(true, columnData); // print row data which supports multiline wrapping } // print the summary for last file diff --git a/ETWAnalyzer/EventDump/DumpTcp.cs b/ETWAnalyzer/EventDump/DumpTcp.cs index 7c8dd204..dc477d7e 100644 --- a/ETWAnalyzer/EventDump/DumpTcp.cs +++ b/ETWAnalyzer/EventDump/DumpTcp.cs @@ -81,6 +81,9 @@ internal class DumpTcp : DumpFileDirBase _ => true, }; + public bool Reset { get; internal set; } + public MinMaxRange MinMaxConnect { get; internal set; } + public MinMaxRange MinMaxDisconnect { get; internal set; } /// /// Unit testing only. ReadFileData will return this list instead of real data @@ -192,6 +195,64 @@ public override List ExecuteInternal() return lret; } + const string Col_Connection = "Connection"; + const string Col_ReceivedPackets = "ReceivedPackets"; + const string Col_ReceivedBytes = "ReceivedBytes"; + const string Col_SentPackets = "SentPackets"; + const string Col_SentBytes = "SentBytes"; + const string Col_Total = "Total"; + const string Col_RetransmitCount = "RetransCount"; + const string Col_RetransmitPercent = "RetransPercent"; + const string Col_RetransmitDelay = "RetransDelay"; + const string Col_RetransmitMin = "RetransMin"; + const string Col_RetransmitMedian = "RetransMedian"; + const string Col_RetransmitMax = "RetransMax"; + const string Col_Template = "Template"; + const string Col_ConnectTime = "ConnectTime"; + const string Col_DisconnectTime = "DisconnectTime"; + const string Col_ResetTime = "ResetTime"; + const string Col_LastSendTime = "LastSendTime"; + const string Col_LastReceiveTime = "LastReceiveTime"; + const string Col_TCB = "TCB"; + + + bool GetEnable(string columnName) + { + bool lret = columnName switch + { + Col_Connection => GetOverrideFlag(Col_Connection,true), + Col_ReceivedPackets => GetOverrideFlag(Col_ReceivedPackets, true), + Col_ReceivedBytes => GetOverrideFlag(Col_ReceivedBytes, true), + Col_SentPackets => GetOverrideFlag(Col_SentPackets, true), + Col_SentBytes => GetOverrideFlag(Col_SentBytes, true), + Col_Total => GetOverrideFlag(Col_Total, SortOrder == SortOrders.TotalCount || SortOrder == SortOrders.TotalSize), + Col_RetransmitCount => GetOverrideFlag(Col_RetransmitCount, true), + Col_RetransmitPercent => GetOverrideFlag(Col_RetransmitPercent, true), + Col_RetransmitDelay => GetOverrideFlag(Col_RetransmitDelay, true), + Col_RetransmitMin => GetOverrideFlag(Col_RetransmitMin, ShowDetails), + Col_RetransmitMedian => GetOverrideFlag(Col_RetransmitMedian, ShowDetails), + Col_RetransmitMax => GetOverrideFlag(Col_RetransmitMax, ShowDetails), + Col_Template => GetOverrideFlag(Col_Template, ShowDetails), + Col_ConnectTime => GetOverrideFlag(Col_ConnectTime, ShowDetails), + Col_DisconnectTime => GetOverrideFlag(Col_DisconnectTime, ShowDetails), + Col_ResetTime => GetOverrideFlag(Col_ResetTime, ShowDetails), + Col_LastSendTime => GetOverrideFlag(Col_LastSendTime, ShowDetails), + Col_LastReceiveTime => GetOverrideFlag(Col_LastReceiveTime, ShowDetails), + Col_TCB => GetOverrideFlag(Col_TCB, ShowDetails), + _ => throw new NotSupportedException($"Column {columnName} is not configurable."), + }; + return lret; + } + + /// + /// Valid column names which can be enabled for more flexible output + /// + public static string[] ColumnNames = + { + Col_Connection,Col_ReceivedPackets,Col_ReceivedBytes,Col_SentPackets,Col_SentBytes,Col_Total,Col_RetransmitCount,Col_RetransmitPercent, + Col_RetransmitDelay,Col_RetransmitMin,Col_RetransmitMedian,Col_RetransmitMax, + Col_Template,Col_ConnectTime,Col_DisconnectTime,Col_ResetTime,Col_LastSendTime, Col_LastReceiveTime, Col_TCB + }; private void PrintMatches(List data) { @@ -209,35 +270,164 @@ private void PrintMatches(List data) int remoteIPLen = allPrinted.Max(x => x.Connection.RemoteIpAndPort.ToString().Length); int tcpTemplateLen = allPrinted.Max(x => x.Connection.LastTcpTemplate?.Length) ?? 8; - const string ConnectionHeadlineStr = "Source IP/Port -> Destination IP/Port"; - int totalIPLen = localIPLen + remoteIPLen + 4; - - if (totalIPLen < ConnectionHeadlineStr.Length ) // increase minimum width if headline is longer than local and remote ip - { - remoteIPLen += ConnectionHeadlineStr.Length - totalIPLen; - } - - string connectionHeadline = ConnectionHeadlineStr.WithWidth(localIPLen+remoteIPLen+4); const int PacketCountWidth = 9; const int BytesCountWidth = 15; const int PercentWidth = 4; - const int RetransMsWidth = 6; + const int RetransMsWidth = 7; int timeWidth = GetWidth(TimeFormatOption); const int PointerWidth = 16; const int TotalColumnWidth = 22; - string sentHeadline = "Sent Packets/Bytes".WithWidth(PacketCountWidth + BytesCountWidth+7); - string receivedHeadline = "Received Packets/Bytes".WithWidth(PacketCountWidth + BytesCountWidth+7); - string retransmissionHeadline = "Retrans Count/%/Delay".WithWidth(PacketCountWidth+PercentWidth+ PacketCountWidth+7); - string detailsMinMaxMedian = ShowDetails ? "Max/Median/Min in ms".WithWidth(3 * (RetransMsWidth+4)+1) : " "; - string detailsTemplate = ShowDetails ? "Template".WithWidth(tcpTemplateLen+2) : ""; - string detailsConnectionTimes = ShowDetails ? "Connect/Disconnect Time".WithWidth(2 * timeWidth+2) : ""; - string detailsTCB = ShowDetails ? "TCB".WithWidth(PointerWidth + 3) : ""; - string headline = $"[yellow]{connectionHeadline}[/yellow] [green]{receivedHeadline}[/green] [red]{sentHeadline}[/red] [magenta]{GetTotalColumnHeader(TotalColumnWidth)}[/magenta][yellow]{retransmissionHeadline}[/yellow][yellow]{detailsMinMaxMedian}[/yellow]"+ - $"{detailsTemplate}{detailsConnectionTimes}{detailsTCB} [magenta]Process[/magenta]"; + MultiLineFormatter formatter = new( + new() + { + Title = "Source IP/Port -> Destination IP/Port", + Name = Col_Connection, + Enabled = GetEnable(Col_Connection), + DataWidth = localIPLen + remoteIPLen + " -> ".Length + 1, + Color = ConsoleColor.Yellow, + }, new() + { + Title = "Received Packets", + Name = Col_ReceivedPackets, + Enabled = GetEnable(Col_ReceivedPackets), + DataWidth = PacketCountWidth, + Color = ConsoleColor.Green, + }, new() + { + Title = "Received Bytes", + Name = Col_ReceivedBytes, + Enabled = GetEnable(Col_ReceivedBytes), + DataWidth = BytesCountWidth + " Bytes".Length, + Color = ConsoleColor.Green, + }, new() + { + Title = "Sent Packets", + Name = Col_SentPackets, + Enabled = GetEnable(Col_SentPackets), + DataWidth = PacketCountWidth, + Color = ConsoleColor.Red, + }, new() + { + Title = "Sent Bytes", + Name = Col_SentBytes, + Enabled = GetEnable(Col_SentBytes), + DataWidth = BytesCountWidth + " Bytes".Length, + Color = ConsoleColor.Red, + }, new() + { + Title = "Total" + ((SortOrder == SortOrders.TotalCount) ? " Packets" : (SortOrder == SortOrders.TotalSize) ? " Bytes" : ""), + Name = Col_Total, + Enabled = GetEnable(Col_Total), + DataWidth = TotalColumnWidth, + Color = ConsoleColor.Red, + }, + new() + { + Title = "Retransmit Count", + Name = Col_RetransmitCount, + Enabled = GetEnable(Col_RetransmitCount), + DataWidth = PacketCountWidth, + Color = ConsoleColor.Yellow, + }, new() + { + Title = "%", + Name = Col_RetransmitPercent, + Enabled = GetEnable(Col_RetransmitPercent), + DataWidth = PercentWidth, + Color = ConsoleColor.Yellow, + }, new() + { + Title = "Delay ms", + Name = Col_RetransmitDelay, + Enabled = GetEnable(Col_RetransmitDelay), + DataWidth = RetransMsWidth + " ms".Length, + Color = ConsoleColor.Yellow, + }, new() + { + Title = "Min ms", + Name = Col_RetransmitMin, + Enabled = GetEnable(Col_RetransmitMin), + DataWidth = RetransMsWidth + " ms".Length, + Color = ConsoleColor.Yellow, + }, new() + { + Title = "Max ms", + Name = Col_RetransmitMax, + Enabled = GetEnable(Col_RetransmitMax), + DataWidth = RetransMsWidth + " ms".Length, + Color = ConsoleColor.Yellow, + + }, new() + { + Title = "Median ms", + Name = Col_RetransmitMedian, + Enabled = GetEnable(Col_RetransmitMedian), + DataWidth = RetransMsWidth + " ms".Length, + Color = ConsoleColor.Yellow, + }, new() + { + Title = "Template", + Name = Col_Template, + Enabled = GetEnable(Col_Template), + DataWidth = tcpTemplateLen + 2, + }, new() + { + Title = "Connect Time", + Name = Col_ConnectTime, + Enabled = GetEnable(Col_ConnectTime), + DataWidth = timeWidth + 1, + }, new() + { + Title = "Disconnect Time", + Name = Col_DisconnectTime, + Enabled = GetEnable(Col_DisconnectTime), + DataWidth = timeWidth + 1, + }, new() + { + Title = "ConnectionReset Time", + Name = Col_ResetTime, + Enabled = GetEnable(Col_ResetTime), + DataWidth = timeWidth + 1, + Color = ConsoleColor.Yellow, + }, new() + { + Title = "LastSent Time", + Name = Col_LastSendTime, + Enabled = GetEnable(Col_LastSendTime), + DataWidth = timeWidth + 1, + Color = ConsoleColor.Red, + + }, new() + { + Title = "LastReceived Time", + Name = Col_LastReceiveTime, + Enabled = GetEnable(Col_LastReceiveTime), + DataWidth = timeWidth + 1, + Color = ConsoleColor.Green, + }, new() + { + Title = "TCB", + Name = Col_TCB, + Enabled = GetEnable(Col_TCB), + DataWidth = PointerWidth + 3, + Color = ConsoleColor.Green, + }, new() + { + Title = "Process ", + Color = ConsoleColor.Magenta, + }, new() + { + Title = "Tags ", + Color = ConsoleColor.Gray, + }, new() + { + Title = "CmdLine", + Color = ConsoleColor.DarkCyan, + }); - ColorConsole.WriteEmbeddedColorLine(headline); + formatter.PrintHeader(); foreach (var file in byFile) { @@ -253,7 +443,7 @@ private void PrintMatches(List data) double totalSumRetransDelay = 0; int totalConnectCounter = 0; - foreach (var match in file.SortAscendingGetTopNLast(SortBy, x => x.Connection.BytesReceived + x.Connection.BytesSent, null, TopN) ) + foreach (var match in file.SortAscendingGetTopNLast(SortBy, x => x.Connection.BytesReceived + x.Connection.BytesSent, null, TopN)) { totalDatagramsReceived += match.Connection.DatagramsReceived; totalDatagramsSent += match.Connection.DatagramsSent; @@ -263,26 +453,42 @@ private void PrintMatches(List data) totalSumRetransDelay += match.Retransmissions.Sum(x => x.RetransmitDiff().TotalMilliseconds); totalConnectCounter += match.InputConnectionCount; + string connection = $"{match.Connection.LocalIpAndPort.ToString().WithWidth(localIPLen)} -> {match.Connection.RemoteIpAndPort.ToString().WithWidth(remoteIPLen)}"; + // retransmission % can only be calculated by sent packets and retransmission events excluding client retransmissions - string retransPercent = "N0".WidthFormat(100.0f * match.Retransmissions.Where(x=>x.IsClientRetransmission.GetValueOrDefault() == false).Count() / match.Connection.DatagramsSent, PercentWidth); + string retransPercent = (100.0f * match.Retransmissions.Where(x => x.IsClientRetransmission.GetValueOrDefault() == false).Count() / match.Connection.DatagramsSent).ToString("N0"); // Delay on the other hand can be calculated by all Retransmit events. - string totalRetransDelay = "N0".WidthFormat(match.Retransmissions.Sum(x => x.RetransmitDiff().TotalMilliseconds), PacketCountWidth); - - ColorConsole.WriteEmbeddedColorLine($"{match.Connection.LocalIpAndPort.ToString().WithWidth(localIPLen)} -> {match.Connection.RemoteIpAndPort.ToString().WithWidth(remoteIPLen)} ", ConsoleColor.Yellow, true); - ColorConsole.WriteEmbeddedColorLine( - $"[green]{"N0".WidthFormat(match.Connection.DatagramsReceived, PacketCountWidth)} {"N0".WidthFormat(match.Connection.BytesReceived, BytesCountWidth)} Bytes[/green] " + - $"[red]{"N0".WidthFormat(match.Connection.DatagramsSent, PacketCountWidth)} {"N0".WidthFormat(match.Connection.BytesSent, BytesCountWidth)} Bytes[/red] " + - $"[magenta]{GetTotalString(match, TotalColumnWidth)}[/magenta]" + - $"[yellow]{"N0".WidthFormat(match.Retransmissions.Count, PacketCountWidth)} {retransPercent} % {totalRetransDelay} ms [/yellow] " + - ( ShowDetails ? - $"[yellow]{"F0".WidthFormat(match.RetransMaxms, RetransMsWidth)} ms {"F0".WidthFormat(match.RetransMedianMs, RetransMsWidth)} ms {"F0".WidthFormat(match.RetransMinMs, RetransMsWidth)} ms [/yellow] " + - $"{(match.Connection.LastTcpTemplate ?? "-").WithWidth(tcpTemplateLen)} " + - $"{GetDateTimeString(match.Connection.TimeStampOpen, match.Session.AdjustedSessionStart, TimeFormatOption, true).WithWidth(timeWidth)} {GetDateTimeString(match.Connection.TimeStampClose, match.Session.AdjustedSessionStart, TimeFormatOption, true).WithWidth(timeWidth)} " + - $"0x{"X".WidthFormat(match.Connection.Tcb, PointerWidth)} " - : "") + - $"[magenta]{match.Process.GetProcessWithId(UsePrettyProcessName)}[/magenta][grey]{GetProcessTags(match.Process, match.Session.AdjustedSessionStart)}[/grey]", ConsoleColor.White, true); - ColorConsole.WriteLine(NoCmdLine ? "" : match.Process.CommandLineNoExe, ConsoleColor.DarkCyan); + string totalRetransDelay = match.Retransmissions.Sum(x => x.RetransmitDiff().TotalMilliseconds).ToString("N0"); + + string[] lineData = new string[] + { + connection, + match.Connection.DatagramsReceived.ToString("N0"), + match.Connection.BytesReceived.ToString("N0") + " Bytes", + match.Connection.DatagramsSent.ToString("N0"), + match.Connection.BytesSent.ToString("N0") + " Bytes", + GetTotalString(match, TotalColumnWidth), + match.Retransmissions.Count.ToString("N0"), + retransPercent, + totalRetransDelay, + match.RetransMinMs.ToString("F0") +" ms", + match.RetransMaxms.ToString("F0") +" ms", + match.RetransMedianMs.ToString("F0") +" ms", + (match.Connection.LastTcpTemplate ?? "-"), + GetDateTimeString(match.Connection.TimeStampOpen, match.Session.AdjustedSessionStart, TimeFormatOption, false), + GetDateTimeString(match.Connection.TimeStampClose, match.Session.AdjustedSessionStart, TimeFormatOption, false), + match.Connection.RetransmitTimeout != null ? GetDateTimeString(match.Connection.RetransmitTimeout, match.Session.AdjustedSessionStart, TimeFormatOption, false) : "", + match.Connection.LastSent != null ? GetDateTimeString(match.Connection.LastSent, match.Session.AdjustedSessionStart, TimeFormatOption, false) : "", + match.Connection.LastReceived != null ? GetDateTimeString(match.Connection.LastReceived, match.Session.AdjustedSessionStart, TimeFormatOption, false) : "", + $"0x{"X".WidthFormat(match.Connection.Tcb, PointerWidth)}", + match.Process.GetProcessWithId(UsePrettyProcessName), + GetProcessTags(match.Process, match.Session.AdjustedSessionStart), + NoCmdLine ? "" : match.Process.CommandLineNoExe, + }; + + formatter.Print(true, lineData); + printedFiles++; if (ShowRetransmit) @@ -298,7 +504,7 @@ private void PrintMatches(List data) //show per file totals always { - int emptyWidth = totalIPLen + 1; //hide the port data always + int emptyWidth = formatter.Columns[0].DataWidth+ 1; //hide the port data always const int totalTotalColumnWidth = 23; string fileDatagramsReceived = $"{"N0".WidthFormat(totalDatagramsReceived, PacketCountWidth)}"; string fileDatagramsSent = $"{"N0".WidthFormat(totalDatagramsSent, PacketCountWidth)}"; @@ -380,7 +586,25 @@ private List ReadFileData() continue; } - if( TcbFilter.Value?.Invoke("0x"+connection.Tcb.ToString("X")) == false ) + if( !MinMaxConnect.IsWithin(((connection.TimeStampOpen ?? DateTimeOffset.MaxValue)-file.Extract.SessionStart).TotalSeconds) ) + { + continue; + } + + if (!MinMaxDisconnect.IsWithin(((connection.TimeStampClose ?? DateTimeOffset.MaxValue) - file.Extract.SessionStart).TotalSeconds)) + { + continue; + } + + // filter by connection reset + if( Reset && connection.RetransmitTimeout == null) + { + continue; + } + + + + if ( TcbFilter.Value?.Invoke("0x"+connection.Tcb.ToString("X")) == false ) { continue; } @@ -545,8 +769,8 @@ string GetTotalString(MatchData data, int minWidth) { return SortOrder switch { - SortOrders.TotalCount => "N0".WidthFormat(data.Connection.DatagramsReceived + data.Connection.DatagramsSent, minWidth), - SortOrders.TotalSize => $"{data.Connection.BytesReceived + data.Connection.BytesSent:N0} Bytes".WithWidth(minWidth), + SortOrders.TotalCount => (data.Connection.DatagramsReceived + data.Connection.DatagramsSent).ToString("N0"), + SortOrders.TotalSize => (data.Connection.BytesReceived + data.Connection.BytesSent).ToString("N0")+ " Bytes", _ => "", }; } diff --git a/ETWAnalyzer/Extract/Network/Tcp/ITcpConnection.cs b/ETWAnalyzer/Extract/Network/Tcp/ITcpConnection.cs index 3edbaffa..8dd3950d 100644 --- a/ETWAnalyzer/Extract/Network/Tcp/ITcpConnection.cs +++ b/ETWAnalyzer/Extract/Network/Tcp/ITcpConnection.cs @@ -65,6 +65,21 @@ public interface ITcpConnection /// DateTimeOffset? TimeStampOpen { get; } + /// + /// Time when data was last sent + /// + public DateTimeOffset? LastSent { get; } + + /// + /// Time when data was last received + /// + public DateTimeOffset? LastReceived { get; } + + /// + /// Time when connection was closed due to retransmission timeout + /// + public DateTimeOffset? RetransmitTimeout { get; } + /// /// Check if connection was active at a given time. /// diff --git a/ETWAnalyzer/Extract/Network/Tcp/TcpConnection.cs b/ETWAnalyzer/Extract/Network/Tcp/TcpConnection.cs index 62f46eac..c28d66c6 100644 --- a/ETWAnalyzer/Extract/Network/Tcp/TcpConnection.cs +++ b/ETWAnalyzer/Extract/Network/Tcp/TcpConnection.cs @@ -11,6 +11,7 @@ namespace ETWAnalyzer.Extract.Network.Tcp { /// /// Contains information about one TCP connection (Tcb, open/close time, src/dst ip and ports). Fired during inital handshake. + /// Serialized to Json /// public class TcpConnection : ITcpConnection { @@ -45,7 +46,6 @@ public class TcpConnection : ITcpConnection /// public string LastTcpTemplate { get; } - /// /// Received data over duration of trace /// @@ -71,6 +71,24 @@ public class TcpConnection : ITcpConnection /// public ETWProcessIndex ProcessIdx { get; } + + /// + /// Time when data was last sent + /// + public DateTimeOffset? LastSent { get; internal set; } + + /// + /// Time when data was last received + /// + public DateTimeOffset? LastReceived { get; } + + + /// + /// Time when connection was closed due to retransmission timeout + /// + public DateTimeOffset? RetransmitTimeout { get; } + + /// /// Socket connect/disconnect time format string /// @@ -78,7 +96,7 @@ public class TcpConnection : ITcpConnection /// - /// Create an instance + /// Create an instance which is used also by Json.NET to deserialize this object. /// /// /// @@ -91,10 +109,13 @@ public class TcpConnection : ITcpConnection /// /// /// + /// + /// + /// /// When localipandPort or remoteipAndPort are null. public TcpConnection(ulong tcb, SocketConnection localipandPort, SocketConnection remoteipAndPort, DateTimeOffset? timeStampOpen, DateTimeOffset? timeStampClose, string lastTcpTemplate, ulong bytesSent, int datagramsSent, - ulong bytesReceived, int datagramsReceived, ETWProcessIndex processIdx) + ulong bytesReceived, int datagramsReceived, ETWProcessIndex processIdx, DateTimeOffset? retransmitTimeout, DateTimeOffset? lastSent, DateTimeOffset? lastReceived) { Tcb = tcb; LocalIpAndPort = localipandPort ?? throw new ArgumentNullException(nameof(localipandPort)); @@ -107,6 +128,9 @@ public TcpConnection(ulong tcb, SocketConnection localipandPort, SocketConnectio DatagramsSent = datagramsSent; DatagramsReceived = datagramsReceived; ProcessIdx = processIdx; + RetransmitTimeout = retransmitTimeout; + LastSent = lastSent; + LastReceived = lastReceived; } diff --git a/ETWAnalyzer/Extractors/TCP/TCPExtractor.cs b/ETWAnalyzer/Extractors/TCP/TCPExtractor.cs index 64950d2a..34bb350c 100644 --- a/ETWAnalyzer/Extractors/TCP/TCPExtractor.cs +++ b/ETWAnalyzer/Extractors/TCP/TCPExtractor.cs @@ -113,6 +113,9 @@ internal void ExtractFromGenericEvents(ETWExtract results, IGenericEvent[] event case TcpETWConstants.TcpCloseTcbRequest: OnClose(ev); break; + case TcpETWConstants.TcpDisconnectTcbRtoTimeout: + OnRetransmitTimeout(ev); + break; default: // Do nothing break; @@ -158,14 +161,14 @@ internal void ExtractFromGenericEvents(ETWExtract results, IGenericEvent[] event } ulong bytesReceived = (ulong)receivedByConnection[tcpconnection].Sum(x => (decimal)((TcpDataTransferReceive)x).NumBytes); - + var lastreceiveTime = receivedByConnection[tcpconnection].LastOrDefault()?.Timestamp; ulong bytesSent = (ulong)sentByConnection[tcpconnection].Sum(x => (decimal)((TcpDataSend)x).BytesSent); int datagramsReceived = receivedByConnection[tcpconnection].Count(); int datagramsSent = sentByConnection[tcpconnection].Count(); TcpConnection connection = new(tcpconnection.Tcb, tcpconnection.LocalIpAndPort, tcpconnection.RemoteIpAndPort, tcpconnection.TimeStampOpen, tcpconnection.TimeStampClose, - templates.LastOrDefault(), bytesSent, datagramsSent, bytesReceived, datagramsReceived, tcpconnection.ProcessIdx); + templates.LastOrDefault(), bytesSent, datagramsSent, bytesReceived, datagramsReceived, tcpconnection.ProcessIdx, tcpconnection.TCPRetansmitTimeout, null, lastreceiveTime); ConnectionIdx connIdx = results.Network.TcpData.AddConnection(connection); connect2Idx[tcpconnection] = connIdx; @@ -202,15 +205,25 @@ internal void ExtractFromGenericEvents(ETWExtract results, IGenericEvent[] event // Get all sent packets just before the current retransmit event // we need the last sent packet because the first packet often was an ACK with 0 send size - List retransmittedSent = sentByConnection[retrans.Connection].Where(x => x.SequenceNr == retrans.SndUna && x.Timestamp < retrans.Timestamp) + List retransmittedSent = sentByConnection[retrans.Connection].Where(x => x.SequenceNr == retrans.SndUna && x.Timestamp <= retrans.Timestamp) .OrderBy(x => x.Timestamp).ToList(); if( retransmittedSent.Count > 0) { + var lastSent = retransmittedSent.Last(); // this is the send which caused later retransmit events + // The application can issue further send events without canceling the current pending retransmissions + // store retransmit event with send time of first sent packet. It might be an ACK packet but for now the heuristics should be good enough // to be useful. results.Network.TcpData.Retransmissions.Add(new TcpRetransmission(connect2Idx[retrans.Connection], retrans.Timestamp, - retransmittedSent[0].Timestamp, retransmittedSent[0].SequenceNr, retransmittedSent[retransmittedSent.Count-1].BytesSent)); + lastSent.Timestamp, lastSent.SequenceNr, lastSent.BytesSent)); + + // set last send time before retransmissions did start + TcpConnection connection = results.Network.TcpData.Connections[(int)connect2Idx[retrans.Connection]]; + if (connection.RetransmitTimeout != null) // connection was closed due to retransmit + { + connection.LastSent = retransmittedSent.Last().Timestamp; // last send event + } } } } @@ -238,6 +251,29 @@ private void OnTcpConnectTcbFailedRcvdRst(IGenericEvent ev) } } + + readonly List myTcpDisconnectTcbRtoTimeout = new(); + + private void OnRetransmitTimeout(IGenericEvent ev) + { + TcpDisconnectTcbRtoTimeout rst = new(ev); + if( TCBFilter(rst.Tcb)) + { + myTcpDisconnectTcbRtoTimeout.Add(rst); + + ulong tcp = rst.Tcb; + + foreach(var connect in myConnections.OrderByDescending(x=> x.TimeStampOpen)) + { + if( connect.Tcb == tcp && connect.TimeStampOpen < rst.Timestamp && connect.TimeStampClose == null ) + { + connect.TCPRetansmitTimeout = rst.Timestamp; + break; + } + } + } + } + readonly List myTemplateChangedEvents = new(); private void OnTcpTemplateChanged(IGenericEvent ev) diff --git a/ETWAnalyzer/Extractors/TCP/TcpDisconnectTcbRtoTimeout.cs b/ETWAnalyzer/Extractors/TCP/TcpDisconnectTcbRtoTimeout.cs new file mode 100644 index 00000000..17411722 --- /dev/null +++ b/ETWAnalyzer/Extractors/TCP/TcpDisconnectTcbRtoTimeout.cs @@ -0,0 +1,38 @@ +//// SPDX-FileCopyrightText: © 2024 Siemens Healthcare GmbH +//// SPDX-License-Identifier: MIT + +using ETWAnalyzer.Extract.Network.Tcp; +using ETWAnalyzer.TraceProcessorHelpers; +using Microsoft.Windows.EventTracing.Events; +using System; + +namespace ETWAnalyzer.Extractors.TCP +{ + /// + /// Fired when connection is reset after the maximum number of retransmissions Microsoft-Windows-TCPIP/TcpConnectRestransmit in case of + /// connection establishment issues, or TcpDataTransferRetransmitRound after connecion has been established have occurred. + /// + internal class TcpDisconnectTcbRtoTimeout + { + // Fields: Tcb:Pointer, LocalIpAndPort, RemoteIpAndPort, Status, Compartment, ... + public ulong Tcb { get; set; } + + public DateTimeOffset Timestamp { get; set; } + + /// + /// not yet parsed. + /// + public int Compartment { get; private set; } + + public SocketConnection LocalIpAndPort { get; private set; } + public SocketConnection RemoteIpAndPort { get; private set; } + + public TcpDisconnectTcbRtoTimeout(IGenericEvent ev) + { + Tcb = (ulong)ev.Fields[TcpETWConstants.TcbField].AsAddress.Value; + Timestamp = ev.Timestamp.DateTimeOffset; + LocalIpAndPort = new SocketConnection(ev.Fields[TcpETWConstants.LocalAddressField].AsSocketAddress.ToIPEndPoint()); + RemoteIpAndPort = new SocketConnection(ev.Fields[TcpETWConstants.RemoteAddressField].AsSocketAddress.ToIPEndPoint()); + } + } +} diff --git a/ETWAnalyzer/Extractors/TCP/TcpRequestConnect.cs b/ETWAnalyzer/Extractors/TCP/TcpRequestConnect.cs index dffcef0a..6a0e40fe 100644 --- a/ETWAnalyzer/Extractors/TCP/TcpRequestConnect.cs +++ b/ETWAnalyzer/Extractors/TCP/TcpRequestConnect.cs @@ -1,19 +1,12 @@ //// SPDX-FileCopyrightText: © 2023 Siemens Healthcare GmbH //// SPDX-License-Identifier: MIT - using ETWAnalyzer.Extract; using ETWAnalyzer.Extract.Network.Tcp; using ETWAnalyzer.TraceProcessorHelpers; -using Microsoft.Windows.EventTracing; using Microsoft.Windows.EventTracing.Events; using System; using System.Collections.Generic; -using System.Linq; -using System.Net; -using System.Text; -using System.Threading; -using System.Threading.Tasks; namespace ETWAnalyzer.Extractors.TCP { @@ -97,6 +90,7 @@ internal class TcpRequestConnect : IEquatable public DateTimeOffset? TimeStampOpen { get; } public DateTimeOffset? TimeStampClose { get; internal set; } + public DateTimeOffset? TCPRetansmitTimeout { get; internal set; } public SocketConnection LocalIpAndPort { get; } public SocketConnection RemoteIpAndPort { get; } diff --git a/ETWAnalyzer/Infrastructure/ColumnDefinition.cs b/ETWAnalyzer/Infrastructure/ColumnDefinition.cs new file mode 100644 index 00000000..b29e79a8 --- /dev/null +++ b/ETWAnalyzer/Infrastructure/ColumnDefinition.cs @@ -0,0 +1,57 @@ +//// SPDX-FileCopyrightText: © 2024 Siemens Healthcare GmbH +//// SPDX-License-Identifier: MIT + +using System; +using System.Collections.Generic; +using System.Linq; +using System.Text; +using System.Threading.Tasks; + +namespace ETWAnalyzer.Infrastructure +{ + + /// + /// Defines an output column which can contain multiline data. + /// + internal class ColumnDefinition + { + /// + /// Column title which is printed to console + /// + public string Title { get; set; } + + /// + /// Symbolic name which is referenced by -Column property to enabled/disable specific columns + /// + public string Name { get; set; } + + /// + /// String which is printed at each row + /// + public string Prefix { get; set; } = ""; + + /// + /// Color in which the text is printed + /// + public ConsoleColor? Color { get; set; } + + /// + /// When false column will not be printed. + /// + public bool Enabled { get; set; } = true; + + + int myDataWidth; + /// + /// Column width excluding extra space to separate columns in output. + /// When zero then the column data is simply appended which in effect turns wrapping off. + /// Minimum non zero data width is 3 + /// + public int DataWidth + { + get => myDataWidth; + set => myDataWidth = value > 0 ? Math.Max(3, value) : Math.Max(0,value); + } + + } +} diff --git a/ETWAnalyzer/Infrastructure/ColumnFormatter.cs b/ETWAnalyzer/Infrastructure/ColumnFormatter.cs index 3cdac570..3764411c 100644 --- a/ETWAnalyzer/Infrastructure/ColumnFormatter.cs +++ b/ETWAnalyzer/Infrastructure/ColumnFormatter.cs @@ -1,4 +1,7 @@ -using System; +//// SPDX-FileCopyrightText: © 2024 Siemens Healthcare GmbH +//// SPDX-License-Identifier: MIT + +using System; using System.Collections.Generic; using System.Linq; using System.Text; diff --git a/ETWAnalyzer/Infrastructure/MultilineFormatter.cs b/ETWAnalyzer/Infrastructure/MultilineFormatter.cs new file mode 100644 index 00000000..657f7495 --- /dev/null +++ b/ETWAnalyzer/Infrastructure/MultilineFormatter.cs @@ -0,0 +1,178 @@ +//// SPDX-FileCopyrightText: © 2024 Siemens Healthcare GmbH +//// SPDX-License-Identifier: MIT + +using ETWAnalyzer.ProcessTools; +using System; +using System.Collections.Generic; +using System.Linq; + +namespace ETWAnalyzer.Infrastructure +{ + /// + /// The MultiLineFormatter class is responsible for printing multiline column data to the console with proper wrapping of output. + /// It is used to format and display tabular data in a visually appealing way. + /// + /// + /// The class has the following key features: + /// Columns Property: This property represents the columns that will be printed. It is an array of ColumnDefinition objects. + /// Constructor: The class has a constructor that accepts a variable number of ColumnDefinition objects.These objects define the properties of each column, such as the title, data width, and color. + /// Print Methods: The class provides two overloaded Print methods.The first method is used to print a line of data, and the second method is used to print column titles.Both methods accept a boolean parameter addNewline to indicate whether a new line should be added after printing. + /// Overall, the MultiLineFormatter class provides a convenient way to format and print multiline column data to the console, making it easier to display tabular data in a readable format. + /// + internal class MultiLineFormatter + { + /// + /// Columns which are printed. + /// + public ColumnDefinition[] Columns { get; set; } + + /// + /// Used for unit testing + /// + internal Action Printer = ColorConsole.Write; + + /// + /// Create a formatter with a given set of columns + /// + /// + public MultiLineFormatter(params ColumnDefinition[] columns) + { + Columns = columns; + } + + /// + /// Get wrapped data with proper alignment. Headers are left aligned, while row data is right aligned to get proper + /// number alignment. + /// + /// Starts with 0 + /// When header is true data is left aligned. + /// Row data to print. The count of columnData elements must match the number of (including disabled) columns. + /// List of column data to print with their column definitions. If line contains no data the list is empty. + /// + private List> GetCombinedFormattedLine(int lineNo, bool isHeader, params string[] columnData) + { + List> columns = new(); + + bool allEmpty = true; + int idx = 0; + foreach(ColumnDefinition curColumn in Columns) + { + if( columnData.Length <= idx ) + { + throw new NotSupportedException($"Data is missing for column {curColumn.Title}."); + } + + string stringToFormat = isHeader ? columnData[idx] : (String.IsNullOrEmpty(columnData[idx]) ? columnData[idx] : curColumn.Prefix + columnData[idx]); + + string nextData = curColumn.Enabled ? GetLine(curColumn, stringToFormat, lineNo, false) : null; + if( nextData != null) + { + columns.Add(new KeyValuePair(nextData, curColumn)); + allEmpty = (allEmpty && nextData == "") ? true : false; + } + + idx++; + } + + if( !allEmpty) + { + for (int i = 0; i < columns.Count; i++) + { + var current = columns[i]; + + if (current.Value.DataWidth > 0) + { + columns[i] = new KeyValuePair(columns[i].Key.WithWidth(isHeader ? (-1) * current.Value.DataWidth : current.Value.DataWidth) + " ", current.Value); + } + } + } + + if (allEmpty) + { + columns.Clear(); + } + + return columns; + } + + /// + /// Print a line of data + /// + /// Add after line was printed a new line + /// Data to print. + public void Print(bool addNewline, params string[] columnData) + { + Print(columnData, false); + if(addNewline) + { + Console.WriteLine(); + } + } + + /// + /// Print column titles to console + /// + /// By default a new line is printed after headers were printed. + public void PrintHeader(bool bPrintNewLine=true) + { + string[] headers = Columns.Select(x => x.Enabled ? x.Title : null).ToArray(); + Print(headers, true); + if( bPrintNewLine ) + { + Console.WriteLine(); + } + } + + /// + /// + /// + /// + /// + void Print(string[] columnData, bool isHeader) + { + int lineNo = 0; + while (true) + { + List> columns = GetCombinedFormattedLine(lineNo, isHeader, columnData.ToArray()); + + if (columns.Count == 0 ) + { + break; + } + + if (lineNo > 0) + { + Console.WriteLine(); + } + + foreach (var col in columns) + { + Printer(col.Key, col.Value.Color); + } + lineNo++; + } + } + + string GetLine(ColumnDefinition column, string str, int lineNo, bool isHeader) + { + if (!column.Enabled) + { + return null; + } + + if( String.IsNullOrEmpty(str) ) + { + return ""; + } + + string line = (lineNo == 0 && column.DataWidth == 0) ? str : ""; + if (column.DataWidth > 0) + { + int startIdx = lineNo * column.DataWidth; + int len = startIdx + column.DataWidth <= str.Length ? column.DataWidth : str.Length - startIdx; + line = startIdx >= str.Length ? "" : str.Substring(startIdx, len); + } + return line; + } + } +} diff --git a/ETWAnalyzer/Properties/AssemblyInfo.cs b/ETWAnalyzer/Properties/AssemblyInfo.cs index 38dcb90f..9b4c5752 100644 --- a/ETWAnalyzer/Properties/AssemblyInfo.cs +++ b/ETWAnalyzer/Properties/AssemblyInfo.cs @@ -42,4 +42,4 @@ // by using the '*' as shown below: // [assembly: AssemblyVersion("1.0.*")] [assembly: AssemblyVersion("1.0.0.0")] -[assembly: AssemblyFileVersion("3.0.0.9")] +[assembly: AssemblyFileVersion("3.0.0.10")] diff --git a/ETWAnalyzer/TraceProcessorHelpers/TcpETWConstants.cs b/ETWAnalyzer/TraceProcessorHelpers/TcpETWConstants.cs index dc9cf1fc..b8004428 100644 --- a/ETWAnalyzer/TraceProcessorHelpers/TcpETWConstants.cs +++ b/ETWAnalyzer/TraceProcessorHelpers/TcpETWConstants.cs @@ -96,6 +96,11 @@ public enum TCPIP_TEMPLATE_TYPES : UInt32 /// public const int TcpAcceptListenerComplete = 1017; + /// + /// Fields: LocalAddress:Binary RemoteAddress:Binary Status:UInt32 ProcessId:UInt32 Compartment:UInt32 Tcb:Pointer + /// + public const int TcpDisconnectTcbRtoTimeout = 1046; + /// /// Transfer Control block /// diff --git a/ETWAnalyzer_uTest/EventDump/DumpBaseTests.cs b/ETWAnalyzer_uTest/EventDump/DumpBaseTests.cs index 1ee8bc13..71462877 100644 --- a/ETWAnalyzer_uTest/EventDump/DumpBaseTests.cs +++ b/ETWAnalyzer_uTest/EventDump/DumpBaseTests.cs @@ -67,10 +67,10 @@ public void CanFormatHereTimeDate() var lTime = TimeZoneInfo.ConvertTimeFromUtc(new DateTime(2000, 1, 1, 1, 0, 0) - utcOffset, TimeZoneInfo.Local); - Assert.Equal(lTime.ToString(DumpBase.DateTimeFormat), hereDateTime); + Assert.Equal(lTime.ToString(DumpBase.DateTimeFormat3), hereDateTime); string hereTime = dmp.GetDateTimeString(time, sessionStart, TimeFormats.HereTime); - Assert.Equal(lTime.ToString(DumpBase.TimeFormat), hereTime); + Assert.Equal(lTime.ToString(DumpBase.TimeFormat3), hereTime); } [Fact] diff --git a/ETWAnalyzer_uTest/EventDump/DumpProcessesTests.cs b/ETWAnalyzer_uTest/EventDump/DumpProcessesTests.cs index 00cc8085..05dc0e78 100644 --- a/ETWAnalyzer_uTest/EventDump/DumpProcessesTests.cs +++ b/ETWAnalyzer_uTest/EventDump/DumpProcessesTests.cs @@ -158,8 +158,10 @@ public void Process_Filter_DisplaysJustMatchingProcesses_When_ParentFilter_Is_No testOutput.Flush(); string[] expectedOutput = new string[] { + "Proces Start T Stop T Duration Return Parent Process Command Line", + "sId ime ime Code ", "1/1/2000 12:00:00 AM test ", - "PID: 5001 Start: Stop: Duration: RCode: Parent: 5000 ImmortalChild.exe " + " 5001 Parent: 5000 ImmortalChild.exe ImmortalChild.exe" }; var lines = testOutput.GetSingleLines(); @@ -446,13 +448,15 @@ public void TestSortOrderSessionAndPrint_ShowTotalTotal() string[] expectedOutput = new string[] { - "1/1/0001 12:00:00 AM File3 " , - "PID: 111 Start: 2000-01-01 10:00:00.000 Stop: 2000-01-01 10:00:10.000 Duration: RCode: Parent: 11 Session: 1 User1 " , - "1/1/0001 12:00:00 AM File2 " , - "PID: 999 Start: 2000-01-01 10:00:00.000 Stop: 2000-01-01 10:00:40.000 Duration: RCode: Parent: 1 Session: 6 UserAdmin " , - "1/1/0001 12:00:00 AM File1 " , - "PID: 111 Start: 2000-01-01 10:00:00.000 Stop: 2000-01-01 10:01:00.000 Duration: RCode: Parent: 11 Session: 1 UserAdmin " , - "PID: 666 Start: 2000-01-01 10:00:00.000 Stop: 2000-01-01 10:00:05.000 Duration: RCode: Parent: 1 Session: 8 User100 ", + "Proces Start Time Stop Time Duration Return Sess User Parent Process Command Line", + "sId Code ion ", + "1/1/0001 12:00:00 AM File3 ", + " 111 Start: 2000-01-01 10:00:00.000 Stop: 2000-01-01 10:00:10.000 1 User1 Parent: 11 ", + "1/1/0001 12:00:00 AM File2 ", + " 999 Start: 2000-01-01 10:00:00.000 Stop: 2000-01-01 10:00:40.000 6 UserAdmin Parent: 1 ", + "1/1/0001 12:00:00 AM File1 ", + " 111 Start: 2000-01-01 10:00:00.000 Stop: 2000-01-01 10:01:00.000 1 UserAdmin Parent: 11 ", + " 666 Start: 2000-01-01 10:00:00.000 Stop: 2000-01-01 10:00:05.000 8 User100 Parent: 1 ", "FileTotals: 2 Processes, 0 new, 2 exited, 0 permanent in 2 sessions of 2 users.", "Totals: 4 Processes, 1 new, 3 exited, 1 permanent in 3 sessions of 3 users." }; @@ -483,20 +487,20 @@ public void TestSortOrderSessionAndPrint_ShowFileTotal() ShowTotal = ETWAnalyzer.Commands.DumpCommand.TotalModes.File, SortOrder = ETWAnalyzer.Commands.DumpCommand.SortOrders.Session, }; - dumper.Print(data); - testOutput.Flush(); string[] expectedOutput = new string[] { - "1/1/0001 12:00:00 AM File3 " , - "PID: 111 Start: 2000-01-01 10:00:00.000 Stop: 2000-01-01 10:00:10.000 Duration: RCode: Parent: 11 Session: 1 User1 " , - "1/1/0001 12:00:00 AM File2 " , - "PID: 999 Start: 2000-01-01 10:00:00.000 Stop: 2000-01-01 10:00:40.000 Duration: RCode: Parent: 1 Session: 6 UserAdmin " , - "1/1/0001 12:00:00 AM File1 " , - "PID: 111 Start: 2000-01-01 10:00:00.000 Stop: 2000-01-01 10:01:00.000 Duration: RCode: Parent: 11 Session: 1 UserAdmin " , - "PID: 666 Start: 2000-01-01 10:00:00.000 Stop: 2000-01-01 10:00:05.000 Duration: RCode: Parent: 1 Session: 8 User100 ", + "Proces Start Time Stop Time Duration Return Sess User Parent Process Command Line", + "sId Code ion ", + "1/1/0001 12:00:00 AM File3 ", + " 111 Start: 2000-01-01 10:00:00.000 Stop: 2000-01-01 10:00:10.000 1 User1 Parent: 11 ", + "1/1/0001 12:00:00 AM File2 ", + " 999 Start: 2000-01-01 10:00:00.000 Stop: 2000-01-01 10:00:40.000 6 UserAdmin Parent: 1 ", + "1/1/0001 12:00:00 AM File1 ", + " 111 Start: 2000-01-01 10:00:00.000 Stop: 2000-01-01 10:01:00.000 1 UserAdmin Parent: 11 ", + " 666 Start: 2000-01-01 10:00:00.000 Stop: 2000-01-01 10:00:05.000 8 User100 Parent: 1 ", "FileTotals: 2 Processes, 0 new, 2 exited, 0 permanent in 2 sessions of 2 users." }; @@ -534,13 +538,15 @@ public void TestSortOrderSessionAndPrint_ShowFileNone() string[] expectedOutput = new string[] { + "Proces Start Time Stop Time Duration Return Sess User Parent Process Command Line", + "sId Code ion ", "1/1/0001 12:00:00 AM File3 " , - "PID: 111 Start: 2000-01-01 10:00:00.000 Stop: 2000-01-01 10:00:10.000 Duration: RCode: Parent: 11 Session: 1 User1 " , + " 111 Start: 2000-01-01 10:00:00.000 Stop: 2000-01-01 10:00:10.000 1 User1 Parent: 11 " , "1/1/0001 12:00:00 AM File2 " , - "PID: 999 Start: 2000-01-01 10:00:00.000 Stop: 2000-01-01 10:00:40.000 Duration: RCode: Parent: 1 Session: 6 UserAdmin " , + " 999 Start: 2000-01-01 10:00:00.000 Stop: 2000-01-01 10:00:40.000 6 UserAdmin Parent: 1 " , "1/1/0001 12:00:00 AM File1 " , - "PID: 111 Start: 2000-01-01 10:00:00.000 Stop: 2000-01-01 10:01:00.000 Duration: RCode: Parent: 11 Session: 1 UserAdmin " , - "PID: 666 Start: 2000-01-01 10:00:00.000 Stop: 2000-01-01 10:00:05.000 Duration: RCode: Parent: 1 Session: 8 User100 " + " 111 Start: 2000-01-01 10:00:00.000 Stop: 2000-01-01 10:01:00.000 1 UserAdmin Parent: 11 " , + " 666 Start: 2000-01-01 10:00:00.000 Stop: 2000-01-01 10:00:05.000 8 User100 Parent: 1 " }; var lines = testOutput.GetSingleLines(); diff --git a/ETWAnalyzer_uTest/Extract/TcpExtractorTests.cs b/ETWAnalyzer_uTest/Extract/TcpExtractorTests.cs index 082aabae..54961c9b 100644 --- a/ETWAnalyzer_uTest/Extract/TcpExtractorTests.cs +++ b/ETWAnalyzer_uTest/Extract/TcpExtractorTests.cs @@ -173,19 +173,19 @@ public void CorrectlyAssignRetransmits_To_First_SentPacket() var tcpData = iExtract.Network.TcpData; Assert.Single(tcpData.Connections); - Assert.Equal(2, tcpData.Retransmissions.Count); + Assert.Equal(3, tcpData.Retransmissions.Count); var retrans0 = tcpData.Retransmissions[0]; Assert.Equal(100, retrans0.NumBytes); Assert.Equal((uint)SequenceNr.S_2000, retrans0.SequenceNumber); - Assert.Equal((long)Time.T0_4, retrans0.RetransmitTime.Ticks); + Assert.Equal((long)Time.T0_3, retrans0.RetransmitTime.Ticks); Assert.Equal((long)Time.T0_3, retrans0.SendTime.Ticks); var retrans1 = tcpData.Retransmissions[1]; Assert.Equal(100, retrans1.NumBytes); Assert.Equal((uint)SequenceNr.S_2000, retrans1.SequenceNumber); - Assert.Equal((long)Time.T0_5, retrans1.RetransmitTime.Ticks); - Assert.Equal((long)Time.T0_3, retrans1.SendTime.Ticks); + Assert.Equal((long)Time.T0_4, retrans1.RetransmitTime.Ticks); + Assert.Equal((long)Time.T0_4, retrans1.SendTime.Ticks); } @@ -318,7 +318,7 @@ public void Can_ExtractConnection_With_Retransmits() Assert.Equal((uint) SequenceNr.S_3000, retrans2.SequenceNumber); Assert.Equal(600, retrans2.NumBytes); Assert.Equal((long) Time.T2_8, retrans2.RetransmitTime.Ticks); - Assert.Equal((long) Time.T2_5, retrans2.SendTime.Ticks); + Assert.Equal((long) Time.T2_8, retrans2.SendTime.Ticks); } diff --git a/ETWAnalyzer_uTest/Infrastructure/MultilineFormatterTests.cs b/ETWAnalyzer_uTest/Infrastructure/MultilineFormatterTests.cs new file mode 100644 index 00000000..289f7432 --- /dev/null +++ b/ETWAnalyzer_uTest/Infrastructure/MultilineFormatterTests.cs @@ -0,0 +1,296 @@ +using ETWAnalyzer.Infrastructure; +using ETWAnalyzer_uTest.TestInfrastructure; +using System; +using System.Collections.Generic; +using Xunit; +using Xunit.Abstractions; + +namespace ETWAnalyzer_uTest.Infrastructure +{ + public class MultilineFormatterTests + { + private ITestOutputHelper myWriter; + public MultilineFormatterTests(ITestOutputHelper myWriter) + { + this.myWriter = myWriter; + } + + List Columns { get; set; } = new(); + + private void ColumnPrinter(string str, ConsoleColor? color) + { + Columns.Add(str); + } + + [Fact] + public void CanFormat_ShortHeader() + { + MultiLineFormatter formatter = new( + new ColumnDefinition() + { + Enabled = true, + Title = "1234", + DataWidth = 5, + }) + { + Printer = ColumnPrinter + }; + Columns.Clear(); + + formatter.PrintHeader(); + + Assert.Single(Columns); + Assert.Equal("1234 ", Columns[0]); + + Columns.Clear(); + formatter.Columns[0].Enabled = false; + formatter.PrintHeader(); + Assert.Empty(Columns); + } + + [Fact] + public void CanFormat_EqualHeader() + { + MultiLineFormatter formatter = new( + new ColumnDefinition() + { + Enabled = true, + Title = "12345", + DataWidth = 5, // column width includes space + }) + { + Printer = ColumnPrinter + }; + Columns.Clear(); + + formatter.PrintHeader(); + Assert.Single(Columns); + Assert.Equal("12345 ", Columns[0]); + + Columns.Clear(); + + formatter.Columns[0].Enabled = false; + formatter.PrintHeader(); + Assert.Empty(Columns); + } + + [Fact] + public void CanFormat_LargerHeader() + { + MultiLineFormatter formatter = new( + new ColumnDefinition() + { + Enabled = true, + Title = "123456", + DataWidth = 5, + }) + { + Printer = ColumnPrinter + }; + + Columns.Clear(); + formatter.PrintHeader(); + + Assert.Equal(2, Columns.Count); + Assert.Equal("12345 ", Columns[0]); + Assert.Equal("6 ", Columns[1]); + } + + [Fact] + public void Can_Format_LargeChainedHeader() + { + MultiLineFormatter formatter = new( + new() + { + Enabled = true, + Title = "123456", + DataWidth = 5, + }, + new() + { + Enabled = true, + Title = "321", + DataWidth = 5, + }, + new() + { + Enabled = true, + Title = "21", + DataWidth = 5, + }) + { + Printer = ColumnPrinter + }; + + Columns.Clear(); + formatter.PrintHeader(); + + Assert.Equal(6, Columns.Count); + + Assert.Equal("12345 ", Columns[0]); + Assert.Equal("6 ", Columns[3]); + Assert.Equal("321 ", Columns[1]); + Assert.Equal(" ", Columns[4]); + Assert.Equal("21 ", Columns[2]); + Assert.Equal(" ", Columns[5]); + } + + + [Fact] + public void Can_Format_LargeChainedHeader_WithDisabled() + { + MultiLineFormatter formatter = new( + new() + { + Enabled = false, + Title = "123456", + DataWidth = 5, + }, + new() + { + Enabled = true, + Title = "321", + DataWidth = 5, + }, + new() + { + Enabled = true, + Title = "21", + DataWidth = 5, + }) + { + Printer = ColumnPrinter + }; + + Columns.Clear(); + formatter.PrintHeader(); + + Assert.Equal(2, Columns.Count); + Assert.Equal("321 ", Columns[0]); + Assert.Equal("21 ", Columns[1]); + } + + + [Fact] + public void Can_FormatChained_Data() + { + using var testOutput = new ExceptionalPrinter(myWriter, true); + + MultiLineFormatter formatter = new( + new() + { + Enabled = true, + Title = "Header1", + DataWidth = 8, + }, + new() + { + Enabled = true, + Title = "Header2", + DataWidth = 9, + }, + new() + { + Enabled = true, + Title = "Header3", + DataWidth = 7, + Color = ConsoleColor.Red, + } + ); + + formatter.PrintHeader(); + Console.WriteLine(); + + string[] columnData = new string[] { "ColData1", "ColData2", "ColData3" }; + + formatter.Print(false, columnData); + + formatter.Printer = ColumnPrinter; + Columns.Clear(); + + /* + Header1 Header2 Header + 3 + ColData ColData2 ColDat + 1 a3 + */ + + formatter.PrintHeader(); + Assert.Equal(3, Columns.Count); + + Assert.Equal("Header1 ", Columns[0]); + Assert.Equal("Header2 ", Columns[1]); + Assert.Equal("Header3 ", Columns[2]); + + Columns.Clear(); + formatter.Print(false, columnData); ; + Assert.Equal(6, Columns.Count); + + Assert.Equal("ColData1 ", Columns[0]); + Assert.Equal(" ", Columns[3]); + Assert.Equal(" ColData2 ", Columns[1]); + Assert.Equal(" ", Columns[4]); + Assert.Equal("ColData ", Columns[2]); + Assert.Equal(" 3 ", Columns[5]); + + + } + + + [Fact] + public void CanFormat_PrefixedData() + { + using var testOutput = new ExceptionalPrinter(myWriter, true); + + MultiLineFormatter formatter = new( + new() + { + Enabled = true, + Title = "Header1", + Prefix = "", + DataWidth = 5, + }, + new() + { + Enabled = true, + Title = "Header2", + Prefix = "Pref2: ", + DataWidth = 5, + } + ); + + string[] colData = new string[] { "Data1", "Data2" }; + + /* + Heade Heade + r1 r2 + Data1 Pref2 + : Dat + a2 + */ + + formatter.PrintHeader(); + formatter.Print(true, colData); + + formatter.Printer = ColumnPrinter; + Columns.Clear(); + + formatter.PrintHeader(); + Assert.Equal(4, Columns.Count); + Assert.Equal("Heade ", Columns[0]); + Assert.Equal("r1 ", Columns[2]); + Assert.Equal("Heade ", Columns[1]); + Assert.Equal("r2 ", Columns[3]); + + Columns.Clear(); + formatter.Print(true, colData); + Assert.Equal(6, Columns.Count); + Assert.Equal("Data1 ", Columns[0]); + Assert.Equal(" ", Columns[2]); + Assert.Equal(" ", Columns[4]); + Assert.Equal("Pref2 ", Columns[1]); + Assert.Equal(": Dat ", Columns[3]); + Assert.Equal(" a2 ", Columns[5]); + } + } +}