diff --git a/.gitignore b/.gitignore index 0e945e0..8cec0ea 100644 --- a/.gitignore +++ b/.gitignore @@ -1,3 +1,4 @@ bin/ obj/ .idea/ +.DS_Store \ No newline at end of file diff --git a/src/Directory.Build.props b/src/Directory.Build.props index 7989127..ca305db 100644 --- a/src/Directory.Build.props +++ b/src/Directory.Build.props @@ -1,7 +1,7 @@ - 0.0.14 - Tony Redondo + 0.0.15 + Tony Redondo, Grégory Léocadie net5.0;net6.0;net7.0 enable enable diff --git a/src/TimeIt.RuntimeMetrics/TimeIt.RuntimeMetrics.csproj b/src/TimeIt.RuntimeMetrics/TimeIt.RuntimeMetrics.csproj deleted file mode 100644 index 653ff9d..0000000 --- a/src/TimeIt.RuntimeMetrics/TimeIt.RuntimeMetrics.csproj +++ /dev/null @@ -1,8 +0,0 @@ - - - - netstandard2.0 - - - - diff --git a/src/TimeIt.RuntimeMetrics/FileStatsd.cs b/src/TimeIt.StartupHook/RuntimeMetrics/FileStorage.cs similarity index 65% rename from src/TimeIt.RuntimeMetrics/FileStatsd.cs rename to src/TimeIt.StartupHook/RuntimeMetrics/FileStorage.cs index f6a5e9c..6472db9 100644 --- a/src/TimeIt.RuntimeMetrics/FileStatsd.cs +++ b/src/TimeIt.StartupHook/RuntimeMetrics/FileStorage.cs @@ -3,35 +3,35 @@ namespace TimeIt.RuntimeMetrics; -public class FileStatsd +public class FileStorage { private readonly StreamWriter _streamWriter; - public FileStatsd(string filePath) + public FileStorage(string filePath) { _streamWriter = new StreamWriter(filePath, true); } [MethodImpl(MethodImplOptions.AggressiveInlining)] - public void Counter(string statName, double value, double sampleRate = 1, string[]? tags = null) + public void Counter(string statName, double value) { WritePayload("counter", statName, value); } [MethodImpl(MethodImplOptions.AggressiveInlining)] - public void Gauge(string statName, double value, double sampleRate = 1, string[]? tags = null) + public void Gauge(string statName, double value) { WritePayload("gauge", statName, value); } [MethodImpl(MethodImplOptions.AggressiveInlining)] - public void Increment(string statName, int value = 1, double sampleRate = 1, string[]? tags = null) + public void Increment(string statName, int value = 1) { WritePayload("increment", statName, value); } [MethodImpl(MethodImplOptions.AggressiveInlining)] - public void Timer(string statName, double value, double sampleRate = 1, string[]? tags = null) + public void Timer(string statName, double value) { WritePayload("timer", statName, value); } @@ -49,17 +49,9 @@ private void WritePayload(string type, string name, double value) { lock (_streamWriter) { - _streamWriter.Write("{ \"type\": "); - if (type is null) - { - _streamWriter.Write("null, "); - } - else - { - _streamWriter.Write("\""); - _streamWriter.Write(type); - _streamWriter.Write("\", "); - } + _streamWriter.Write("{ \"type\": \""); + _streamWriter.Write(type); + _streamWriter.Write("\", "); _streamWriter.Write("\"name\": "); if (name is null) diff --git a/src/TimeIt.RuntimeMetrics/HeapHistory.cs b/src/TimeIt.StartupHook/RuntimeMetrics/HeapHistory.cs similarity index 100% rename from src/TimeIt.RuntimeMetrics/HeapHistory.cs rename to src/TimeIt.StartupHook/RuntimeMetrics/HeapHistory.cs diff --git a/src/TimeIt.RuntimeMetrics/HeapStats.cs b/src/TimeIt.StartupHook/RuntimeMetrics/HeapStats.cs similarity index 100% rename from src/TimeIt.RuntimeMetrics/HeapStats.cs rename to src/TimeIt.StartupHook/RuntimeMetrics/HeapStats.cs diff --git a/src/TimeIt.RuntimeMetrics/Keywords.cs b/src/TimeIt.StartupHook/RuntimeMetrics/Keywords.cs similarity index 100% rename from src/TimeIt.RuntimeMetrics/Keywords.cs rename to src/TimeIt.StartupHook/RuntimeMetrics/Keywords.cs diff --git a/src/TimeIt.RuntimeMetrics/MetricsName.cs b/src/TimeIt.StartupHook/RuntimeMetrics/MetricsName.cs similarity index 100% rename from src/TimeIt.RuntimeMetrics/MetricsName.cs rename to src/TimeIt.StartupHook/RuntimeMetrics/MetricsName.cs diff --git a/src/TimeIt.RuntimeMetrics/ProcessHelpers.cs b/src/TimeIt.StartupHook/RuntimeMetrics/ProcessHelpers.cs similarity index 93% rename from src/TimeIt.RuntimeMetrics/ProcessHelpers.cs rename to src/TimeIt.StartupHook/RuntimeMetrics/ProcessHelpers.cs index a0a6812..59c5244 100644 --- a/src/TimeIt.RuntimeMetrics/ProcessHelpers.cs +++ b/src/TimeIt.StartupHook/RuntimeMetrics/ProcessHelpers.cs @@ -7,6 +7,8 @@ namespace TimeIt.RuntimeMetrics; public static class ProcessHelpers { + private static readonly Process CurrentProcess = Process.GetCurrentProcess(); + /// /// Wrapper around and its property accesses /// @@ -29,11 +31,11 @@ public static void GetCurrentProcessRuntimeMetrics( out int threadCount, out long privateMemorySize) { - using var process = Process.GetCurrentProcess(); + var process = CurrentProcess; userProcessorTime = process.UserProcessorTime; systemCpuTime = process.PrivilegedProcessorTime; - totalProcessorTime = systemCpuTime + userProcessorTime; threadCount = process.Threads.Count; privateMemorySize = process.PrivateMemorySize64; + totalProcessorTime = systemCpuTime + userProcessorTime; } } \ No newline at end of file diff --git a/src/TimeIt.StartupHook/RuntimeMetrics/RuntimeEventListener.cs b/src/TimeIt.StartupHook/RuntimeMetrics/RuntimeEventListener.cs index 5ec988e..775a989 100644 --- a/src/TimeIt.StartupHook/RuntimeMetrics/RuntimeEventListener.cs +++ b/src/TimeIt.StartupHook/RuntimeMetrics/RuntimeEventListener.cs @@ -12,30 +12,23 @@ class RuntimeEventListener : EventListener private const string RuntimeEventSourceName = "Microsoft-Windows-DotNETRuntime"; private const string AspNetCoreHostingEventSourceName = "Microsoft.AspNetCore.Hosting"; private const string AspNetCoreKestrelEventSourceName = "Microsoft-AspNetCore-Server-Kestrel"; - private const int EventGcSuspendBegin = 9; private const int EventGcRestartEnd = 3; private const int EventGcHeapStats = 4; private const int EventContentionStop = 91; private const int EventGcGlobalHeapHistory = 205; - private static readonly string[] GcCountMetricNames = { MetricsNames.Gen0CollectionsCount, MetricsNames.Gen1CollectionsCount, MetricsNames.Gen2CollectionsCount }; - - private readonly FileStatsd _statsd; - + private readonly FileStorage _storage; private readonly Timing _contentionTime = new(); - private readonly string _delayInSeconds; private long _contentionCount; - private DateTime? _gcStart; - public RuntimeEventListener(FileStatsd statsd, TimeSpan delay) + public RuntimeEventListener(FileStorage storage, TimeSpan delay) { - _statsd = statsd; + _storage = storage; _delayInSeconds = ((int)delay.TotalSeconds).ToString(); - EventSourceCreated += (_, e) => EnableEventSource(e.EventSource); } @@ -43,15 +36,14 @@ public void Refresh() { // Can't use a Timing because Dogstatsd doesn't support local aggregation // It means that the aggregations in the UI would be wrong - _statsd.Gauge(MetricsNames.ContentionTime, _contentionTime.Clear()); - _statsd.Counter(MetricsNames.ContentionCount, Interlocked.Exchange(ref _contentionCount, 0)); - - _statsd.Gauge(MetricsNames.ThreadPoolWorkersCount, ThreadPool.ThreadCount); + _storage.Gauge(MetricsNames.ContentionTime, _contentionTime.Clear()); + _storage.Counter(MetricsNames.ContentionCount, Interlocked.Exchange(ref _contentionCount, 0)); + _storage.Gauge(MetricsNames.ThreadPoolWorkersCount, ThreadPool.ThreadCount); } protected override void OnEventWritten(EventWrittenEventArgs eventData) { - if (_statsd == null) + if (_storage == null) { // I know it sounds crazy at first, but because OnEventSourceCreated is called from the base constructor, // and EnableEvents is called from OnEventSourceCreated, it's entirely possible that OnEventWritten @@ -74,7 +66,7 @@ protected override void OnEventWritten(EventWrittenEventArgs eventData) { if (_gcStart is { } start) { - _statsd.Timer(MetricsNames.GcPauseTime, (eventData.TimeStamp - start).TotalMilliseconds); + _storage.Timer(MetricsNames.GcPauseTime, (eventData.TimeStamp - start).TotalMilliseconds); } } else @@ -83,10 +75,10 @@ protected override void OnEventWritten(EventWrittenEventArgs eventData) { var stats = HeapStats.FromPayload(eventData.Payload); - _statsd.Gauge(MetricsNames.Gen0HeapSize, stats.Gen0Size); - _statsd.Gauge(MetricsNames.Gen1HeapSize, stats.Gen1Size); - _statsd.Gauge(MetricsNames.Gen2HeapSize, stats.Gen2Size); - _statsd.Gauge(MetricsNames.LohSize, stats.LohSize); + _storage.Gauge(MetricsNames.Gen0HeapSize, stats.Gen0Size); + _storage.Gauge(MetricsNames.Gen1HeapSize, stats.Gen1Size); + _storage.Gauge(MetricsNames.Gen2HeapSize, stats.Gen2Size); + _storage.Gauge(MetricsNames.LohSize, stats.LohSize); } else if (eventData.EventId == EventContentionStop) { @@ -101,14 +93,24 @@ protected override void OnEventWritten(EventWrittenEventArgs eventData) if (heapHistory.MemoryLoad is { } memoryLoad) { - _statsd.Gauge(MetricsNames.GcMemoryLoad, memoryLoad); + _storage.Gauge(MetricsNames.GcMemoryLoad, memoryLoad); } - _statsd.Increment(GcCountMetricNames[heapHistory.Generation], 1); - - if (heapHistory.Compacting && heapHistory.Generation == 2) + if (heapHistory.Generation == 0) + { + _storage.Increment(MetricsNames.Gen0CollectionsCount, 1); + } + else if (heapHistory.Generation == 1) { - _statsd.Increment(MetricsNames.Gen2CompactingCollectionsCount, 1); + _storage.Increment(MetricsNames.Gen1CollectionsCount, 1); + } + else if (heapHistory.Generation == 2) + { + _storage.Increment(MetricsNames.Gen2CollectionsCount, 1); + if (heapHistory.Compacting) + { + _storage.Increment(MetricsNames.Gen2CompactingCollectionsCount, 1); + } } } } @@ -130,12 +132,10 @@ private void EnableEventSource(EventSource eventSource) } else if (eventSource.Name is AspNetCoreHostingEventSourceName or AspNetCoreKestrelEventSourceName) { - var settings = new Dictionary + EnableEvents(eventSource, EventLevel.Critical, EventKeywords.All, new Dictionary { ["EventCounterIntervalSec"] = _delayInSeconds - }; - - EnableEvents(eventSource, EventLevel.Critical, EventKeywords.All, settings); + }); } } @@ -162,7 +162,7 @@ private void ExtractCounters(ReadOnlyCollection payload) if (eventPayload.TryGetValue("Mean", out var rawValue) || eventPayload.TryGetValue("Increment", out rawValue)) { - _statsd.Gauge(statName, (double)rawValue); + _storage.Gauge(statName, (double)rawValue); } } } diff --git a/src/TimeIt.StartupHook/RuntimeMetrics/RuntimeMetricsWriter.cs b/src/TimeIt.StartupHook/RuntimeMetrics/RuntimeMetricsWriter.cs index 161f51b..a13e873 100644 --- a/src/TimeIt.StartupHook/RuntimeMetrics/RuntimeMetricsWriter.cs +++ b/src/TimeIt.StartupHook/RuntimeMetrics/RuntimeMetricsWriter.cs @@ -1,5 +1,4 @@ -using System.Collections.Concurrent; -using System.Runtime.ExceptionServices; +using System.Runtime.ExceptionServices; #nullable disable @@ -7,10 +6,8 @@ namespace TimeIt.RuntimeMetrics; internal class RuntimeMetricsWriter : IDisposable { - private static readonly Func InitializeListenerFunc = InitializeListener; - private readonly TimeSpan _delay; - private readonly FileStatsd _statsd; + private readonly FileStorage _storage; private readonly Timer _timer; private readonly RuntimeEventListener _listener; private readonly bool _enableProcessMetrics; @@ -20,15 +17,10 @@ internal class RuntimeMetricsWriter : IDisposable private TimeSpan _previousTotalCpu; private int _exceptionCounts; - public RuntimeMetricsWriter(FileStatsd statsd, TimeSpan delay) - : this(statsd, delay, InitializeListenerFunc) - { - } - - internal RuntimeMetricsWriter(FileStatsd statsd, TimeSpan delay, Func initializeListener) + internal RuntimeMetricsWriter(FileStorage storage, TimeSpan delay) { _delay = delay; - _statsd = statsd; + _storage = storage; _timer = new Timer(_ => PushEvents(), null, delay, delay); try @@ -43,7 +35,6 @@ internal RuntimeMetricsWriter(FileStatsd statsd, TimeSpan delay, Func 0) { - _statsd.Increment(MetricsNames.ExceptionsCount, exceptionCounts); + _storage.Increment(MetricsNames.ExceptionsCount, exceptionCounts); } } catch @@ -121,11 +113,6 @@ internal void PushEvents() } } - private static RuntimeEventListener InitializeListener(FileStatsd statsd, TimeSpan delay) - { - return new RuntimeEventListener(statsd, delay); - } - private void FirstChanceException(object sender, FirstChanceExceptionEventArgs e) { Interlocked.Increment(ref _exceptionCounts); diff --git a/src/TimeIt.RuntimeMetrics/Timing.cs b/src/TimeIt.StartupHook/RuntimeMetrics/Timing.cs similarity index 100% rename from src/TimeIt.RuntimeMetrics/Timing.cs rename to src/TimeIt.StartupHook/RuntimeMetrics/Timing.cs diff --git a/src/TimeIt.StartupHook/RuntimeMetricsInitializer.cs b/src/TimeIt.StartupHook/RuntimeMetricsInitializer.cs deleted file mode 100644 index 6990e29..0000000 --- a/src/TimeIt.StartupHook/RuntimeMetricsInitializer.cs +++ /dev/null @@ -1,28 +0,0 @@ -using TimeIt; -using TimeIt.RuntimeMetrics; - -class RuntimeMetricsInitializer -{ - private readonly RuntimeMetricsWriter? MetricsWriter; - - public RuntimeMetricsInitializer(DateTime startDate) - { - if (Environment.GetEnvironmentVariable(Constants.TimeItMetricsTemporalPathEnvironmentVariable) is - { Length: > 0 } metricsPath) - { - var fileStatsd = new FileStatsd(metricsPath); - fileStatsd.Gauge(Constants.ProcessStartTimeUtcMetricName, startDate.ToBinary()); - MetricsWriter = new RuntimeMetricsWriter(fileStatsd, TimeSpan.FromMilliseconds(50)); - MetricsWriter.PushEvents(); - - AppDomain.CurrentDomain.ProcessExit += (sender, args) => - { - fileStatsd.Gauge(Constants.ProcessEndTimeUtcMetricName, Clock.UtcNow.ToBinary()); - MetricsWriter.PushEvents(); - fileStatsd.Dispose(); - }; - - fileStatsd.Gauge(Constants.MainMethodStartTimeUtcMetricName, Clock.UtcNow.ToBinary()); - } - } -} \ No newline at end of file diff --git a/src/TimeIt.StartupHook/StartupHook.cs b/src/TimeIt.StartupHook/StartupHook.cs index 463b61b..db5f932 100644 --- a/src/TimeIt.StartupHook/StartupHook.cs +++ b/src/TimeIt.StartupHook/StartupHook.cs @@ -1,48 +1,34 @@ -using System.Reflection; -using System.Runtime.Loader; +using TimeIt; +using TimeIt.RuntimeMetrics; public class StartupHook { - private static object? _runtimeMetrics; - private static Assembly? _runtimeMetricsAssemblyCache; - private static string? _hookFolder; + private static RuntimeMetricsWriter? _metricsWriter; + private static FileStorage? _fileStatsd; public static void Initialize() { var startDate = Clock.UtcNow; - _hookFolder = Path.GetDirectoryName(typeof(StartupHook).Assembly.Location) ?? string.Empty; - AssemblyLoadContext.Default.Resolving += DefaultOnResolving; - _runtimeMetrics = new RuntimeMetricsInitializer(startDate); - } - - private static Assembly? DefaultOnResolving(AssemblyLoadContext ctx, AssemblyName assemblyName) - { - if (_hookFolder is null) + if (Environment.GetEnvironmentVariable(Constants.TimeItMetricsTemporalPathEnvironmentVariable) is + { Length: > 0 } metricsPath) { - return null; + _fileStatsd = new FileStorage(metricsPath); + _fileStatsd.Gauge(Constants.ProcessStartTimeUtcMetricName, startDate.ToBinary()); + _metricsWriter = new RuntimeMetricsWriter(_fileStatsd, TimeSpan.FromMilliseconds(50)); + _metricsWriter.PushEvents(); + AppDomain.CurrentDomain.ProcessExit += CurrentDomainOnProcessExit; + _fileStatsd.Gauge(Constants.MainMethodStartTimeUtcMetricName, Clock.UtcNow.ToBinary()); } + } - const string runtimeMetricsAssemblyName = "TimeIt.RuntimeMetrics"; - if (assemblyName.Name?.Equals(runtimeMetricsAssemblyName, StringComparison.Ordinal) == true) - { - if (_runtimeMetricsAssemblyCache is null) - { - var assemblyRuntimeMetricsPath = Path.Combine(_hookFolder, runtimeMetricsAssemblyName + ".dll"); - if (File.Exists(assemblyRuntimeMetricsPath)) - { - _runtimeMetricsAssemblyCache = ctx.LoadFromAssemblyPath(assemblyRuntimeMetricsPath); - } - } - - return _runtimeMetricsAssemblyCache; - } - - var otherAssemblies = Path.Combine(_hookFolder, assemblyName.Name + ".dll"); - if (File.Exists(otherAssemblies) && AssemblyName.GetAssemblyName(otherAssemblies).Version == assemblyName.Version) + private static void CurrentDomainOnProcessExit(object? sender, EventArgs e) + { + if (_fileStatsd is { } fileStatsd) { - return ctx.LoadFromAssemblyPath(otherAssemblies); + fileStatsd.Gauge(Constants.MainMethodEndTimeUtcMetricName, Clock.UtcNow.ToBinary()); + _metricsWriter?.PushEvents(); + fileStatsd.Gauge(Constants.ProcessEndTimeUtcMetricName, Clock.UtcNow.ToBinary()); + fileStatsd.Dispose(); } - - return null; } } \ No newline at end of file diff --git a/src/TimeIt.StartupHook/TimeIt.StartupHook.csproj b/src/TimeIt.StartupHook/TimeIt.StartupHook.csproj index dd5c935..aac9a16 100644 --- a/src/TimeIt.StartupHook/TimeIt.StartupHook.csproj +++ b/src/TimeIt.StartupHook/TimeIt.StartupHook.csproj @@ -10,8 +10,5 @@ - - - diff --git a/src/TimeIt/ConsoleExporter.cs b/src/TimeIt/ConsoleExporter.cs index 9f21509..53fb7e1 100644 --- a/src/TimeIt/ConsoleExporter.cs +++ b/src/TimeIt/ConsoleExporter.cs @@ -105,14 +105,16 @@ public void Export(IEnumerable results) "[dodgerblue1 bold]Outliers[/]"); // Add rows - foreach (var result in results) + var resultsList = results.ToList(); + for (var idx = 0; idx < resultsList.Count; idx++) { + var result = resultsList[idx]; var totalNum = result.MetricsData.Count; if (totalNum > 0) { summaryTable.AddRow( - $"[aqua]{result.Name}[/]", + $"[aqua underline]{result.Name}[/]", $"[aqua]{Utils.FromNanosecondsToMilliseconds(result.Mean)}ms[/]", $"[aqua]{Utils.FromNanosecondsToMilliseconds(result.Stdev)}ms[/]", $"[aqua]{Utils.FromNanosecondsToMilliseconds(result.StdErr)}ms[/]", @@ -145,11 +147,11 @@ public void Export(IEnumerable results) string name; if (i < totalNum - 1) { - name = "├>" + item.Key; + name = " ├>" + item.Key; } else { - name = "└>" + item.Key; + name = " └>" + item.Key; } summaryTable.AddRow( @@ -163,16 +165,6 @@ public void Export(IEnumerable results) Math.Round(mP90, 6).ToString(), outliersCount?.ToString() ?? "N/A"); } - - summaryTable.AddRow( - string.Empty, - string.Empty, - string.Empty, - string.Empty, - string.Empty, - string.Empty, - string.Empty, - string.Empty); } else { diff --git a/src/TimeIt/Constants.cs b/src/TimeIt/Constants.cs index 351bd6e..699463c 100644 --- a/src/TimeIt/Constants.cs +++ b/src/TimeIt/Constants.cs @@ -6,11 +6,15 @@ public static class Constants public const string StartupHookEnvironmentVariable = "DOTNET_STARTUP_HOOKS"; public const string TimeItMetricsTemporalPathEnvironmentVariable = "TIMEIT_METRICS_TEMPORAL_PATH"; public const string ProcessTimeToStartMetricName = "process.time_to_start_ms"; - public const string ProcessTimeToMainMetricName = "process.time_to_main_ms"; + public const string ProcessTimeToMainMetricName = "process.time_to_main_ms"; public const string ProcessTimeToEndMetricName = "process.time_to_end_ms"; + public const string ProcessTimeToMainEndMetricName = "process.time_to_end_main_ms"; public const string ProcessInternalDurationMetricName = "process.internal_duration_ms"; + public const string ProcessCorrectedDurationMetricName = "process.corrected_duration_ms"; + public const string ProcessStartupHookOverheadMetricName = "process.startuphook_overhead_ms"; public const string ProcessStartTimeUtcMetricName = "process.start"; public const string MainMethodStartTimeUtcMetricName = "main.start"; + public const string MainMethodEndTimeUtcMetricName = "main.end"; public const string ProcessEndTimeUtcMetricName = "process.end"; } #endif \ No newline at end of file diff --git a/src/TimeIt/Program.cs b/src/TimeIt/Program.cs index fd49b46..479c690 100644 --- a/src/TimeIt/Program.cs +++ b/src/TimeIt/Program.cs @@ -6,7 +6,7 @@ using TimeIt.DatadogExporter; using System.CommandLine; -AnsiConsole.MarkupLine("[bold dodgerblue1 underline]TimeIt (v. {0}) by Tony Redondo[/]\n", typeof(Utils).Assembly.GetName().Version?.ToString() ?? "unknown"); +AnsiConsole.MarkupLine("[bold dodgerblue1 underline]TimeIt v{0}[/]", GetVersion()); var argument = new Argument("configuration file", "The JSON configuration file"); var templateVariables = new Option("--variable", isDefault: true, description: "Variables used to instantiate the configuration file", @@ -134,3 +134,16 @@ await root.InvokeAsync(args); + +return; + +static string GetVersion() +{ + var version = typeof(Utils).Assembly.GetName().Version; + if (version is null) + { + return "unknown"; + } + + return $"{version.Major}.{version.Minor}.{version.Build}"; +} diff --git a/src/TimeIt/ScenarioProcessor.cs b/src/TimeIt/ScenarioProcessor.cs index d169a20..48ca99a 100644 --- a/src/TimeIt/ScenarioProcessor.cs +++ b/src/TimeIt/ScenarioProcessor.cs @@ -8,7 +8,6 @@ using Spectre.Console; using TimeIt.Common.Configuration; using TimeIt.Common.Results; -using TimeIt.RuntimeMetrics; namespace TimeIt; @@ -419,6 +418,7 @@ private static async Task RunCommandAsync(Scenario scenario) { DateTime? inProcStartDate = null; DateTime? inProcMainStartDate = null; + DateTime? inProcMainEndDate = null; DateTime? inProcEndDate = null; var metrics = new Dictionary(); var metricsCount = new Dictionary(); @@ -428,12 +428,43 @@ private static async Task RunCommandAsync(Scenario scenario) { if (metricItem.Name is not null) { + static void EnsureMainDuration(Dictionary values, DateTime? mainStartDate, DateTime? mainEndDate) + { + if (mainStartDate is not null && mainEndDate is not null) + { + values[Constants.ProcessInternalDurationMetricName] = + (mainEndDate.Value - mainStartDate.Value).TotalMilliseconds; + } + } + + static void EnsureStartupHookOverhead( + DataPoint point, + Dictionary values, + DateTime? startDate, + DateTime? mainStartDate, + DateTime? mainEndDate, + DateTime? endDate) + { + if (startDate is not null && + mainStartDate is not null && + mainEndDate is not null && + endDate is not null) + { + var mainDuration = (mainEndDate.Value - mainStartDate.Value).TotalMilliseconds; + var internalDuration = (endDate.Value - startDate.Value).TotalMilliseconds; + var overheadDuration = internalDuration - mainDuration; + var globalDuration = (point.End - point.Start).TotalMilliseconds; + values[Constants.ProcessStartupHookOverheadMetricName] = overheadDuration; + values[Constants.ProcessCorrectedDurationMetricName] = globalDuration - overheadDuration; + } + } + if (metricItem.Name == Constants.ProcessStartTimeUtcMetricName) { inProcStartDate = DateTime.FromBinary((long)metricItem.Value); metrics[Constants.ProcessTimeToStartMetricName] = (inProcStartDate.Value - dataPoint.Start).TotalMilliseconds; - - + EnsureStartupHookOverhead(dataPoint, metrics, inProcStartDate, inProcMainStartDate, + inProcMainEndDate, inProcEndDate); continue; } @@ -441,23 +472,28 @@ private static async Task RunCommandAsync(Scenario scenario) { inProcMainStartDate = DateTime.FromBinary((long)metricItem.Value); metrics[Constants.ProcessTimeToMainMetricName] = (inProcMainStartDate.Value - dataPoint.Start).TotalMilliseconds; - if (inProcEndDate != null) - { - metrics[Constants.ProcessInternalDurationMetricName] = (inProcEndDate.Value - inProcMainStartDate.Value).TotalMilliseconds; - } - + EnsureMainDuration(metrics, inProcMainStartDate, inProcMainEndDate); + EnsureStartupHookOverhead(dataPoint, metrics, inProcStartDate, inProcMainStartDate, + inProcMainEndDate, inProcEndDate); continue; } + if (metricItem.Name == Constants.MainMethodEndTimeUtcMetricName) + { + inProcMainEndDate = DateTime.FromBinary((long)metricItem.Value); + metrics[Constants.ProcessTimeToMainEndMetricName] = (dataPoint.End - inProcMainEndDate.Value).TotalMilliseconds; + EnsureMainDuration(metrics, inProcMainStartDate, inProcMainEndDate); + EnsureStartupHookOverhead(dataPoint, metrics, inProcStartDate, inProcMainStartDate, + inProcMainEndDate, inProcEndDate); + continue; + } + if (metricItem.Name == Constants.ProcessEndTimeUtcMetricName) { inProcEndDate = DateTime.FromBinary((long)metricItem.Value); metrics[Constants.ProcessTimeToEndMetricName] = (dataPoint.End - inProcEndDate.Value).TotalMilliseconds; - if (inProcMainStartDate != null) - { - metrics[Constants.ProcessInternalDurationMetricName] = (inProcEndDate.Value - inProcMainStartDate.Value).TotalMilliseconds; - } - + EnsureStartupHookOverhead(dataPoint, metrics, inProcStartDate, inProcMainStartDate, + inProcMainEndDate, inProcEndDate); continue; } diff --git a/src/TimeIt/TimeIt.sln b/src/TimeIt/TimeIt.sln index 6152e52..a93943d 100644 --- a/src/TimeIt/TimeIt.sln +++ b/src/TimeIt/TimeIt.sln @@ -13,8 +13,6 @@ Project("{2150E333-8FDC-42A3-9474-1A3956D46DE8}") = "root", "root", "{023A1498-D EndProject Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "TimeIt.StartupHook", "..\TimeIt.StartupHook\TimeIt.StartupHook.csproj", "{5B08763D-5ECF-4300-81F5-73B68E23B6BB}" EndProject -Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "TimeIt.RuntimeMetrics", "..\TimeIt.RuntimeMetrics\TimeIt.RuntimeMetrics.csproj", "{626E5521-FC70-48B9-B783-6C877B46AC51}" -EndProject Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "TimeIt.DatadogExporter", "..\TimeIt.DatadogExporter\TimeIt.DatadogExporter.csproj", "{5484AC8D-8054-4795-8781-1DA623057A46}" EndProject Global @@ -35,10 +33,6 @@ Global {5B08763D-5ECF-4300-81F5-73B68E23B6BB}.Debug|Any CPU.Build.0 = Debug|Any CPU {5B08763D-5ECF-4300-81F5-73B68E23B6BB}.Release|Any CPU.ActiveCfg = Release|Any CPU {5B08763D-5ECF-4300-81F5-73B68E23B6BB}.Release|Any CPU.Build.0 = Release|Any CPU - {626E5521-FC70-48B9-B783-6C877B46AC51}.Debug|Any CPU.ActiveCfg = Debug|Any CPU - {626E5521-FC70-48B9-B783-6C877B46AC51}.Debug|Any CPU.Build.0 = Debug|Any CPU - {626E5521-FC70-48B9-B783-6C877B46AC51}.Release|Any CPU.ActiveCfg = Release|Any CPU - {626E5521-FC70-48B9-B783-6C877B46AC51}.Release|Any CPU.Build.0 = Release|Any CPU {5484AC8D-8054-4795-8781-1DA623057A46}.Debug|Any CPU.ActiveCfg = Debug|Any CPU {5484AC8D-8054-4795-8781-1DA623057A46}.Debug|Any CPU.Build.0 = Debug|Any CPU {5484AC8D-8054-4795-8781-1DA623057A46}.Release|Any CPU.ActiveCfg = Release|Any CPU