如何使用秒表测量多个点之间经过的时间?

How to use the stopwatch to measure the elapsed time between multiple points?

我想测量我的代码中当前经过的时间以及多个代码段之间经过的时间。一个例子:

当我想得到我正在做的经过时间时

static void Main(string[] args)
{
    Stopwatch _stopwatch = new Stopwatch();
    _stopwatch.Start();

    ... do something ...

    _stopwatch.Stop();
    Console.WriteLine("Time elapsed total: {0:hh\:mm\:ss}", _stopwatch.Elapsed);
}

我也可以像这样输出代码执行过程中经过的时间

static void Main(string[] args)
{
    Stopwatch _stopwatch = new Stopwatch();
    _stopwatch.Start();

    ... do something ...
    Console.WriteLine("Time elapsed: {0:hh\:mm\:ss}", _stopwatch.Elapsed);

    ... do something ...
    Console.WriteLine("Time elapsed: {0:hh\:mm\:ss}", _stopwatch.Elapsed);

    ... do something ...
    Console.WriteLine("Time elapsed: {0:hh\:mm\:ss}", _stopwatch.Elapsed);

    ... do something ...
    Console.WriteLine("Time elapsed: {0:hh\:mm\:ss}", _stopwatch.Elapsed);


    // finally
    _stopwatch.Stop();
    Console.WriteLine("Time elapsed total: {0:hh\:mm\:ss}", _stopwatch.Elapsed);
}

但我想要的是这样的:

Code startet ... | elapsed time 00:02:01:sss | this single segment took 00:02:01:sss

Connected to database ... | elapsed time 00:02:04:sss | this single segment took 00:00:03:sss

Added 40.000 rows ... | elapsed time 00:05:23:sss | this single segment took 00:03:19:sss

所以我想要的是除了代码中单个部分的总经过时间和停止时间之外,还有经过时间旁边的单个部分的时间。

我该怎么做?

在每个经过的时间打印后使用秒表的Restart()方法;它会将经过的时间重置为 0 ...并保留一个变量以将经过的时间总计为总经过时间。

希望这对您有所帮助...

我想我解决了。对我来说,看起来也许有些专家可以检查 "optimization"?

我将最后一个时间跨度存储在一个 vraiable 中,并从当前时间跨度中减去最后一个时间跨度:

    private static TimeSpan _pastTimeSpan;

    static void Main(string[] args)
    {
        _stopwatch = new Stopwatch();
        _stopwatch.Start();

        _pastTimeSpan = _stopwatch.Elapsed;

        ... code ...

        MyElapsedTime(_stopwatch.Elapsed);

        ... code ...

        MyElapsedTime(_stopwatch.Elapsed);

        ... code ...

        MyElapsedTime(_stopwatch.Elapsed);

        _stopwatch.Stop();
        Console.WriteLine("Time elapsed total: {0:hh\:mm\:ss}", _stopwatch.Elapsed);
     }

    private static void MyElapsedTime(TimeSpan ts)
    {
        // Get the last TimeSpan
        TimeSpan pastTimeSpan = _pastTimeSpan;

        // Update last TimeSpan with current
        _pastTimeSpan = ts;

        // Get difference between two
        TimeSpan diffTs = ts.Subtract(pastTimeSpan);

        Console.WriteLine(string.Format("Elapsed time {0}:{1} | Segment took {2}:{3}", Math.Floor(ts.TotalMinutes), ts.ToString("ss\.ff"), Math.Floor(diffTs.TotalMinutes), diffTs.ToString("ss\.ff")));
    }

输出将是

Elapsed time 0:01.70 | Segment took 0:01.70
Elapsed time 0:01.78 | Segment took 0:00.07

根据 STORM 的回答,我构建了一个多 ID/多级别秒表。它可用于测量具有 x 级深度方法的并行任务。

用法示例:

public DataManager()
{
    StopWatchTimer.MeasureText(new [] { _stopWatchId }, $"CTOR loading ...");

    BuildDefaultExchanges(); _sw.MeasureText(new[] { _stopWatchId }, $"BuildDefaultExchanges");
    BuildExchanges();        _sw.MeasureText(new[] { _stopWatchId }, $"BuildExchanges");
    
    foreach (var exchange in ModuleGlobals.MicExchanges)
    {
        var defaultExchange = ExchangesView.FirstOrDefault(x => x.Mic == exchange.Mic);
    } StopWatchTimer.MeasureText(new[] { _stopWatchId }, $"foreach (var exchange in ModuleGlobals.MicExchanges)");

// More level 1 code

    StopWatchTimer.MeasureText(new[] { _stopWatchId }, $"CTOR loaded");
    StopWatchTimer.MeasureStop(_stopWatchId);
}

public void BuildExchanges()
{
    // level 2 code:
    Exchanges.Clear(); _sw.MeasureText(new[] { _stopWatchId, "BuildExchanges" }, $"ClearExchanges");
    BuildExchangesDefault(); StopWatchTimer.MeasureText(new[] { _stopWatchId, "BuildExchanges" }, $"ExchangesDefault");
    
    foreach (var exchange in Exchanges) // Level 3
    {
        ExchangesView.Add(new MicExchangeItemViewModel(exchange.Value, true)); _sw.MeasureText(new[] { _stopWatchId, "BuildExchanges", "Exchanges" }, exchange.Key);
    } StopWatchTimer.MeasureText(new[] { _stopWatchId, "BuildExchanges" }, $"Exchanges Build");

    BuildExchangesDefault(); StopWatchTimer.MeasureText(new[] { _stopWatchId, "BuildExchanges" }, $"ExchangesView");
}

Class:

public static class StopWatchTimer
{
    internal class Segment
    {
        public TimeSpan StartTimeSpan { get; set; }
        public TimeSpan LevelTimeSpan { get; set; }
        public TimeSpan TimeSpan { get; set; }
        internal readonly Dictionary<string, Segment> Segments = new();
    }

    private static readonly ICustomLogger _logger = ContainerLocator.Current.Resolve<ICustomLogger>();
    private static readonly Dictionary<string, (Stopwatch stopwatch, Segment segemnt)> _timer = new(); 

    public static void MeasureText(string[] ids, string text)
    {
        var mainId = ids[0];

        if(!_timer.ContainsKey(mainId))
        {
            // Time only needed in Level 0
            _timer.Add(mainId, (new Stopwatch(), new Segment()));
            _timer[mainId].stopwatch.Start();
        }
        
        _logger.Log(String.Join(" | ", GetSegmentText(ids, 0, _timer[mainId].segemnt, _timer[mainId].stopwatch, text)));
    }

    private static IEnumerable<string> GetSegmentText(string[] ids, int level, Segment segment, Stopwatch stopwatch, string text)
    {
        // For multilevel timer start segment at 0
        var ts = stopwatch.Elapsed - segment.StartTimeSpan;
        
        // Get the last TimeSpan
        TimeSpan pastTimeSpan = segment.TimeSpan;

        // Ignore SubLevel
        if (ids.Length == 1)
        {
            pastTimeSpan = segment.LevelTimeSpan;
            segment.LevelTimeSpan = ts;
        }

        // Update last TimeSpan with current
        segment.TimeSpan = ts;
        
        // Get difference between two
        TimeSpan diffTs = ts.Subtract(pastTimeSpan);

        // Time of the actual level
        yield return $"{ids[level]} Σ {Math.Floor(ts.TotalMinutes)}:{ts.ToString("ss\.ffff")}";

        // Append potential sub levels
        if (ids.Length > level + 1)
        {
            if (!segment.Segments.ContainsKey(ids[level + 1]))
                segment.Segments.Add(ids[level + 1], new Segment() { StartTimeSpan = ts });
            
            foreach (var s in GetSegmentText(ids, level + 1, segment.Segments[ids[level + 1]], stopwatch, text))
                yield return s;
        }
        else
        {
            // time for lowest segment
            yield return $"Δ {Math.Floor(diffTs.TotalMinutes)}:{diffTs.ToString("ss\.ffff")} - {text}";
        }
    }

    public static void MeasureStop(string id)
    {
        if (_timer.ContainsKey(id))
        {
            _timer[id].stopwatch.Stop();
            _timer.Remove(id);
        }
    }
}

结果:

DataManager Σ 0:00.0006 | Δ 0:00.0006 - CTOR loading ...
DataManager Σ 0:00.0704 | Δ 0:00.0698 - BuildDefaultExchanges
DataManager Σ 0:00.0717 | BuildExchanges Σ 0:00.0000 | Δ 0:00.0000 - ClearExchanges
DataManager Σ 0:00.1249 | BuildExchanges Σ 0:00.0532 | Δ 0:00.0531 - ExchangesDefault
DataManager Σ 0:00.3456 | BuildExchanges Σ 0:00.2739 | Exchanges Σ 0:00.0736 | Δ 0:00.0008 - MIBG
.
.
.
DataManager Σ 0:00.8440 | BuildExchanges Σ 0:00.7723 | Exchanges Σ 0:00.5720 | Δ 0:00.0002 - KOME
DataManager Σ 0:00.8442 | BuildExchanges Σ 0:00.7725 | Exchanges Σ 0:00.5723 | Δ 0:00.0002 - IBER
DataManager Σ 0:00.8445 | BuildExchanges Σ 0:00.7727 | Exchanges Σ 0:00.5725 | Δ 0:00.0002 - ERBX
DataManager Σ 0:00.8447 | BuildExchanges Σ 0:00.7729 | Δ 0:00.0001 - Exchanges Build
DataManager Σ 0:00.8782 | BuildExchanges Σ 0:00.8064 | Δ 0:00.0335 - ExchangesView
DataManager Σ 0:00.8854 | Δ 0:00.8149 - BuildExchanges
DataManager Σ 0:00.8866 | Δ 0:00.0007 - CTOR loaded