dotnet / dotnet/BenchmarkDotNet

Incorrectly detected number of invocations

Open
#1,780 6 comments 1 reaction 1 assignee Claimed by @AndreyAkinshin View on GitHub
bug
Dominant language
C#
Stars
11.5k
Forks
1.1k
Avg merge
6d 11h
Merged PRs (30d)
12

Description

Currently, we have the following [heuristic](https://github.com/dotnet/BenchmarkDotNet/blob/v0.13.1/src/BenchmarkDotNet/Engines/EngineFactory.cs#L55): if the duration of the first `WorkloadJitting` iteration is more than `IterationTime` (which is [500ms](https://github.com/dotnet/BenchmarkDotNet/blob/v0.13.1/src/BenchmarkDotNet/Engines/EngineResolver.cs#L13) by default), we skip the `Pilot` stage and perform a single invocation in further iterations.

This heuristic doesn't always work well, so in this scope of #1573, we have introduced [another heuristic](https://github.com/dotnet/BenchmarkDotNet/blob/v0.13.1/src/BenchmarkDotNet/Engines/EngineFactory.cs#L47): if the duration of the first `WorkloadJitting` iteration takes more than `IterationTime`, we but less than 1 second (a magic number), we discard the first results and perform another `WorkloadJitting` iteration.

Unfortunately, it doesn't always work well either. If we try to run [these F# benchmarks](https://github.com/matthewcrews/SliceMapPerformanceExploration/blob/29970bfd00c92c3aadd9e4326db93ce9450086a8/Program.fs#L148) (the problem was originally reported [here](https://twitter.com/McCrews/status/1427688915884855298) by Matthew Crews), we could observe the following situation (the full log is available [here](https://gist.github.com/matthewcrews/bf1747d140df16e7e9c1d048400de4a5)):

```txt
WorkloadJitting 1: 1 op, 2660880000.00 ns, 2.6609 s/op

WorkloadWarmup 1: 1 op, 55999700.00 ns, 55.9997 ms/op
WorkloadWarmup 2: 1 op, 48296500.00 ns, 48.2965 ms/op
WorkloadWarmup 3: 1 op, 47339800.00 ns, 47.3398 ms/op
WorkloadWarmup 4: 1 op, 37181000.00 ns, 37.1810 ms/op
WorkloadWarmup 5: 1 op, 37303500.00 ns, 37.3035 ms/op
WorkloadWarmup 6: 1 op, 38082300.00 ns, 38.0823 ms/op
WorkloadWarmup 7: 1 op, 37534700.00 ns, 37.5347 ms/op
WorkloadWarmup 8: 1 op, 39494000.00 ns, 39.4940 ms/op
WorkloadWarmup 9: 1 op, 37381700.00 ns, 37.3817 ms/op
```

While the typical duration of the warmed benchmark is about 35-45ms, the first invocation takes more than 2.5 seconds. This situation leads to reasonable warnings:

![](https://pbs.twimg.com/media/E9Fhn2nUYAkdGVc?format=png&name=large)

I believe that the ultimate solution is to introduce an ability to restart the Pilot stage in the case of "too fast" WorkloadWarmup iterations. However, it would require a major refactoring of our Engine infrastructure. As a quick hotfix, we could just bump the magic number from 1 second to a higher value (let's say 10 seconds). The worst cast side effect from such a change is extra 10 seconds of the total benchmarking time for heavy benchmarks (that actually take more than 500ms, but less than 10 seconds).

@adamsitnik, what do you think?

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.