由两个不同的秒表测量的执行时间答案

【问题标题】：Execution time measured by two different stopwatches由两个不同的秒表测量的执行时间
【发布时间】：2018-09-29 18:32:23
【问题描述】：

我要分析方法Tuple<A,B,C,D> Calculate()的执行时间。

我所做的如下：

Tuple<A, B, C, D, E>
Calculate(Line l, Path p)
{
    var stopwatch = new System.Diagnostics.Stopwatch();
    stopwatch.Start();

    var rv = Calculate2(l, p);

    System.Diagnostics.Debug.WriteLine($" stopwatch.ElapsedMilliseconds} ms;");
    }

    return rv;
}


Tuple<A, B, C, D, E>
Calculate2(Line l, Path p)
{
    var stopwatch = new System.Diagnostics.Stopwatch();
    stopwatch.Start();

    A a = ...; B b = ...; C c = ...; D d = ...; E e = ...
    ... content of this method

    System.Diagnostics.Debug.WriteLine($" stopwatch.ElapsedMilliseconds} ms;");

    return Tuple.Create(a,b,c,d,e);
}

第一次测量给出 28 毫秒，第二次只有 8 毫秒（每次）。
这是否意味着return statement 需要 20 毫秒？
我觉得这难以置信..？

这不是Tuple-问题：我尝试了一个结构元组和一个显式类，结果完全相同。

编辑
我在课堂上添加了一个静态秒表，发现在Calculate2(..) 入口处，静态秒表立即显示20毫秒的延迟。

我想知道这是否与方法的 JIT 编译有关。
我在第一次运行后添加了第二次运行，但没有显示延迟。
事实上，延迟是在第一次调用该函数时，出于某种其他原因，我认为第一个是瓶颈。

【问题讨论】：

Debug.WriteLine 远非免费。
确实！但是我发现这无法解释 8/28 的差异，因为在这两种情况下执行相同数量的 Debug.Writeline。
从定时器的角度来看，调用第一个完全调用第二个，所以Debug.WriteLine完全和元组创建；而调用第二个只是构建五个变量。
请发帖minimal reproducible example。
是的，您测量了抖动开销。 20 毫秒有点高端，因此它可能还包括磁盘开销，即查找一个或多个框架程序集的成本。

标签： c# performance stopwatch

【解决方案1】：

Stopwatch sw = new Stopwatch();
sw.Start();
//do some work
Thread.Sleep(TimeSpan.FromSeconds(30));
sw.Stop();

var totalTimeElapsed = sw.Elapsed.TotalMilliseconds;
var milSecs = sw.ElapsedMilliseconds;

您需要使用 Elapsed.TotalMilliseconds 而不是 ElapsedMilliseconds。你可以找到一个很好的解释here

ElapsedMilliseconds 可能会给您带来意想不到的结果。

【讨论】：

该答案详细说明了一些完全不同的事情，并围绕使用.Elapsed.TotalMilliseconds 与.Elapsed.Milliseconds 进行，后者通过TimeSpan。这与问题的内容完全不同。 .ElapsedMilliseconds 和 Elapsed.TotalMilliseconds 之间的主要区别是四舍五入，仅此而已。这可能与问题有关，但链接的答案不是。当我在计算机上运行代码时，代码中两个值之间的差异为 0.7 毫秒，远小于 OP 观察到的差异 8。
20/28 的差异不是四舍五入的问题，实际上两者给出的结果完全相同。感谢您的努力，但一定是别的。
@LasseVågsætherKarlsen 这不仅仅是一个四舍五入的问题。 1.234 秒的秒表将在 ElapsedMilliseconds 的属性中返回 234。停在 1.23456 秒的秒表将在 TimeSpan.TotalMilliseconds 的属性中返回 1234.56。但正如杰拉德所说，这不是问题，但它确实让我失望了一两次。
不，它不会，StopWatch.ElapsedMilliseconds 将返回 1234，但是，Stopwatch.Elapsed.Milliseconds 将返回 234，但 OP 没有使用它。