CODEWITHSUNDEEP
javagarbage-collectionmicrobenchmarkjmh
Pleymor
Pleymor

Reputation: 2921

Random peaks in JMH Benchmark Iterations

I am trying to bench a very fast method (~20 us/op), and it seems to work pretty well, excepted for a few iterations which are randomly very long:

Iteration  63: 14.319 us/op
Iteration  64: 13.128 us/op
Iteration  65: 15.198 us/op
Iteration  66: 20.822 us/op
Iteration  67: 21.669 us/op
Iteration  68: 21.439 us/op
Iteration  69: 15.946 us/op
Iteration  70: 18.793 us/op
Iteration  71: 19.212 us/op
Iteration  72: 816.129 us/op  // oopsy
Iteration  73: 22.115 us/op
Iteration  74: 15.143 us/op
Iteration  75: 18.423 us/op
Iteration  76: 15.238 us/op

Result "benchmark.StuffBench.run_bench":
  20.629 ±(99.9%) 9.164 us/op [Average]
  (min, avg, max) = (12.689, 20.629, 816.129), stdev = 47.763
  CI (99.9%): [11.464, 29.793] (assumes normal distribution)

It might be the GC, but shouldDoGc(false) does not change anything:

final Options options = new OptionsBuilder()
                .include(StuffBench.class.getSimpleName())
                .shouldDoGC(false)
                .build();
Collection<RunResult> runResults = new Runner(options).run();

Benchmark class:

@Fork(value = 2)
@Threads(1)
@Warmup(iterations = 1000, time = 50, timeUnit = TimeUnit.MICROSECONDS)
@Measurement(iterations = 150, time = 50, timeUnit = TimeUnit.MICROSECONDS)
@Timeout(time = 50, timeUnit = TimeUnit.MICROSECONDS)
@OutputTimeUnit(TimeUnit.MICROSECONDS)
@BenchmarkMode(Mode.AverageTime)
@State(Scope.Benchmark)
public class StuffBench {
    private Stuff stuff;

    @Setup
    public void initialize() {
        stuff = new Stuff();
    }

    @Benchmark
    public void run_bench() {
        stuff.run();
    }
}

Upvotes: 3

Views: 241

Answers (1)

Peter Lawrey
Peter Lawrey

Reputation: 533790

To solve this kind problem I have used what I call a jitter sampler. You have one thread setting a timestamp, running the code, reset the timestamp and pausing to not overload the CPU. A second thread samples the time stamp and if it is active and has been too long e.g. 20 us, you print a stack trace of what it is doing. e.g. Thread.getStackTrace() Combine the most common stack traces and you have a safepoint which can point to the problem (or the first safepoint after the problem) It's a bit more art than science ;)

Upvotes: 1

Related Questions