Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

JMH hangs between benchmarks (unable to kill forked JVM?)

Tags:

java

jvm

jmh

I have a large set of macrobenchmarks that measure execution time of various simulations using different execution engines (some of them are heavily multi-threaded). Most of these jobs use jmh settings that I specify in abstract base class as:

@ContextConfiguration(value = AbstractJobExecutorBenchmarker.CONTEXT_LOCATION)
@State(Scope.Benchmark)
@Fork(1)
@BenchmarkMode(Mode.SingleShotTime)
@Warmup(iterations = 1, timeUnit = TimeUnit.MILLISECONDS)
@Measurement(iterations = 5, timeUnit = TimeUnit.MILLISECONDS)
public abstract class AbstractJobExecutorBenchmarker extends AbstractTestNGSpringContextTests

(I also add -gc -si false to command line)

When I fire any single one of those benchmarks or some small subset it all works fine. However if I try to run all of them in one go (i.e. no filtering options), jmh succesfully finishies few of them and then suddenly frezees after one specific benchmark... alli terations for it are done, final results are printed, but it doesn't look like forked JVM was killed and new isn't starting, seems like whole process is stucked. Example of last statements printed:

Iteration   3: 03:59:52.059 [pool-8-thread-1] INFO  MessageTrafficController: Starting MessageTrafficController
03:59:52.059 [pool-8-thread-3] INFO  MessageTrafficController: Starting MessageTrafficController
03:59:52.060 [pool-8-thread-5] INFO  MessageTrafficController: Starting MessageTrafficController
03:59:52.060 [pool-8-thread-6] INFO  MessageTrafficController: Starting MessageTrafficController
03:59:52.061 [pool-8-thread-7] INFO  MessageTrafficController: Starting MessageTrafficController
03:59:52.061 [pool-8-thread-8] INFO  MessageTrafficController: Starting MessageTrafficController
03:59:52.061 [pool-8-thread-9] INFO  MessageTrafficController: Starting MessageTrafficController
03:59:52.061 [pool-8-thread-10] INFO  MessageTrafficController: Starting MessageTrafficController
03:59:52.062 [pool-8-thread-13] INFO  MessageTrafficController: Starting MessageTrafficController
03:59:52.062 [pool-8-thread-14] INFO  MessageTrafficController: Starting MessageTrafficController
03:59:52.063 [pool-8-thread-15] INFO  MessageTrafficController: Starting MessageTrafficController
03:59:52.063 [pool-8-thread-18] INFO  MessageTrafficController: Starting MessageTrafficController
03:59:52.063 [pool-8-thread-19] INFO  MessageTrafficController: Starting MessageTrafficController
03:59:52.064 [pool-8-thread-20] INFO  MessageTrafficController: Starting MessageTrafficController
03:59:52.064 [pool-8-thread-22] INFO  MessageTrafficController: Starting MessageTrafficController
03:59:52.065 [pool-8-thread-25] INFO  MessageTrafficController: Starting MessageTrafficController
04:00:57.600 [pool-8-thread-6] WARN  MessageTrafficController: Stopped due to class java.lang.InterruptedException
04:00:57.601 [pool-8-thread-7] WARN  MessageTrafficController: Stopped due to class java.lang.InterruptedException
04:00:57.604 [pool-8-thread-13] WARN  MessageTrafficController: Stopped due to class java.lang.InterruptedException
04:00:57.604 [pool-8-thread-10] WARN  MessageTrafficController: Stopped due to class java.lang.InterruptedException
04:00:57.603 [pool-8-thread-8] WARN  MessageTrafficController: Stopped due to class java.lang.InterruptedException
04:00:57.604 [pool-8-thread-9] WARN  MessageTrafficController: Stopped due to class java.lang.InterruptedException
04:00:57.606 [pool-8-thread-22] WARN  MessageTrafficController: Stopped due to class java.lang.InterruptedException
04:00:57.608 [pool-8-thread-25] WARN  MessageTrafficController: Stopped due to class java.lang.InterruptedException
04:00:57.606 [pool-8-thread-20] WARN  MessageTrafficController: Stopped due to class java.lang.InterruptedException
04:00:57.605 [pool-8-thread-15] WARN  MessageTrafficController: Stopped due to class java.lang.InterruptedException
04:00:57.606 [pool-8-thread-19] WARN  MessageTrafficController: Stopped due to class java.lang.InterruptedException
04:00:57.606 [pool-8-thread-18] WARN  MessageTrafficController: Stopped due to class java.lang.InterruptedException
04:00:57.604 [pool-8-thread-14] WARN  MessageTrafficController: Stopped due to class java.lang.InterruptedException
65598.920 ms

Result : 76749.529 Âą(99.9%) 804946.698 ms
  Statistics: (min, avg, max) = (39272.712, 76749.529, 125376.954), stdev = 44121.845
  Confidence interval (99.9%): [-728197.169, 881696.226]

If I kill forked JVM manually the whole process unblocks. However after finishing next benchmark it gets stuck again... Any ideas why does it happen? And why it does NOT happen when I fire off the same benchmark separately?

Also, is there some timeout option in JMH, so it kills forked process forcefully if normal shutdown takes too long?

like image 904
Kranach Avatar asked Feb 19 '14 08:02

Kranach


1 Answers

This is already answered on JMH dev mailing list: you need to debug your workload to disallow stray threads, hooks, etc. from blocking the forked VM from exiting.

like image 199
Aleksey Shipilev Avatar answered Sep 22 '22 03:09

Aleksey Shipilev