< Summary

Information
Class: MyNet.Utilities.Logging.PerformanceLogger
Assembly: MyNet.Utilities
File(s): https://raw.githubusercontent.com/sandre58/MyNet/85372080fe102cd9ee155ceab49ae000e7f66103/src/MyNet.Utilities/Logging/PerformanceLogger.cs
Tag: 323_28699572109
Line coverage
91%
Covered lines: 63
Uncovered lines: 6
Coverable lines: 69
Total lines: 226
Line coverage: 91.3%
Branch coverage
64%
Covered branches: 35
Total branches: 54
Branch coverage: 64.8%
Method coverage

Feature is only available for sponsors

Upgrade to PRO version

Metrics

MethodBranch coverage Crap Score Cyclomatic complexity Line coverage
.cctor()100%11100%
get_Stack()100%22100%
.ctor(...)62.5%88100%
.ctor(...)100%11100%
get_Current()0%620%
get_Elapsed()100%11100%
FormatTimeSpan(...)60%1010100%
Dispose()68.75%161695%
AddTime(...)100%11100%
MergeTimes(...)50%3233.33%
TraceTimes()71.42%1414100%

File(s)

https://raw.githubusercontent.com/sandre58/MyNet/85372080fe102cd9ee155ceab49ae000e7f66103/src/MyNet.Utilities/Logging/PerformanceLogger.cs

#LineLine coverage
 1// -----------------------------------------------------------------------
 2// <copyright file="PerformanceLogger.cs" company="Stéphane ANDRE">
 3// Copyright (c) Stéphane ANDRE. All rights reserved.
 4// </copyright>
 5// -----------------------------------------------------------------------
 6
 7using System;
 8using System.Collections.Concurrent;
 9using System.Collections.Generic;
 10using System.Diagnostics;
 11using System.Diagnostics.CodeAnalysis;
 12using System.Linq;
 13using System.Threading;
 14using Microsoft.Extensions.Logging;
 15
 16namespace MyNet.Utilities.Logging;
 17
 18/// <summary>
 19/// A utility class for logging the performance of code blocks. It uses a stack to manage nested performance loggers and
 20/// </summary>
 21public sealed class PerformanceLogger : IDisposable
 22{
 623    private static readonly AsyncLocal<Stack<PerformanceLogger>?> CurrentStack = new();
 24
 13825    private static Stack<PerformanceLogger> Stack => CurrentStack.Value ??= new();
 26
 27    private readonly ILogger _logger;
 28    private readonly string _title;
 29    private readonly Stopwatch _stopwatch;
 30    private readonly IDisposable? _scope;
 2731    private readonly ConcurrentDictionary<string, RegisteredTime> _registeredTimes = new();
 32    private readonly Func<TimeSpan, LogLevel> _provideLogLevel;
 33    private bool _disposed;
 34
 35    /// <summary>
 36    /// Initializes a new instance of the <see cref="PerformanceLogger"/> class with the specified logger, title, log le
 37    /// </summary>
 38    /// <param name="logger">The logger to use for logging performance messages.</param>
 39    /// <param name="title">The title of the performance logger, used in log messages.</param>
 40    /// <param name="level">The log level to use for logging performance messages.</param>
 41    /// <param name="showStartMessage">Whether to show a start message when the performance logger is created.</param>
 42    /// <param name="showEndMessage">Whether to show an end message when the performance logger is disposed.</param>
 43    public PerformanceLogger(ILogger logger, string title, LogLevel level = LogLevel.Trace, bool showStartMessage = fals
 2444        : this(logger, title, _ => level, showStartMessage, showEndMessage)
 45    {
 2446    }
 47
 48    /// <summary>
 49    /// Initializes a new instance of the <see cref="PerformanceLogger"/> class with the specified logger, title, functi
 50    /// </summary>
 51    /// <param name="logger">The logger to use for logging performance messages.</param>
 52    /// <param name="title">The title of the performance logger, used in log messages.</param>
 53    /// <param name="provideLogLevel">A function that determines the log level based on the elapsed time.</param>
 54    /// <param name="showStartMessage">Whether to show a start message when the performance logger is created.</param>
 55    /// <param name="showEndMessage">Whether to show an end message when the performance logger is disposed.</param>
 56    public PerformanceLogger(ILogger logger, string title, Func<TimeSpan, LogLevel> provideLogLevel, bool showStartMessa
 57    {
 2758        _logger = logger ?? throw new ArgumentNullException(nameof(logger));
 2759        _title = title ?? throw new ArgumentNullException(nameof(title));
 2760        _provideLogLevel = provideLogLevel ?? throw new ArgumentNullException(nameof(provideLogLevel));
 61
 2762        Stack.Push(this);
 63
 2764        _scope = _logger.BeginScope(_title);
 65
 2766        if (showStartMessage)
 67        {
 368            _logger.LogStart(_title);
 69        }
 70
 2771        _stopwatch = Stopwatch.StartNew();
 72
 73        ShowEndMessage = showEndMessage;
 2774    }
 75
 76    /// <summary>
 77    /// Gets the current performance logger from the stack. If there are no performance loggers in the stack, it returns
 78    /// </summary>
 079    public static PerformanceLogger? Current => Stack.Count == 0 ? null : Stack.Peek();
 80
 81    /// <summary>
 82    /// Gets a value indicating whether to show an end message when the performance logger is disposed. This property is
 83    /// </summary>
 84    public bool ShowEndMessage { get; }
 85
 86    /// <summary>
 87    /// Gets the elapsed time since the performance logger was created. This property returns the total time that has pa
 88    /// </summary>
 3989    public TimeSpan Elapsed => _stopwatch.Elapsed;
 90
 91    /// <summary>
 92    /// Formats a TimeSpan into a human-readable string with appropriate units (days, hours, minutes, seconds, milliseco
 93    /// </summary>
 94    /// <param name="time">The TimeSpan to format.</param>
 95    /// <returns>A formatted string representing the TimeSpan.</returns>
 96    private static string FormatTimeSpan(TimeSpan time) =>
 2197        time.TotalDays >= 1
 2198            ? $"{time.TotalDays:F2}d"
 2199            : time.TotalHours >= 1
 21100                ? $"{time.TotalHours:F2}h"
 21101                : time.TotalMinutes >= 1
 21102                    ? $"{time.TotalMinutes:F2}m"
 21103                    : time.TotalSeconds >= 1
 21104                        ? $"{time.TotalSeconds:F2}s"
 21105                        : time.TotalMilliseconds >= 1
 21106                            ? $"{time.TotalMilliseconds:F2}ms"
 21107                            : $"{time.TotalMicroseconds:F2}μs";
 108
 109    /// <summary>
 110    /// Disposes the performance logger, stopping the stopwatch and logging the elapsed time along with any registered t
 111    /// </summary>
 112    public void Dispose()
 113    {
 27114        if (_disposed)
 115        {
 0116            return;
 117        }
 118
 27119        _disposed = true;
 120
 27121        _stopwatch.Stop();
 122
 27123        var elapsed = _stopwatch.Elapsed;
 124
 27125        if (ShowEndMessage)
 126        {
 3127            if (_logger.IsEnabled(LogLevel.Trace))
 128            {
 3129                _logger.LogEnd(_title, FormatTimeSpan(elapsed));
 130            }
 131        }
 132
 27133        PerformanceLogger? parent = null;
 134
 27135        if (Stack.Count > 0 && ReferenceEquals(Stack.Peek(), this))
 136        {
 27137            Stack.Pop();
 138        }
 139
 27140        if (Stack.Count > 0)
 141        {
 3142            parent = Stack.Peek();
 143        }
 144
 27145        if (parent is null)
 146        {
 24147            TraceTimes();
 148        }
 149        else
 150        {
 3151            var level = _provideLogLevel(elapsed);
 152
 3153            parent.AddTime(_title, elapsed, level);
 3154            parent.MergeTimes(this);
 155        }
 156
 27157        _scope?.Dispose();
 27158    }
 159
 160    /// <summary>
 161    /// Adds a registered time to the performance logger with the specified key, time, and log level. This method allows
 162    /// </summary>
 163    /// <param name="key">The key associated with the registered time.</param>
 164    /// <param name="time">The time span to register.</param>
 165    /// <param name="level">The log level for the registered time.</param>
 166    public void AddTime(string key, TimeSpan time, LogLevel level)
 3167        => _registeredTimes.AddOrUpdate(key, _ => new(level, time), (_, existing) => new(level, existing.Time + time));
 168
 169    /// <summary>
 170    /// Merges the registered times from a child performance logger into the current performance logger. This method is 
 171    /// </summary>
 172    /// <param name="child">The child performance logger whose registered times are to be merged.</param>
 173    private void MergeTimes(PerformanceLogger child)
 174    {
 6175        foreach (var item in child._registeredTimes)
 176        {
 0177            AddTime(
 0178                $"{child._title} -> {item.Key}",
 0179                item.Value.Time,
 0180                item.Value.Level);
 181        }
 3182    }
 183
 184    /// <summary>
 185    /// Logs the total elapsed time and any registered times in a structured format. If there are no registered times, i
 186    /// </summary>
 187    [SuppressMessage("Performance", "CA1848:Use the LoggerMessage delegates", Justification = "The number of messages is
 188    [SuppressMessage("ReSharper", "DuplicateItemInLoggerTemplate", Justification = "The log messages are dynamic and do 
 189    private void TraceTimes()
 190    {
 24191        var totalLevel = _provideLogLevel(Elapsed);
 192
 24193        if (_registeredTimes.IsEmpty)
 194        {
 21195            if (_logger.IsEnabled(totalLevel))
 12196                _logger.Log(totalLevel, "{Title} completed in {Elapsed}", _title, FormatTimeSpan(Elapsed));
 197
 21198            return;
 199        }
 200
 201        const string separator = "********************";
 202
 3203        if (_logger.IsEnabled(totalLevel))
 3204            _logger.Log(totalLevel, "{} {Title} {Separator}", separator, _title, separator);
 205
 12206        foreach (var item in _registeredTimes.OrderByDescending(x => x.Value.Time))
 207        {
 3208            if (_logger.IsEnabled(item.Value.Level))
 3209                _logger.Log(item.Value.Level, "{Key} - {Elapsed}", item.Key, FormatTimeSpan(item.Value.Time));
 210        }
 211
 3212        if (_logger.IsEnabled(totalLevel))
 3213            _logger.Log(totalLevel, "Total Time : {Elapsed}", FormatTimeSpan(Elapsed));
 214
 3215        if (_logger.IsEnabled(totalLevel))
 3216            _logger.Log(totalLevel, "{Separator} {Title} {Separator}", separator, _title, separator);
 3217    }
 218
 219    /// <summary>
 220    /// A record representing a registered time measurement with an associated log level. This record is used to store t
 221    /// </summary>
 222    /// <param name="Level">The log level associated with the registered time.</param>
 223    /// <param name="Time">The time span of the registered time.</param>
 224    private sealed record RegisteredTime(LogLevel Level, TimeSpan Time);
 225}
 226