Iteration/Warmup Timeout (was: Using jmh.shutdownTimeout)

[Behrooz Nobakht]

Hi,

Thanks for the reply. I'm a bit struggling again with a use case explained
below
and I'd appreciate any clues or hints on how to proceed.

Consider the following benchmark code:

<pre>
@BenchmarkMode(Mode.Throughput)
@Fork(value = 1)
@Warmup(iterations = 1, time = 32, timeUnit = TimeUnit.MILLISECONDS)
@Measurement(iterations = 16, time = 1, timeUnit = TimeUnit.SECONDS)
@Timeout(time = 1, timeUnit = TimeUnit.SECONDS)
@State(Scope.Benchmark)
public class SieveBenchmark {

  @Param({"10000", "50000", "1000000"})
  public long N;

  @Benchmark
  public Collection<Long> sieve() throws Exception {
    Main main = new Main(N);
    return main.primes();
  }

}
</pre>

Basically, `Main` launches a "bunch" of threads to compute the sequence of
primes up to N. I've been careful with ExecutorService and have added shut
down hooks to make sure they shut down when the forked JVM goes down.

When I run the benchmark here's the initial output:

<pre>
# JMH 1.9.3 (released 11 days ago)
# VM invoker: /nobeh/dev/software/jdk1.8.0_60-b16/jre/bin/java
# VM options: -Djmh.shutdownTimeout=1 -Djmh.shutdownTimeout.step=1 -Xmx8000m
# Warmup: 1 iterations, 32 ms each
# Measurement: 16 iterations, 1 s each
# Timeout: 1 s per iteration, ***WARNING: The timeout might be too low!***
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Throughput, ops/time
# Benchmark: com.github.crisposs.sieves.benchmark.SieveBenchmark.sieve
# Parameters: (N = 10000)

Forking 1 times using command:
[/nobeh/dev/software/jdk1.8.0_60-b16/jre/bin/java, -Djmh.shutdownTimeout=1,
-Djmh.shutdownTimeout.step=1, -Xmx8000m,
-XX:CompileCommandFile=/tmp/jmh7678188388270630343compilecommand, -cp,
prime-sieves-bench.jar, org.openjdk.jmh.runner.ForkedMain, 127.0.0.1, 51819]
# Run progress: 0.00% complete, ETA 00:00:48
# Fork: 1 of 1
System.gc() executed
# Warmup Iteration   1: Took PT4.818S : 9973
0.204 ops/s
System.gc() executed
Iteration   1: Took PT4.745S : 9973
0.211 ops/s
System.gc() executed
Iteration   2: Took PT4.67S : 9973
0.214 ops/s
System.gc() executed
Iteration   3: Took PT4.59S : 9973
0.218 ops/s
System.gc() executed
</pre>

The part that says "Took PTXXXS" is a line in class `Main` that is printed
at the end of the computation.

Please help me to correct my understanding:

- Based on the benchmark configuration I expect that each iteration is
allowed to be executed at most 1 second.
Is this not correct?
- If not, what should I use to have control over the iteration/warmup
explicit ending?
- When I add @Threads(N) to the benchmark configuration, although I expect
exceptions happen due to shutdown of threads (and catch them at a higher
level),
yet the benchmark fails to make progress to next iterations/warmups.
Any advice?

Thanks again,
Behrooz





On Fri, May 22, 2015 at 11:10 AM, Aleksey Shipilev <
aleksey.shipilev at oracle.com> wrote:

> On 22.05.2015 12:04, Behrooz Nobakht wrote:
> > Now my question is which one of the following is the correct way to use
> > this:
> >
> > Inside my benchmark Main:
> >
> > new OptionBuilder().jvmArgsPrepend("-Djmh.shutdownTimeout=N")
> >
> > or when running the benchmark as:
> >
> > java -Djmh.shutdownTimeout=N -jar uber.jar?
>
> Both are correct, depending on whether you are using an API launcher, or
> a CLI launcher.
>
> Thanks,
> -Aleksey
>
>
>


-- 
-- Behrooz Nobakht