BenchmarkDotNet
BenchmarkDotNet copied to clipboard
Published
20 hours ago •
dotnet
dotnet
BenchmarkDotNet hangs when run via crank with [EventPipeProfiler]
trafficstars
I've been experimenting with crank to run microbenchmarks and found that if a benchmark is run using it that uses [EventPipeProfiler(BenchmarkDotNet.Diagnosers.EventPipeProfile.CpuSampling)], the benchmark process will hang just before it should complete (similar to #1383).
To replicate, clone https://github.com/martincostello/crank-sandbox/commit/54641fa2a30441721ace18bcaed819f4d187bc4f and run .\perf.ps1 -Scenario microbenchmarks-local.
The process will hang when the benchmark is about to complete. The output from running the benchmark project in different ways are shown below.
Run with [EventPipeProfiler(...)] using crank
Running the benchmark with [EventPipeProfiler(...)] hangs:
Benchmark output via crank which hangs
[10:15:18.748] Running session '63c14cbb8ce04187b3a0e4d111302d00' with description ''
[10:15:18.777] Starting job 'application' ...
[10:15:18.890] Submitted job: http://localhost:5010/jobs/1
[10:15:20.956] 'application' has been selected by the server ...
[10:15:20.957] Using local folder: "C:\Coding\martincostello\crank-sandbox"
[10:15:21.189] Uploading C:\Users\martin.costello\AppData\Local\Temp\tmpF427.tmp (1,000KB)
[10:15:21.222] 'application' is now building ... http://localhost:5010/jobs/1/buildlog
[10:16:23.828] 'application' is running ... http://localhost:5010/jobs/1/output
// Validating benchmarks:
Assembly Microbenchmarks, Version=1.0.0.0, Culture=neutral, PublicKeyToken=9a192a7522c9e1a0 is located in temp. If you are running benchmarks from xUnit you need to disable shadow copy. It's not supported by design.
// ***** BenchmarkRunner: Start *****
// ***** Found 1 benchmark(s) in total *****
// ***** Building 1 exe(s) in Parallel: Start *****
// ***** Done, took 00:00:00 (0.06 sec) *****
// Found 1 benchmarks:
// ArrayBenchmarks.Empty: Job-AFIJBW(Toolchain=InProcessEmitToolchain, IterationCount=3, LaunchCount=1, WarmupCount=3)
// **************************
// Benchmark: ArrayBenchmarks.Empty: Job-AFIJBW(Toolchain=InProcessEmitToolchain, IterationCount=3, LaunchCount=1, WarmupCount=3)
// *** Execute ***
// Launch: 1 / 1
// Benchmark Process Environment Information:
// Runtime=.NET 6.0.1 (6.0.121.56705), X64 RyuJIT
// GC=Concurrent Workstation
// Job: Job-AFIJBW(Toolchain=InProcessEmitToolchain, IterationCount=3, LaunchCount=1, WarmupCount=3)
OverheadJitting 1: 1 op, 320100.00 ns, 320.1000 us/op
WorkloadJitting 1: 1 op, 238800.00 ns, 238.8000 us/op
OverheadJitting 2: 16 op, 696500.00 ns, 43.5312 us/op
WorkloadJitting 2: 16 op, 724800.00 ns, 45.3000 us/op
WorkloadPilot 1: 16 op, 2900.00 ns, 181.2500 ns/op
WorkloadPilot 2: 32 op, 1900.00 ns, 59.3750 ns/op
WorkloadPilot 3: 64 op, 1600.00 ns, 25.0000 ns/op
WorkloadPilot 4: 128 op, 2100.00 ns, 16.4062 ns/op
WorkloadPilot 5: 256 op, 2900.00 ns, 11.3281 ns/op
WorkloadPilot 6: 512 op, 5100.00 ns, 9.9609 ns/op
WorkloadPilot 7: 1024 op, 9300.00 ns, 9.0820 ns/op
WorkloadPilot 8: 2048 op, 17400.00 ns, 8.4961 ns/op
WorkloadPilot 9: 4096 op, 34500.00 ns, 8.4229 ns/op
WorkloadPilot 10: 8192 op, 66000.00 ns, 8.0566 ns/op
WorkloadPilot 11: 16384 op, 131500.00 ns, 8.0261 ns/op
WorkloadPilot 12: 32768 op, 268100.00 ns, 8.1818 ns/op
WorkloadPilot 13: 65536 op, 545200.00 ns, 8.3191 ns/op
WorkloadPilot 14: 131072 op, 1082700.00 ns, 8.2603 ns/op
WorkloadPilot 15: 262144 op, 2178700.00 ns, 8.3111 ns/op
WorkloadPilot 16: 524288 op, 4639100.00 ns, 8.8484 ns/op
WorkloadPilot 17: 1048576 op, 11990500.00 ns, 11.4350 ns/op
WorkloadPilot 18: 2097152 op, 18175000.00 ns, 8.6665 ns/op
WorkloadPilot 19: 4194304 op, 34453700.00 ns, 8.2144 ns/op
WorkloadPilot 20: 8388608 op, 69075500.00 ns, 8.2344 ns/op
WorkloadPilot 21: 16777216 op, 81825500.00 ns, 4.8772 ns/op
WorkloadPilot 22: 33554432 op, 117627100.00 ns, 3.5056 ns/op
WorkloadPilot 23: 67108864 op, 233796900.00 ns, 3.4838 ns/op
WorkloadPilot 24: 134217728 op, 469254900.00 ns, 3.4962 ns/op
WorkloadPilot 25: 268435456 op, 929340600.00 ns, 3.4621 ns/op
OverheadWarmup 1: 268435456 op, 973219900.00 ns, 3.6255 ns/op
OverheadWarmup 2: 268435456 op, 907064600.00 ns, 3.3791 ns/op
OverheadWarmup 3: 268435456 op, 908831600.00 ns, 3.3857 ns/op
OverheadWarmup 4: 268435456 op, 903413400.00 ns, 3.3655 ns/op
OverheadWarmup 5: 268435456 op, 904842600.00 ns, 3.3708 ns/op
OverheadWarmup 6: 268435456 op, 900978200.00 ns, 3.3564 ns/op
OverheadActual 1: 268435456 op, 898010400.00 ns, 3.3453 ns/op
OverheadActual 2: 268435456 op, 897681100.00 ns, 3.3441 ns/op
OverheadActual 3: 268435456 op, 936824300.00 ns, 3.4899 ns/op
OverheadActual 4: 268435456 op, 900479900.00 ns, 3.3545 ns/op
OverheadActual 5: 268435456 op, 893593100.00 ns, 3.3289 ns/op
OverheadActual 6: 268435456 op, 890133600.00 ns, 3.3160 ns/op
OverheadActual 7: 268435456 op, 1102080300.00 ns, 4.1056 ns/op
OverheadActual 8: 268435456 op, 896531900.00 ns, 3.3398 ns/op
OverheadActual 9: 268435456 op, 892172700.00 ns, 3.3236 ns/op
OverheadActual 10: 268435456 op, 890106200.00 ns, 3.3159 ns/op
OverheadActual 11: 268435456 op, 950896800.00 ns, 3.5424 ns/op
OverheadActual 12: 268435456 op, 897117900.00 ns, 3.3420 ns/op
OverheadActual 13: 268435456 op, 916266600.00 ns, 3.4134 ns/op
OverheadActual 14: 268435456 op, 888049800.00 ns, 3.3082 ns/op
OverheadActual 15: 268435456 op, 884401900.00 ns, 3.2947 ns/op
WorkloadWarmup 1: 268435456 op, 906255600.00 ns, 3.3761 ns/op
WorkloadWarmup 2: 268435456 op, 894847900.00 ns, 3.3336 ns/op
WorkloadWarmup 3: 268435456 op, 893384300.00 ns, 3.3281 ns/op
WorkloadActual 1: 268435456 op, 889573900.00 ns, 3.3139 ns/op
WorkloadActual 2: 268435456 op, 892718100.00 ns, 3.3256 ns/op
WorkloadActual 3: 268435456 op, 920964500.00 ns, 3.4309 ns/op
WorkloadResult 1: 268435456 op, 0.00 ns, 0.0000 ns/op
WorkloadResult 2: 268435456 op, 0.00 ns, 0.0000 ns/op
WorkloadResult 3: 268435456 op, 23846600.00 ns, 0.0888 ns/op
GC: 0 0 0 768 268435456
Threading: 0 0 268435456
// Run, Diagnostic
// Benchmark Process Environment Information:
// Runtime=.NET 6.0.1 (6.0.121.56705), X64 RyuJIT
// GC=Concurrent Workstation
// Job: Job-AFIJBW(Toolchain=InProcessEmitToolchain, IterationCount=3, LaunchCount=1, WarmupCount=3)
OverheadJitting 1: 1 op, 200.00 ns, 200.0000 ns/op
WorkloadJitting 1: 1 op, 200.00 ns, 200.0000 ns/op
OverheadJitting 2: 16 op, 300.00 ns, 18.7500 ns/op
WorkloadJitting 2: 16 op, 400.00 ns, 25.0000 ns/op
WorkloadPilot 1: 16 op, 400.00 ns, 25.0000 ns/op
WorkloadPilot 2: 32 op, 400.00 ns, 12.5000 ns/op
WorkloadPilot 3: 64 op, 600.00 ns, 9.3750 ns/op
WorkloadPilot 4: 128 op, 800.00 ns, 6.2500 ns/op
WorkloadPilot 5: 256 op, 1100.00 ns, 4.2969 ns/op
WorkloadPilot 6: 512 op, 1800.00 ns, 3.5156 ns/op
WorkloadPilot 7: 1024 op, 3400.00 ns, 3.3203 ns/op
WorkloadPilot 8: 2048 op, 6500.00 ns, 3.1738 ns/op
WorkloadPilot 9: 4096 op, 12500.00 ns, 3.0518 ns/op
WorkloadPilot 10: 8192 op, 25400.00 ns, 3.1006 ns/op
WorkloadPilot 11: 16384 op, 50500.00 ns, 3.0823 ns/op
WorkloadPilot 12: 32768 op, 100500.00 ns, 3.0670 ns/op
WorkloadPilot 13: 65536 op, 522800.00 ns, 7.9773 ns/op
WorkloadPilot 14: 131072 op, 586900.00 ns, 4.4777 ns/op
WorkloadPilot 15: 262144 op, 1018900.00 ns, 3.8868 ns/op
WorkloadPilot 16: 524288 op, 2063100.00 ns, 3.9351 ns/op
WorkloadPilot 17: 1048576 op, 3838000.00 ns, 3.6602 ns/op
WorkloadPilot 18: 2097152 op, 7552100.00 ns, 3.6011 ns/op
WorkloadPilot 19: 4194304 op, 14838000.00 ns, 3.5377 ns/op
WorkloadPilot 20: 8388608 op, 30759100.00 ns, 3.6668 ns/op
WorkloadPilot 21: 16777216 op, 61071900.00 ns, 3.6402 ns/op
WorkloadPilot 22: 33554432 op, 125661400.00 ns, 3.7450 ns/op
WorkloadPilot 23: 67108864 op, 244868800.00 ns, 3.6488 ns/op
WorkloadPilot 24: 134217728 op, 488025900.00 ns, 3.6361 ns/op
WorkloadPilot 25: 268435456 op, 979080700.00 ns, 3.6474 ns/op
OverheadWarmup 1: 268435456 op, 970278600.00 ns, 3.6146 ns/op
OverheadWarmup 2: 268435456 op, 983991400.00 ns, 3.6657 ns/op
OverheadWarmup 3: 268435456 op, 953983000.00 ns, 3.5539 ns/op
OverheadWarmup 4: 268435456 op, 983715600.00 ns, 3.6646 ns/op
OverheadWarmup 5: 268435456 op, 1053442500.00 ns, 3.9244 ns/op
OverheadWarmup 6: 268435456 op, 1026788900.00 ns, 3.8251 ns/op
OverheadActual 1: 268435456 op, 996092200.00 ns, 3.7107 ns/op
OverheadActual 2: 268435456 op, 982976300.00 ns, 3.6619 ns/op
OverheadActual 3: 268435456 op, 978177200.00 ns, 3.6440 ns/op
OverheadActual 4: 268435456 op, 971212900.00 ns, 3.6180 ns/op
OverheadActual 5: 268435456 op, 970812700.00 ns, 3.6166 ns/op
OverheadActual 6: 268435456 op, 963666900.00 ns, 3.5899 ns/op
OverheadActual 7: 268435456 op, 957076400.00 ns, 3.5654 ns/op
OverheadActual 8: 268435456 op, 962566000.00 ns, 3.5858 ns/op
OverheadActual 9: 268435456 op, 962844300.00 ns, 3.5869 ns/op
OverheadActual 10: 268435456 op, 965152300.00 ns, 3.5955 ns/op
OverheadActual 11: 268435456 op, 1005165100.00 ns, 3.7445 ns/op
OverheadActual 12: 268435456 op, 1073419500.00 ns, 3.9988 ns/op
OverheadActual 13: 268435456 op, 1119569100.00 ns, 4.1707 ns/op
OverheadActual 14: 268435456 op, 1034841800.00 ns, 3.8551 ns/op
OverheadActual 15: 268435456 op, 990678700.00 ns, 3.6906 ns/op
WorkloadWarmup 1: 268435456 op, 1010880000.00 ns, 3.7658 ns/op
WorkloadWarmup 2: 268435456 op, 1021374200.00 ns, 3.8049 ns/op
WorkloadWarmup 3: 268435456 op, 1000011500.00 ns, 3.7253 ns/op
WorkloadActual 1: 268435456 op, 1019726000.00 ns, 3.7988 ns/op
WorkloadActual 2: 268435456 op, 1017723100.00 ns, 3.7913 ns/op
WorkloadActual 3: 268435456 op, 1007113600.00 ns, 3.7518 ns/op
WorkloadResult 1: 268435456 op, 41548800.00 ns, 0.1548 ns/op
WorkloadResult 2: 268435456 op, 39545900.00 ns, 0.1473 ns/op
WorkloadResult 3: 268435456 op, 28936400.00 ns, 0.1078 ns/op
GC: 0 0 0 1048 268435456
Threading: 0 0 268435456
Run with [EventPipeProfiler(...)] using dotnet run
Running the benchmark project using dotnet run directly (i.e. not through crank) does not hang:
Benchmark output via dotnet run which does not hang
> dotnet run --project .\src\Microbenchmarks\Microbenchmarks.csproj --configuration Release -- --job short --filter * --memory
// Validating benchmarks:
// ***** BenchmarkRunner: Start *****
// ***** Found 1 benchmark(s) in total *****
// ***** Building 1 exe(s) in Parallel: Start *****
// start dotnet restore /p:UseSharedCompilation=false /p:BuildInParallel=false /m:1 /p:Deterministic=true /p:Optimize=true in C:\Coding\martincostello\crank-sandbox\src\Microbenchmarks\bin\Release\net6.0\200a1bdb-e575-44ae-a1a1-fb0a7af00aa0
// command took 0.94s and exited with 0
// start dotnet build -c Release --no-restore /p:UseSharedCompilation=false /p:BuildInParallel=false /m:1 /p:Deterministic=true /p:Optimize=true in C:\Coding\martincostello\crank-sandbox\src\Microbenchmarks\bin\Release\net6.0\200a1bdb-e575-44ae-a1a1-fb0a7af00aa0
// command took 2.49s and exited with 0
// ***** Done, took 00:00:03 (3.51 sec) *****
// Found 1 benchmarks:
// ArrayBenchmarks.Empty: ShortRun(IterationCount=3, LaunchCount=1, WarmupCount=3)
// **************************
// Benchmark: ArrayBenchmarks.Empty: ShortRun(IterationCount=3, LaunchCount=1, WarmupCount=3)
// *** Execute ***
// Launch: 1 / 1
// Execute: dotnet "200a1bdb-e575-44ae-a1a1-fb0a7af00aa0.dll" --benchmarkName "Microbenchmarks.ArrayBenchmarks.Empty" --job "ShortRun" --benchmarkId 0 in C:\Coding\martincostello\crank-sandbox\src\Microbenchmarks\bin\Release\net6.0\200a1bdb-e575-44ae-a1a1-fb0a7af00aa0\bin\Release\net6.0
// BeforeAnythingElse
// Benchmark Process Environment Information:
// Runtime=.NET 6.0.1 (6.0.121.56705), X64 RyuJIT
// GC=Concurrent Workstation
// Job: ShortRun(IterationCount=3, LaunchCount=1, WarmupCount=3)
OverheadJitting 1: 1 op, 245200.00 ns, 245.2000 us/op
WorkloadJitting 1: 1 op, 169700.00 ns, 169.7000 us/op
OverheadJitting 2: 16 op, 471900.00 ns, 29.4937 us/op
WorkloadJitting 2: 16 op, 537600.00 ns, 33.6000 us/op
WorkloadPilot 1: 16 op, 800.00 ns, 50.0000 ns/op
WorkloadPilot 2: 32 op, 1000.00 ns, 31.2500 ns/op
WorkloadPilot 3: 64 op, 1200.00 ns, 18.7500 ns/op
WorkloadPilot 4: 128 op, 1700.00 ns, 13.2812 ns/op
WorkloadPilot 5: 256 op, 2600.00 ns, 10.1562 ns/op
WorkloadPilot 6: 512 op, 4700.00 ns, 9.1797 ns/op
WorkloadPilot 7: 1024 op, 8900.00 ns, 8.6914 ns/op
WorkloadPilot 8: 2048 op, 17300.00 ns, 8.4473 ns/op
WorkloadPilot 9: 4096 op, 33400.00 ns, 8.1543 ns/op
WorkloadPilot 10: 8192 op, 66200.00 ns, 8.0811 ns/op
WorkloadPilot 11: 16384 op, 182000.00 ns, 11.1084 ns/op
WorkloadPilot 12: 32768 op, 317100.00 ns, 9.6771 ns/op
WorkloadPilot 13: 65536 op, 662800.00 ns, 10.1135 ns/op
WorkloadPilot 14: 131072 op, 1052800.00 ns, 8.0322 ns/op
WorkloadPilot 15: 262144 op, 2214500.00 ns, 8.4476 ns/op
WorkloadPilot 16: 524288 op, 4420000.00 ns, 8.4305 ns/op
WorkloadPilot 17: 1048576 op, 9001100.00 ns, 8.5841 ns/op
WorkloadPilot 18: 2097152 op, 17705100.00 ns, 8.4424 ns/op
WorkloadPilot 19: 4194304 op, 35598400.00 ns, 8.4873 ns/op
WorkloadPilot 20: 8388608 op, 61494000.00 ns, 7.3307 ns/op
WorkloadPilot 21: 16777216 op, 58462700.00 ns, 3.4846 ns/op
WorkloadPilot 22: 33554432 op, 114558100.00 ns, 3.4141 ns/op
WorkloadPilot 23: 67108864 op, 225797300.00 ns, 3.3646 ns/op
WorkloadPilot 24: 134217728 op, 455127000.00 ns, 3.3910 ns/op
WorkloadPilot 25: 268435456 op, 904989700.00 ns, 3.3713 ns/op
OverheadWarmup 1: 268435456 op, 917160200.00 ns, 3.4167 ns/op
OverheadWarmup 2: 268435456 op, 913590600.00 ns, 3.4034 ns/op
OverheadWarmup 3: 268435456 op, 947876000.00 ns, 3.5311 ns/op
OverheadWarmup 4: 268435456 op, 915310300.00 ns, 3.4098 ns/op
OverheadWarmup 5: 268435456 op, 933133700.00 ns, 3.4762 ns/op
OverheadWarmup 6: 268435456 op, 918496100.00 ns, 3.4217 ns/op
OverheadActual 1: 268435456 op, 909851300.00 ns, 3.3895 ns/op
OverheadActual 2: 268435456 op, 927718700.00 ns, 3.4560 ns/op
OverheadActual 3: 268435456 op, 911818700.00 ns, 3.3968 ns/op
OverheadActual 4: 268435456 op, 924241600.00 ns, 3.4431 ns/op
OverheadActual 5: 268435456 op, 906062000.00 ns, 3.3753 ns/op
OverheadActual 6: 268435456 op, 907505600.00 ns, 3.3807 ns/op
OverheadActual 7: 268435456 op, 916456600.00 ns, 3.4141 ns/op
OverheadActual 8: 268435456 op, 946998000.00 ns, 3.5278 ns/op
OverheadActual 9: 268435456 op, 980132700.00 ns, 3.6513 ns/op
OverheadActual 10: 268435456 op, 951012000.00 ns, 3.5428 ns/op
OverheadActual 11: 268435456 op, 955429300.00 ns, 3.5593 ns/op
OverheadActual 12: 268435456 op, 941769100.00 ns, 3.5084 ns/op
OverheadActual 13: 268435456 op, 917283800.00 ns, 3.4171 ns/op
OverheadActual 14: 268435456 op, 936825100.00 ns, 3.4899 ns/op
OverheadActual 15: 268435456 op, 920712500.00 ns, 3.4299 ns/op
WorkloadWarmup 1: 268435456 op, 930204900.00 ns, 3.4653 ns/op
WorkloadWarmup 2: 268435456 op, 940036400.00 ns, 3.5019 ns/op
WorkloadWarmup 3: 268435456 op, 916463500.00 ns, 3.4141 ns/op
// BeforeActualRun
WorkloadActual 1: 268435456 op, 936133700.00 ns, 3.4874 ns/op
WorkloadActual 2: 268435456 op, 906952600.00 ns, 3.3787 ns/op
WorkloadActual 3: 268435456 op, 906443500.00 ns, 3.3768 ns/op
// AfterActualRun
WorkloadResult 1: 268435456 op, 11892100.00 ns, 0.0443 ns/op
WorkloadResult 2: 268435456 op, 0.00 ns, 0.0000 ns/op
WorkloadResult 3: 268435456 op, 0.00 ns, 0.0000 ns/op
GC: 0 0 0 480 268435456
Threading: 0 0 268435456
// AfterAll
// Benchmark Process 18532 has exited with code 0.
// Run, Diagnostic
// Execute: dotnet "200a1bdb-e575-44ae-a1a1-fb0a7af00aa0.dll" --benchmarkName "Microbenchmarks.ArrayBenchmarks.Empty" --job "ShortRun" --benchmarkId 0 in C:\Coding\martincostello\crank-sandbox\src\Microbenchmarks\bin\Release\net6.0\200a1bdb-e575-44ae-a1a1-fb0a7af00aa0\bin\Release\net6.0
// BeforeAnythingElse
// Benchmark Process Environment Information:
// Runtime=.NET 6.0.1 (6.0.121.56705), X64 RyuJIT
// GC=Concurrent Workstation
// Job: ShortRun(IterationCount=3, LaunchCount=1, WarmupCount=3)
OverheadJitting 1: 1 op, 259700.00 ns, 259.7000 us/op
WorkloadJitting 1: 1 op, 171800.00 ns, 171.8000 us/op
OverheadJitting 2: 16 op, 492800.00 ns, 30.8000 us/op
WorkloadJitting 2: 16 op, 546700.00 ns, 34.1688 us/op
WorkloadPilot 1: 16 op, 700.00 ns, 43.7500 ns/op
WorkloadPilot 2: 32 op, 800.00 ns, 25.0000 ns/op
WorkloadPilot 3: 64 op, 1000.00 ns, 15.6250 ns/op
WorkloadPilot 4: 128 op, 1500.00 ns, 11.7188 ns/op
WorkloadPilot 5: 256 op, 2400.00 ns, 9.3750 ns/op
WorkloadPilot 6: 512 op, 4300.00 ns, 8.3984 ns/op
WorkloadPilot 7: 1024 op, 7700.00 ns, 7.5195 ns/op
WorkloadPilot 8: 2048 op, 14900.00 ns, 7.2754 ns/op
WorkloadPilot 9: 4096 op, 29000.00 ns, 7.0801 ns/op
WorkloadPilot 10: 8192 op, 57500.00 ns, 7.0190 ns/op
WorkloadPilot 11: 16384 op, 151500.00 ns, 9.2468 ns/op
WorkloadPilot 12: 32768 op, 228200.00 ns, 6.9641 ns/op
WorkloadPilot 13: 65536 op, 472600.00 ns, 7.2113 ns/op
WorkloadPilot 14: 131072 op, 1447200.00 ns, 11.0413 ns/op
WorkloadPilot 15: 262144 op, 1936900.00 ns, 7.3887 ns/op
WorkloadPilot 16: 524288 op, 4010400.00 ns, 7.6492 ns/op
WorkloadPilot 17: 1048576 op, 9808600.00 ns, 9.3542 ns/op
WorkloadPilot 18: 2097152 op, 16603700.00 ns, 7.9173 ns/op
WorkloadPilot 19: 4194304 op, 32876100.00 ns, 7.8383 ns/op
WorkloadPilot 20: 8388608 op, 66539100.00 ns, 7.9321 ns/op
WorkloadPilot 21: 16777216 op, 95803800.00 ns, 5.7104 ns/op
WorkloadPilot 22: 33554432 op, 118425700.00 ns, 3.5294 ns/op
WorkloadPilot 23: 67108864 op, 240476000.00 ns, 3.5834 ns/op
WorkloadPilot 24: 134217728 op, 468161600.00 ns, 3.4881 ns/op
WorkloadPilot 25: 268435456 op, 949462100.00 ns, 3.5370 ns/op
OverheadWarmup 1: 268435456 op, 1036425300.00 ns, 3.8610 ns/op
OverheadWarmup 2: 268435456 op, 1055739900.00 ns, 3.9329 ns/op
OverheadWarmup 3: 268435456 op, 1014692900.00 ns, 3.7800 ns/op
OverheadWarmup 4: 268435456 op, 1015835200.00 ns, 3.7843 ns/op
OverheadWarmup 5: 268435456 op, 949966400.00 ns, 3.5389 ns/op
OverheadActual 1: 268435456 op, 950786400.00 ns, 3.5420 ns/op
OverheadActual 2: 268435456 op, 958870300.00 ns, 3.5721 ns/op
OverheadActual 3: 268435456 op, 955248500.00 ns, 3.5586 ns/op
OverheadActual 4: 268435456 op, 953680000.00 ns, 3.5527 ns/op
OverheadActual 5: 268435456 op, 945617500.00 ns, 3.5227 ns/op
OverheadActual 6: 268435456 op, 962935500.00 ns, 3.5872 ns/op
OverheadActual 7: 268435456 op, 989605300.00 ns, 3.6866 ns/op
OverheadActual 8: 268435456 op, 1000879900.00 ns, 3.7286 ns/op
OverheadActual 9: 268435456 op, 976607800.00 ns, 3.6381 ns/op
OverheadActual 10: 268435456 op, 956959700.00 ns, 3.5650 ns/op
OverheadActual 11: 268435456 op, 952369600.00 ns, 3.5479 ns/op
OverheadActual 12: 268435456 op, 956541900.00 ns, 3.5634 ns/op
OverheadActual 13: 268435456 op, 938919200.00 ns, 3.4977 ns/op
OverheadActual 14: 268435456 op, 941542100.00 ns, 3.5075 ns/op
OverheadActual 15: 268435456 op, 938157300.00 ns, 3.4949 ns/op
WorkloadWarmup 1: 268435456 op, 932054200.00 ns, 3.4722 ns/op
WorkloadWarmup 2: 268435456 op, 931331100.00 ns, 3.4695 ns/op
WorkloadWarmup 3: 268435456 op, 948968800.00 ns, 3.5352 ns/op
// BeforeActualRun
WorkloadActual 1: 268435456 op, 940339500.00 ns, 3.5030 ns/op
WorkloadActual 2: 268435456 op, 933018100.00 ns, 3.4758 ns/op
WorkloadActual 3: 268435456 op, 932689400.00 ns, 3.4745 ns/op
// AfterActualRun
WorkloadResult 1: 268435456 op, 0.00 ns, 0.0000 ns/op
WorkloadResult 2: 268435456 op, 0.00 ns, 0.0000 ns/op
WorkloadResult 3: 268435456 op, 0.00 ns, 0.0000 ns/op
GC: 0 0 0 384 268435456
Threading: 0 0 268435456
// AfterAll
Mean = 0.015 ns, StdErr = 0.015 ns (100.00%), N = 3, StdDev = 0.026 ns
Min = 0.000 ns, Q1 = 0.000 ns, Median = 0.000 ns, Q3 = 0.022 ns, Max = 0.044 ns
IQR = 0.022 ns, LowerFence = -0.033 ns, UpperFence = 0.055 ns
ConfidenceInterval = [-0.452 ns; 0.481 ns] (CI 99.9%), Margin = 0.467 ns (3159.91% of Mean)
Skewness = 0.38, Kurtosis = 0.67, MValue = 2
// ***** BenchmarkRunner: Finish *****
// * Export *
BenchmarkDotNet.Artifacts\results\Microbenchmarks.ArrayBenchmarks-report.csv
BenchmarkDotNet.Artifacts\results\Microbenchmarks.ArrayBenchmarks-report-github.md
BenchmarkDotNet.Artifacts\results\Microbenchmarks.ArrayBenchmarks-report.html
// * Detailed results *
ArrayBenchmarks.Empty: ShortRun(IterationCount=3, LaunchCount=1, WarmupCount=3)
Runtime = .NET 6.0.1 (6.0.121.56705), X64 RyuJIT; GC = Concurrent Workstation
Mean = 0.015 ns, StdErr = 0.015 ns (100.00%), N = 3, StdDev = 0.026 ns
Min = 0.000 ns, Q1 = 0.000 ns, Median = 0.000 ns, Q3 = 0.022 ns, Max = 0.044 ns
IQR = 0.022 ns, LowerFence = -0.033 ns, UpperFence = 0.055 ns
ConfidenceInterval = [-0.452 ns; 0.481 ns] (CI 99.9%), Margin = 0.467 ns (3159.91% of Mean)
Skewness = 0.38, Kurtosis = 0.67, MValue = 2
-------------------- Histogram --------------------
[-0.001 ns ; 0.045 ns) | @@@
---------------------------------------------------
// * Summary *
BenchmarkDotNet=v0.13.1, OS=Windows 10.0.22000
Intel Core i9-9980HK CPU 2.40GHz, 1 CPU, 16 logical and 8 physical cores
.NET SDK=6.0.101
[Host] : .NET 6.0.1 (6.0.121.56705), X64 RyuJIT
ShortRun : .NET 6.0.1 (6.0.121.56705), X64 RyuJIT
Job=ShortRun IterationCount=3 LaunchCount=1
WarmupCount=3
| Method | Mean | Error | StdDev | Median | Allocated |
|------- |----------:|----------:|----------:|-------:|----------:|
| Empty | 0.0148 ns | 0.4666 ns | 0.0256 ns | 0.0 ns | - |
// * Warnings *
ZeroMeasurement
ArrayBenchmarks.Empty: ShortRun -> The method duration is indistinguishable from the empty method duration
// * Legends *
Mean : Arithmetic mean of all measurements
Error : Half of 99.9% confidence interval
StdDev : Standard deviation of all measurements
Median : Value separating the higher half of all measurements (50th percentile)
Allocated : Allocated memory per single operation (managed only, inclusive, 1KB = 1024B)
1 ns : 1 Nanosecond (0.000000001 sec)
// * Diagnostic Output - MemoryDiagnoser *
// * Diagnostic Output - EventPipeProfiler *
Exported 1 trace file(s). Example:
C:\Coding\martincostello\crank-sandbox\BenchmarkDotNet.Artifacts\Microbenchmarks.ArrayBenchmarks.Empty-20220206-102638.speedscope.json
// ***** BenchmarkRunner: End *****
// ** Remained 0 benchmark(s) to run **
Run time: 00:00:57 (57.23 sec), executed benchmarks: 1
Global total time: 00:01:00 (60.75 sec), executed benchmarks: 1
// * Artifacts cleanup *
Run without [EventPipeProfiler(...)] using crank
Running the same command against the main branch without [EventPipeProfiler(...)] does not hang.
Benchmark output via crank which does not hang
> .\perf.ps1 -Scenario microbenchmarks-local
[10:12:12.583] Running session '03e067af6ecb4512834f602d1fd7a8a2' with description ''
[10:12:12.612] Starting job 'application' ...
[10:12:12.727] Submitted job: http://localhost:5010/jobs/1
[10:12:17.823] 'application' has been selected by the server ...
[10:12:17.824] Using local folder: "C:\Coding\martincostello\crank-sandbox"
[10:12:18.053] Uploading C:\Users\martin.costello\AppData\Local\Temp\tmp28D2.tmp (1,000KB)
[10:12:18.086] 'application' is now building ... http://localhost:5010/jobs/1/buildlog
[10:13:20.704] 'application' is running ... http://localhost:5010/jobs/1/output
[10:13:49.957] Stopping job 'application' ...
[10:13:51.052] Deleting job 'application' ...
BenchmarkDotNet=v0.13.1, OS=Windows 10.0.22000
Intel Core i9-9980HK CPU 2.40GHz, 1 CPU, 16 logical and 8 physical cores
.NET SDK=6.0.101
[Host] : .NET 6.0.1 (6.0.121.56705), X64 RyuJIT
Toolchain=InProcessEmitToolchain IterationCount=3 LaunchCount=1
WarmupCount=3
Method | Mean | Error | StdDev | Median | Allocated |
------- |----------:|----------:|----------:|-------:|----------:|
Empty | 0.0296 ns | 0.9365 ns | 0.0513 ns | 0.0 ns | - |
