maven hangs for ~20 mins during the project build (used to work fine)

Question

Building this maven project used to work just fine for quite a while (6 month), but today while executing mvn clean install the build start hanging every single time (tried with different versions of mvn including the latest 3.5.0 and against both openJDK & Oracle JDK - result is the same)

kill -3 PID output

"resolver-5" #491 daemon prio=5 os_prio=0 tid=0x00007f6da8bd3800 nid=0x16b3 waiting on condition [0x00007f6d68df3000]
   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000006c658c4a8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
    at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)

"resolver-4" #490 daemon prio=5 os_prio=0 tid=0x00007f6da8bd2800 nid=0x16b2 waiting on condition [0x00007f6d69945000]
   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000006c658c4a8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
    at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)

"resolver-3" #489 daemon prio=5 os_prio=0 tid=0x00007f6da8bd9000 nid=0x16b1 waiting on condition [0x00007f6de97bc000]
   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000006c658c4a8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
    at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)

"resolver-2" #488 daemon prio=5 os_prio=0 tid=0x00007f6da8bd8800 nid=0x16b0 waiting on condition [0x00007f6de940e000]
   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000006c658c4a8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
    at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)

"resolver-1" #487 daemon prio=5 os_prio=0 tid=0x00007f6da8bd7800 nid=0x16af waiting on condition [0x00007f6de930d000]
   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000006c658c4a8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
    at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)

"Thread-14" #34 daemon prio=5 os_prio=0 tid=0x00007f6d9c0e7800 nid=0x73cd in Object.wait() [0x00007f6de99f7000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    at org.apache.tools.ant.taskdefs.StreamPumper.waitForInput(StreamPumper.java:245)
    - locked <0x00000006cbe26170> (a org.apache.tools.ant.taskdefs.StreamPumper)
    at org.apache.tools.ant.taskdefs.StreamPumper.run(StreamPumper.java:125)
    at java.lang.Thread.run(Thread.java:745)

"Thread-13" #33 daemon prio=5 os_prio=0 tid=0x00007f6d9c10a800 nid=0x73cb in Object.wait() [0x00007f6de9af8000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    at org.apache.tools.ant.taskdefs.StreamPumper.waitForInput(StreamPumper.java:245)
    - locked <0x00000006cbe4a7d8> (a org.apache.tools.ant.taskdefs.StreamPumper)
    at org.apache.tools.ant.taskdefs.StreamPumper.run(StreamPumper.java:125)
    at java.lang.Thread.run(Thread.java:745)

"BuilderThread 3" #19 prio=5 os_prio=0 tid=0x00007f6e00927800 nid=0x7373 waiting on condition [0x00007f6dea27d000]
   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000006c6284f48> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
    at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)

"BuilderThread 2" #18 prio=5 os_prio=0 tid=0x00007f6e00926800 nid=0x7372 in Object.wait() [0x00007f6dea49b000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000006cb6c4780> (a java.lang.UNIXProcess)
    at java.lang.Object.wait(Object.java:502)
    at java.lang.UNIXProcess.waitFor(UNIXProcess.java:395)
    - locked <0x00000006cb6c4780> (a java.lang.UNIXProcess)
    at org.apache.tools.ant.taskdefs.Execute.waitFor(Execute.java:534)
    at org.apache.tools.ant.taskdefs.Execute.execute(Execute.java:463)
    at org.apache.tools.ant.taskdefs.ExecTask.runExecute(ExecTask.java:628)
    at org.apache.tools.ant.taskdefs.ExecTask.runExec(ExecTask.java:669)
    at org.apache.tools.ant.taskdefs.ExecTask.execute(ExecTask.java:495)
    at org.apache.tools.ant.UnknownElement.execute(UnknownElement.java:292)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.apache.tools.ant.dispatch.DispatchUtils.execute(DispatchUtils.java:106)
    at org.apache.tools.ant.Task.perform(Task.java:348)
    at org.apache.tools.ant.Target.execute(Target.java:435)
    at org.apache.tools.ant.Target.performTasks(Target.java:456)
    at org.apache.tools.ant.Project.executeSortedTargets(Project.java:1393)
    at org.apache.tools.ant.Project.executeTarget(Project.java:1364)
    at org.apache.maven.plugin.antrun.AntRunMojo.execute(AntRunMojo.java:313)
    at org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo(DefaultBuildPluginManager.java:134)
    at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:208)
    at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:154)
    at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:146)
    at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject(LifecycleModuleBuilder.java:117)
    at org.apache.maven.lifecycle.internal.builder.multithreaded.MultiThreadedBuilder$1.call(MultiThreadedBuilder.java:200)
    at org.apache.maven.lifecycle.internal.builder.multithreaded.MultiThreadedBuilder$1.call(MultiThreadedBuilder.java:196)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)

"BuilderThread 1" #17 prio=5 os_prio=0 tid=0x00007f6e00926000 nid=0x7371 waiting on condition [0x00007f6dea39b000]
   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000006c6284f48> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
    at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)

"process reaper" #12 daemon prio=10 os_prio=0 tid=0x00007f6db02a8800 nid=0x7369 runnable [0x00007f6dea4d5000]
   java.lang.Thread.State: RUNNABLE
    at java.lang.UNIXProcess.waitForProcessExit(Native Method)
    at java.lang.UNIXProcess.lambda$initStreams$3(UNIXProcess.java:289)
    at java.lang.UNIXProcess$$Lambda$7/747506922.run(Unknown Source)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)

"BuilderThread 0" #10 prio=5 os_prio=0 tid=0x00007f6e008d4800 nid=0x7367 waiting on condition [0x00007f6dea803000]
   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000006c6284f48> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
    at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)

"Service Thread" #8 daemon prio=9 os_prio=0 tid=0x00007f6e000c2800 nid=0x7355 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C1 CompilerThread2" #7 daemon prio=9 os_prio=0 tid=0x00007f6e000b3000 nid=0x7354 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread1" #6 daemon prio=9 os_prio=0 tid=0x00007f6e000b1800 nid=0x7353 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" #5 daemon prio=9 os_prio=0 tid=0x00007f6e000ae800 nid=0x7352 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" #4 daemon prio=9 os_prio=0 tid=0x00007f6e000ac800 nid=0x7351 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" #3 daemon prio=8 os_prio=0 tid=0x00007f6e00084000 nid=0x7350 in Object.wait() [0x00007f6df05f4000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143)
    - locked <0x00000006c231e5c8> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:164)
    at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)

"Reference Handler" #2 daemon prio=10 os_prio=0 tid=0x00007f6e0007f800 nid=0x734f in Object.wait() [0x00007f6df06f5000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    at java.lang.Object.wait(Object.java:502)
    at java.lang.ref.Reference.tryHandlePending(Reference.java:191)
    - locked <0x00000006c2dd4ae0> (a java.lang.ref.Reference$Lock)
    at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153)

"main" #1 prio=5 os_prio=0 tid=0x00007f6e0000a800 nid=0x7349 waiting on condition [0x00007f6e0a5e2000]
   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000006c6280d98> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
    at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
    at java.util.concurrent.ExecutorCompletionService.take(ExecutorCompletionService.java:193)
    at org.apache.maven.lifecycle.internal.builder.multithreaded.MultiThreadedBuilder.multiThreadedProjectTaskSegmentBuild(MultiThreadedBuilder.java:140)
    at org.apache.maven.lifecycle.internal.builder.multithreaded.MultiThreadedBuilder.build(MultiThreadedBuilder.java:101)
    at org.apache.maven.lifecycle.internal.LifecycleStarter.execute(LifecycleStarter.java:128)
    at org.apache.maven.DefaultMaven.doExecute(DefaultMaven.java:309)
    at org.apache.maven.DefaultMaven.doExecute(DefaultMaven.java:194)
    at org.apache.maven.DefaultMaven.execute(DefaultMaven.java:107)
    at org.apache.maven.cli.MavenCli.execute(MavenCli.java:993)
    at org.apache.maven.cli.MavenCli.doMain(MavenCli.java:345)
    at org.apache.maven.cli.MavenCli.main(MavenCli.java:191)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.codehaus.plexus.classworlds.launcher.Launcher.launchEnhanced(Launcher.java:289)
    at org.codehaus.plexus.classworlds.launcher.Launcher.launch(Launcher.java:229)
    at org.codehaus.plexus.classworlds.launcher.Launcher.mainWithExitCode(Launcher.java:415)
    at org.codehaus.plexus.classworlds.launcher.Launcher.main(Launcher.java:356)

"VM Thread" os_prio=0 tid=0x00007f6e00077800 nid=0x734e runnable 

"GC task thread#0 (ParallelGC)" os_prio=0 tid=0x00007f6e0001f800 nid=0x734a runnable 

"GC task thread#1 (ParallelGC)" os_prio=0 tid=0x00007f6e00021000 nid=0x734b runnable 

"GC task thread#2 (ParallelGC)" os_prio=0 tid=0x00007f6e00023000 nid=0x734c runnable 

"GC task thread#3 (ParallelGC)" os_prio=0 tid=0x00007f6e00024800 nid=0x734d runnable 

"VM Periodic Task Thread" os_prio=0 tid=0x00007f6e000c5000 nid=0x7356 waiting on condition 

JNI global references: 280

Heap
 PSYoungGen      total 1161728K, used 704160K [0x000000076ab00000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 979968K, 53% used [0x000000076ab00000,0x000000078a929980,0x00000007a6800000)
  from space 181760K, 99% used [0x00000007b4e80000,0x00000007bfffe8f0,0x00000007c0000000)
  to   space 208896K, 0% used [0x00000007a6800000,0x00000007a6800000,0x00000007b3400000)
 ParOldGen       total 1211904K, used 320544K [0x00000006c0000000, 0x0000000709f80000, 0x000000076ab00000)
  object space 1211904K, 26% used [0x00000006c0000000,0x00000006d3908220,0x0000000709f80000)
 Metaspace       used 92817K, capacity 96210K, committed 96512K, reserved 1134592K
  class space    used 10910K, capacity 11975K, committed 12032K, reserved 1048576K

Is it some weird deadlock issue ? Thanks in advance!

UPDATE Actually the build does not hang forever (only 20 - 25 mins). Still it is not clear what is the reason

Answer 1

Maven 3.5.x has some pretty terrible bugs, namely:

• Metadata download hangs for repository with cache lifetime
• Maven dependency resolution locks up

What is specifically happening is that if you are building a project with submodules or multiple projects, Maven 3.5.x sporadically locks up when downloading duplicate dependencies. Example: Let spring-expression-4.3.5.RELEASE be a dependency of two or more project POMs. It's downloaded into the Maven Repo by project 1 at ".m2\repository\org\springframework\spring-expression\4.3.5.RELEASE\spring-expression-4.3.5.RELEASE.jar" (of course, with the POM and checksum files). When project 2 goes to check/download the same dependency in the same location, it locks up for 20 minutes and then reports "0 B" was downloaded in the logs.

Until the Maven team addresses this issue in the 3.5.x releases, we pulled back to Maven 3.3.9 and the problem vanished. (NOTE: This was regularly reproducible at the same point in dependency resolution in our project.)