BenchmarkDotNetを使って処理速度を測る

ある処理を実装する場合、複数の実装方法がありますが、果たしてそれらの候補のうちどれが一番速いのか、を確認したいときがあります。

いままではなんとなくStopWatchクラスを使って以下のように計測していました。

var sw = new Stopwatch();

sw.Start();

//計測したい処理
Enumerable.Range(0, 20)
    .ToList()
    .ForEach(item => Console.WriteLine(item * 2));

sw.Stop();

//経過時間出力
Console.WriteLine($"{sw.ElapsedMilliseconds} ms");

とはいえこれだとミリ秒レベルでしか時間を測れないので、細かい処理を数百万オーダーで行ったときに、１つ１つの処理が0.5msなのか0.1msなのかは大きな違いになるはずが、「0ms」としかわからないのは困ったりするわけです。また、一回計測するごとに手動で実行し、ある程度信頼できる平均値を求めたければその回数だけ手動またはそのためのコードを書く必要があります。

そこで、「BenchmarkDotNet」というフレームワークが便利なようです。これを使うと対象の処理の速度について平均値やヒストグラムなどの情報を得ることができます。

インストール

Nugetからインストールします。

パッケージマネージャーコンソールから、

PM> install-package benchmarkdotnet

または、

f:id:shuhelohelo:20190428114654p:plain

としてインストールします。

試してみる

試しに以下のような簡単なプログラムを書いてみました。前述の1~20までの数字を2倍してコンソールに出力するプログラムの処理速度を計測してみます。

使い方は以下のとおりです。

計測したい処理をまとめるclassを作ります。
計測したい処理をそのclassの中にメソッドとして記述します。
そのメソッドに[Benchmark]属性をつけます。
BenchmarkRunner.Run<計測したい処理をまとめたclass>()でベンチマーク開始。
プロジェクトをReleaseビルドでデバッグ実行します。

これはおそらく最も単純な使い方で、いろいろな設定ができると思います。

using BenchmarkDotNet.Attributes;
using BenchmarkDotNet.Running;
using System;
using System.Diagnostics;
using System.Linq;
using System.Threading;

namespace ConsoleApp2
{
    class Program
    {
        static void Main(string[] args)
        {
            Console.WriteLine("Hello World!");

            //ベンチマーク実行開始
            BenchmarkRunner.Run<BenchmarkTest>();
        }
    }

    //
    public class BenchmarkTest
    {
        //計測したい処理
        [Benchmark]
        public void TargetMethodA()
        {
            //計測したい処理
            Enumerable.Range(0, 20)
                .ToList()
                .ForEach(item => Console.WriteLine(item * 2));
        }
    }
}

実行

さて、実行してみましょう。実行すると、テスト対象の処理が100回試行されます。対象の処理内容によりますが、今回の簡単なものでも思ったより待ちました。

実行が完了すると、処理時間の平均やヒストグラムが出力されます。 CPU、OS、SDKなどの実行環境の情報も出力されます。

WorkloadActual  100: 64 op, 254472200.00 ns, 3.9761 ms/op

// AfterActualRun
WorkloadResult   1: 64 op, 6133700.00 ns, 95.8391 us/op
WorkloadResult   2: 64 op, 242116100.00 ns, 3.7831 ms/op
WorkloadResult   3: 64 op, 234991300.00 ns, 3.6717 ms/op

...中略

WorkloadResult  82: 64 op, 252811400.00 ns, 3.9502 ms/op
WorkloadResult  83: 64 op, 254471400.00 ns, 3.9761 ms/op
GC:  0 0 0 0 0

// AfterAll

Mean = 3.8638 ms, StdErr = 0.0481 ms (1.24%); N = 83, StdDev = 0.4379 ms
Min = 0.0958 ms, Q1 = 3.8183 ms, Median = 3.8998 ms, Q3 = 3.9821 ms, Max = 4.3079 ms
IQR = 0.1638 ms, LowerFence = 3.5726 ms, UpperFence = 4.2278 ms
ConfidenceInterval = [3.6997 ms; 4.0279 ms] (CI 99.9%), Margin = 0.1641 ms (4.25% of Mean)
Skewness = -7.64, Kurtosis = 66.09, MValue = 2.07

Successfully reverted power plan (GUID: 381b4222-f694-41f0-9685-ff5bb260df2e FriendlyName: バランス)
// ***** BenchmarkRunner: Finish  *****

// * Export *
  BenchmarkDotNet.Artifacts\results\ConsoleApp2.BenchmarkTest-report.csv
  BenchmarkDotNet.Artifacts\results\ConsoleApp2.BenchmarkTest-report-github.md
  BenchmarkDotNet.Artifacts\results\ConsoleApp2.BenchmarkTest-report.html

// * Detailed results *
BenchmarkTest.TargetMethodA: DefaultJob
Runtime = .NET Core 3.0.0-preview4-27615-11 (CoreCLR 4.6.27615.73, CoreFX 4.700.19.21213), 64bit RyuJIT; GC = Concurrent Workstation
Mean = 3.8638 ms, StdErr = 0.0481 ms (1.24%); N = 83, StdDev = 0.4379 ms
Min = 0.0958 ms, Q1 = 3.8183 ms, Median = 3.8998 ms, Q3 = 3.9821 ms, Max = 4.3079 ms
IQR = 0.1638 ms, LowerFence = 3.5726 ms, UpperFence = 4.2278 ms
ConfidenceInterval = [3.6997 ms; 4.0279 ms] (CI 99.9%), Margin = 0.1641 ms (4.25% of Mean)
Skewness = -7.64, Kurtosis = 66.09, MValue = 2.07
-------------------- Histogram --------------------
[   8.001 us ;  183.677 us) | @
[ 183.677 us ;  359.353 us) |
[ 359.353 us ;  535.029 us) |
[ 535.029 us ;  710.705 us) |
[ 710.705 us ;  886.381 us) |
[ 886.381 us ; 1062.057 us) |
[1062.057 us ; 1237.733 us) |
[1237.733 us ; 1413.409 us) |
[1413.409 us ; 1589.085 us) |
[1589.085 us ; 1764.761 us) |
[1764.761 us ; 1940.437 us) |
[1940.437 us ; 2116.113 us) |
[2116.113 us ; 2291.789 us) |
[2291.789 us ; 2467.465 us) |
[2467.465 us ; 2643.141 us) |
[2643.141 us ; 2818.817 us) |
[2818.817 us ; 2994.493 us) |
[2994.493 us ; 3170.169 us) |
[3170.169 us ; 3345.845 us) |
[3345.845 us ; 3497.209 us) |
[3497.209 us ; 3631.606 us) | @@
[3631.606 us ; 3791.793 us) | @@@@@@
[3791.793 us ; 3967.469 us) | @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
[3967.469 us ; 4142.259 us) | @@@@@@@@@@@@@@@@@@@@
[4142.259 us ; 4323.368 us) | @@@@
---------------------------------------------------

// * Summary *

BenchmarkDotNet=v0.11.5, OS=Windows 10.0.17763.437 (1809/October2018Update/Redstone5)
Intel Core i5-8250U CPU 1.60GHz (Kaby Lake R), 1 CPU, 8 logical and 4 physical cores
.NET Core SDK=3.0.100-preview4-011223
  [Host]     : .NET Core 3.0.0-preview4-27615-11 (CoreCLR 4.6.27615.73, CoreFX 4.700.19.21213), 64bit RyuJIT  [AttachedDebugger]
  DefaultJob : .NET Core 3.0.0-preview4-27615-11 (CoreCLR 4.6.27615.73, CoreFX 4.700.19.21213), 64bit RyuJIT


|        Method |     Mean |     Error |    StdDev |
|-------------- |---------:|----------:|----------:|
| TargetMethodA | 3.864 ms | 0.1641 ms | 0.4379 ms |

// * Warnings *
MinIterationTime
  BenchmarkTest.TargetMethodA: Default -> The minimum observed iteration time is 6.1345 ms which is very small. It's recommended to increase it.
Environment
  Summary -> Benchmark was executed with attached debugger

// * Hints *
Outliers
  BenchmarkTest.TargetMethodA: Default -> 17 outliers were removed, 18 outliers were detected (95.85 us, 4.57 ms..8.25 ms)

// * Legends *
  Mean   : Arithmetic mean of all measurements
  Error  : Half of 99.9% confidence interval
  StdDev : Standard deviation of all measurements
  1 ms   : 1 Millisecond (0.001 sec)

// ***** BenchmarkRunner: End *****
// ** Remained 0 benchmark(s) to run **
Run time: 00:01:27 (87.99 sec), executed benchmarks: 1

Global total time: 00:01:42 (102.31 sec), executed benchmarks: 1
// * Artifacts cleanup *

出力をみてみると実行結果の概要がマークダウンの表として出力されていて、これをそのまま貼り付ければ以下のように表示されるのが便利です。