我正在使用 DateTime 对一行 C# 代码进行一些真正快速而肮脏的基准测试：
long lStart = DateTime.Now.Ticks;
// do something
long lFinish = DateTime.Now.Ticks;
问题在于结果：
开始时间 [633679466564559902] 完成时间 [633679466564559902] 开始时间 [633679466564569917] 完成时间 [633679466564569917] 开始时间 [633679466564579932] 完成时间 [633679466564579932]
...等等。
鉴于开始时间和结束时间相同，Ticks 显然不够精细。
那么，我怎样才能更好地衡量性能呢？
该类Stopwatch自 .NET 2.0 起可用，是实现此目的的最佳方式。它是一个非常高性能的计数器，精确到几分之一毫秒。看一下MSDN 文档，很清楚。
编辑：如前所述，建议多次运行代码以获得合理的平均时间。
重复执行你的代码。问题似乎是您的代码执行速度比测量仪器的粒度要快得多。最简单的解决方案是多次执行您的代码（数千次，也许是数百万次），然后计算平均执行时间。
编辑：此外，由于当前优化编译器（以及 CLR 和 JVM 等虚拟机）的性质，测量单行代码的执行速度可能会非常误导，因为测量会对速度产生很大影响. 更好的方法是分析整个系统（或至少更大的块）并检查瓶颈在哪里。
我觉得这些很有用
http://accelero.codeplex.com/SourceControl/changeset/view/22633#290971 http://accelero.codeplex.com/SourceControl/changeset/view/22633#290973 http://accelero.codeplex.com/SourceControl/变更集/视图/22633#290972
TickTimer 是 Stopwatch 的精简副本，它在构建时启动并且不支持重新启动。如果当前硬件不支持高分辨率计时，它也会通知您（秒表吞下了这个问题）
所以这
var tickTimer = new TickTimer();
//call a method that takes some time
DoStuff();
tickTimer.Stop();
Debug.WriteLine("Elapsed HighResElapsedTicks " + tickTimer.HighResElapsedTicks);
Debug.WriteLine("Elapsed DateTimeElapsedTicks " + tickTimer.DateTimeElapsedTicks);
Debug.WriteLine("Elapsed ElapsedMilliseconds " + tickTimer.ElapsedMilliseconds);
Debug.WriteLine("Start Time " + new DateTime(tickTimer.DateTimeUtcStartTicks).ToLocalTime().ToLongTimeString());
会输出这个
Elapsed HighResElapsedTicks 10022886
Elapsed DateTimeElapsedTicks 41896
Elapsed ElapsedMilliseconds 4.18966178849554
Start Time 11:44:58
DebugTimer 是 TickTimer 的包装器，它将结果写入 Debug。（注意：它支持 Disposable 模式）
所以这
using (new DebugTimer("DoStuff"))
{
//call a method that takes some time
DoStuff();
}
将其输出到调试窗口
DoStuff: Total 3.6299 ms
IterationDebugTimer 用于计时多次运行操作并将结果写入 Debug 所需的时间。它还将执行不包括在内的初始运行，以忽略启动时间。（注意：它支持 Disposable 模式）
所以这
int x;
using (var iterationDebugTimer = new IterationDebugTimer("Add", 100000))
{
iterationDebugTimer.Run(() =>
{
x = 1+4;
});
}
会输出这个
Add: Iterations 100000
Total 1.198540 ms
Single 0.000012 ms
只是为了补充其他人已经说过的关于使用秒表和测量平均值的内容。
确保在测量之前调用您的方法。否则，您还将测量 JIT 编译代码所需的时间。这可能会严重扭曲您的数字。
此外，请确保您测量发布模式代码，因为调试版本的优化默认关闭。调整调试代码是没有意义的恕我直言。
并确保你测量的是你真正想要测量的东西。当优化开始时，编译器/JIT 编译器可能会重新排列代码或将其完全删除，因此您最终可能会测量出与预期略有不同的东西。至少看看生成的代码以确保代码没有被剥离。
根据您要测量的内容，请记住，真实系统对运行时的压力不同于典型的测试应用程序。一些性能问题与例如对象如何被垃圾收集有关。这些问题通常不会出现在简单的测试应用程序中。
实际上，最好的建议是使用真实数据来衡量真实系统，因为沙盒测试可能会变得非常不准确。
https://andreyakinshin.gitbooks.io/performancebookdotnet/content/science/microbenchmarking.html
https://github.com/PerfDotNet/BenchmarkDotNet
“确实，微基准测试非常困难。如果一个操作需要 10-100ns，那么操作测量是一个很大的挑战。我建议您使用 BenchmarkDotNet 进行基准测试。它是一个可以帮助您进行诚实基准测试并获得测量结果的库良好的精度。当然，您可以编写自己的基准测试而不需要任何额外的库。在本节中，我们将讨论为什么它可能是一个坏主意以及在开始之前您应该了解的内容。
使用真正的分析器，例如dotTrace。
Stopwatch假设您使用的是 .NET 2.0 或更高版本，则可以使用.
System.Diagnostics.Stopwatch.StartNew();
该类Stopwatch还具有公共只读字段IsHighResolution，可以让您知道秒表是否基于高分辨率性能计数器。如果不是，则基于系统计时器。
我不确定秒表基于高分辨率性能计数器需要什么。有一些 API 调用，但我认为如果秒表不使用高分辨率，那么 API 可能不存在。
查看Is DateTime.Now 是衡量函数性能的最佳方法的答案吗？如需解释或阅读我关于高性能测量的博客文章
问题是 DateTime 的分辨率约为 15ms，不能比这更精确了。然而，秒表可以。
Stopwatch课堂样本
using System.Diagnostics;
......
...
..
Stopwatch sw = new Stopwatch();
sw.Start();
//Your Code Here
sw.Stop();
Console.WriteLine("Elapsed={0}",sw.Elapsed);
这是 MSDN 上关于如何为 Windows 实现持续更新、高分辨率时间提供程序的一篇不错的文章
这是本文的示例源代码(C++)。
我的偏好是 @Evgeniy 提到的 BenchmarkDotNet 。可能他的回复被绕过了，因为没有代码片段，但由于这是一个复杂的项目，因此至少值得先看看库，然后再去定制一些东西。
因为有些代码总是引人注目，这里是引用站点的示例：
using System;
using System.Security.Cryptography;
using BenchmarkDotNet.Attributes;
using BenchmarkDotNet.Running;
namespace MyBenchmarks
{
[ClrJob(baseline: true), CoreJob, MonoJob, CoreRtJob]
[RPlotExporter, RankColumn]
public class Md5VsSha256
{
private SHA256 sha256 = SHA256.Create();
private MD5 md5 = MD5.Create();
private byte[] data;
[Params(1000, 10000)]
public int N;
[GlobalSetup]
public void Setup()
{
data = new byte[N];
new Random(42).NextBytes(data);
}
[Benchmark]
public byte[] Sha256() => sha256.ComputeHash(data);
[Benchmark]
public byte[] Md5() => md5.ComputeHash(data);
}
public class Program
{
public static void Main(string[] args)
{
var summary = BenchmarkRunner.Run<Md5VsSha256>();
}
}
}
另一种选择是使用Fody自动插入计时器代码。这使您的代码更易于阅读，因为它分离了您的横切关注点。我认为这接近于所谓的面向方面编程，但在编译后完成。
有关执行方法计时的 fody 插件，请参阅https://github.com/Fody/MethodTimer 。
引用自述文件：
使用拦截器，在您的程序集中的某处：
public static class MethodTimeLogger {
public static void Log(MethodBase methodBase, long milliseconds)
{
//Do some logging here
}
}
你的代码，
public class MyClass
{
[Time]
public void MyMethod()
{
//Some code u are curious how long it takes
Console.WriteLine("Hello");
}
}
编译成这样：
public class MyClass
{
public void MyMethod()
{
var stopwatch = Stopwatch.StartNew();
try
{
//Some code u are curious how long it takes
Console.WriteLine("Hello");
}
finally
{
stopwatch.Stop();
MethodTimeLogger.Log(methodof(MyClass.MyMethod), stopwatch.ElapsedMilliseconds);
}
}
}
一次性风格Stopwatch最适合我。
class VWatch : IDisposable {
Stopwatch watch = new Stopwatch();
public VWatch() {
this.watch.Start();
}
public void Dispose() {
this.watch.Stop();
Console.WriteLine("Finished. Elapsed={0}", this.watch.Elapsed);
}
}
进而：
using (new VWatch()) {
/// do something for time measurement
}
有时最好看看为什么需要对操作进行计时？它运行缓慢吗？或者你只是好奇？优化的第一条规则是“不要这样做”。因此，根据您实际测量的内容，可能会改变对哪种工具最适合该任务的看法。
最容易使用像ANTS Performance Profiler这样的分析器，或者其他可用的分析器之一。
我做了一个从滴答声返回毫秒的扩展。
public static int GetTotalRunningTimeInMilliseconds(this DateTime start)
{
var endTicks = DateTime.Now.Ticks - start.Ticks;
return TimeSpan.FromTicks(endTicks).Milliseconds;
}
用法：
var start = DateTime.Now;
//...your long running code here
var endTime = start.GetTotalRunningTimeInMilliseconds();
我做了一个非常简单的方法来测量Action的执行速度，这对我来说有好处，我可以在需要时重用它，以及我必须测量的任何代码。
对我来说，一个 DateTime 就足够了，但它很容易从 DateTime 适应到Stopwatch。
public static TimeSpan MeasureTime(Action action)
{
DateTime start = DateTime.Now;
if (action == null)
{
throw new ArgumentNullException("action");
}
try
{
action();
}
catch (Exception ex)
{
Debugger.Log(1, "Measuring",ex.ToString());
}
return DateTime.Now - start;
}
如何使用它？：
private static void StressTest()
{
List<TimeSpan> tss = new List<TimeSpan>();
for (int i = 0; i < 100; i++)
{
// here is the measuring:
var ts = MeasureTime(() => instance.Method("param1"));
tss.Add(ts);
}
Console.WriteLine("Max: {0}", tss.Max());
Console.WriteLine("Min: {0}", tss.Min());
Console.WriteLine("Avg: {0}", TimeSpan.FromMilliseconds(tss.Average(i => i.TotalMilliseconds)));
}
或者：
var ts = MeasureTime(() =>
{
// Some intensive stuff here
int a = 1;
// more here
int b = 2;
// and so on
});
为了通过测量之间的差异来衡量性能，我使用了这个类。StopWatch 类没有该Split方法。
/// <summary>
/// Stopwatch like class that keeps track of timelapses.
/// Probably low-res because of the usage of DateTime.
/// </summary>
public class ChronoMeter
{
/// <summary>
/// The name given when the Chronometer was constructed.
/// </summary>
public string Name { get; private set; }
/// <summary>
/// The moment in time Start was called.
/// </summary>
public DateTime Started { get; private set; }
/// <summary>
/// All time recordings are added to this list by calling Split and Stop.
/// </summary>
public List<ChronoRecord> Records { get; private set; }
private readonly Stopwatch _stopWatch = new Stopwatch();
private bool _hasBeenStopped = false;
/// <summary>
/// Constrcutor
/// </summary>
/// <param name="pName">The name is used in logging</param>
/// <param name="pLoggingType">The type of logging appriate for the information yielded by this time recording.</param>
public ChronoMeter(string pName)
{
Name = pName;
Records = new List<ChronoRecord>();
}
/// <summary>
/// Not calling Stop is bad practise. Therefore a little safety net zo the end is still recorderd.
/// Keep in mind that the garbase collector invokes the destructor, so the moment of time probably doesn't make much sense.
/// It is more to notify that you should have used Stop for the latest split.
/// </summary>
~ChronoMeter()
{
if (!_hasBeenStopped)
{
Stop("Destructor safety net");
}
}
/// <summary>
/// TimeElapsedSinceStart of a ChronoRecord is relative to the moment ChronoMeter was started by calling this function.
/// </summary>
public void Start()
{
_stopWatch.Start();
Started = DateTime.Now;
}
/// <summary>
/// Splits the timerecording and add a record of this moment to the list of split records.
/// </summary>
/// <param name="pSplitName"></param>
public void Split(string pSplitName)
{
_stopWatch.Stop();
var created = Started + _stopWatch.Elapsed;
var previousRecord = Records.LastOrDefault();
Records.Add(new ChronoRecord(pSplitName, Started, created, previousRecord));
_stopWatch.Start();
}
/// <summary>
/// Indicates you are done and the records will be written to the log.
/// </summary>
public void Stop(string pSplitName)
{
Split(pSplitName);
_stopWatch.Stop();
_hasBeenStopped = true;
}
public class ChronoRecord
{
public string Name { get; private set; }
public TimeSpan TimeElapsedSinceStart { get; private set; }
public TimeSpan TimeElapsedSincePrevious { get; private set; }
public DateTime Start { get; private set; }
public DateTime Created { get; private set; }
public ChronoRecord(string pName, DateTime pStartDateTime, DateTime pCreated, ChronoRecord pPreviousRecord=null)
{
if (pCreated == default(DateTime)) //Ignore DefaultDateTimeComparison
{
pCreated = DateTime.Now;
}
Created = pCreated;
Name = pName;
Start = pStartDateTime;
TimeElapsedSinceStart = Created - Start;
if (pPreviousRecord != null)
{
TimeElapsedSincePrevious = Created - pPreviousRecord.Created;
}
else
{
TimeElapsedSincePrevious = TimeElapsedSinceStart;
}
}
}
}