JMH iteration count/time affects benchmark results in an odd way

[Aleksey Shipilev]

On 08/06/2016 06:46 PM, Dávid Karnok wrote:
> Hi. I'm running a benchmark (
> https://github.com/reactor/reactive-streams-commons/blob/master/src/jmh/java/rsc/scheduler/SingleSchedulerPerf.java)
> and getting odd results depending on the value of the measure annotation.
> My specs: i7 4770K, Windows 7 x64, Java 8u102, tried with both v1.11.3 and
> v1.13
> 
> If I run the benchmark with this (rest the same):
> 
>    @Measurement(iterations = 5, time = 1, timeUnit = TimeUnit.SECONDS)
> 
>    I get around 8000 +/- 2000 ops/second for both the warmup and the
> measurement (in each iteration).
> 
> 
> If I run the benchmark with this:
> 
>    @Measurement(iterations = 5, time = 2, timeUnit = TimeUnit.SECONDS)
> 
>    I get 14000 +/- 1000 ops/second for both the warmup and measurement,
> even though the warmup still uses time = 1
> 
> 
> If I run the benchmark with this:
> 
>    @Measurement(iterations = 10, time = 1, timeUnit = TimeUnit.SECONDS)
> 
>    I get 14000 +/- 1000 ops/second for both the warmup and measurement
> again.
> 
> 
> I've run the bench with each settings several times but still getting the
> same pattern. Given that every other parameter and algorithm is the same,
> how can the measurement count or time affect ops/s upfront?

Well, this is usually indicative of two things:
 a) @Benchmark is not steady-state, and subsequent @Benchmark
invocations are getting faster/slower -- which means longer running
benchmark would deviate upwards/downwards;
 b) Huge run-to-run variance, which means the experiment that appears
slow is an outlier.

However, this cannot explain the behavior if the result is consistent
and/or affects warmup *before* any measurement iterations were even
invoked. This makes me think something is odd in your benchmarking
environment.

For example, on my i7 4770K, Linux x86_64, JDK 8b101, running "./gradlew
jmh -Pjmh='SingleSchedulerPerf'":

@Measurement(iterations = 10, time = 2, timeUnit = TimeUnit.SECONDS)
SingleSchedulerPerf.pipeline: 15391.283 ± 267.733  ops/s

@Measurement(iterations = 10, time = 1, timeUnit = TimeUnit.SECONDS)
SingleSchedulerPerf.pipeline: 15498.424 ± 153.380  ops/s

@Measurement(iterations = 5, time = 1, timeUnit = TimeUnit.SECONDS)
SingleSchedulerPerf.pipeline: 15001.340 ± 455.589  ops/s

@Measurement(iterations = 5, time = 2, timeUnit = TimeUnit.SECONDS)
SingleSchedulerPerf.pipeline: 15515.072 ± 650.476  ops/s


Run with more forks, maybe?

Thanks,
-Aleksey