Setup time is counted against iteration time in Mode.SingleShotTime (JMH-1.0)
Dmitry Vyazelenko
vyazelenko at yahoo.com
Mon Sep 1 14:48:35 UTC 2014
Hi,
I've discovered that when Mode.SingleShotTime is used the time in @Setup
is counted against iteration time. This results in benchmark being interrupted
if @Setup takes long time.
What is also interesting is that iteration time for Mode.SingleShotTime is set
to 10 minutes. I would expect that in this mode JMH will wait forever for iteration
to complete. Or at least such behavior should be documented somewhere. :)
Here is the benchmark to reproduce:
@Fork(1)
@Warmup(iterations=10)
@Measurement(iterations=10)
@OutputTimeUnit(TimeUnit.NANOSECONDS)
@State(Scope.Benchmark)
@BenchmarkMode(Mode.SingleShotTime)
public class SetupTimeCountedAgainstIterationTime_SingleShotTime {
@Setup(Level.Trial)
public void setUp() throws Exception {
System.out.println("Starting setup...");
Thread.sleep(TimeUnit.MINUTES.toMillis(15));
System.out.println("Setup finished!");
}
@Benchmark
public void baseline() {
}
}
When executed it fails with InterruptedException:
java -jar target\benchmarks.jar -foe true
# VM invoker: C:\Program Files\Java\jre7\bin\java.exe
# VM options: <none>
# Warmup: 10 iterations, single-shot each
# Measurement: 10 iterations, single-shot each
# Threads: 1 thread
# Benchmark mode: Single shot invocation time
# Benchmark: org.sample.SetupTimeCountedAgainstIterationTime_SingleShotTime.baseline
# Run progress: 0.00% complete, ETA 00:00:00
# Fork: 1 of 1
# Warmup Iteration 1: Starting setup...
(*interrupt*) <failure>
java.lang.InterruptedException: sleep interrupted
at java.lang.Thread.sleep(Native Method)
at org.sample.SetupTimeCountedAgainstIterationTime_SingleShotTime.setUp(SetupTimeCountedAgainstIterationTime_SingleShotTime.java:16)
at org.sample.generated.SetupTimeCountedAgainstIterationTime_SingleShotTime_baseline._jmh_tryInit_f_setuptimecountedagainstiterationtime_singleshottime0_G(SetupTimeCountedAgainstIterationTime_SingleShotTime_baseline.java:340)
at org.sample.generated.SetupTimeCountedAgainstIterationTime_SingleShotTime_baseline.baseline_SingleShotTime(SetupTimeCountedAgainstIterationTime_SingleShotTime_baseline.java:281)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at org.openjdk.jmh.runner.LoopBenchmarkHandler$BenchmarkTask.call(LoopBenchmarkHandler.java:210)
at org.openjdk.jmh.runner.LoopBenchmarkHandler$BenchmarkTask.call(LoopBenchmarkHandler.java:192)
at java.util.concurrent.FutureTask.run(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)
Expected: @Setup completes after 15 minutes and benchmark executes without exception.
Best regards,
Dmitry Vyazelenko
More information about the jmh-dev
mailing list