[
https://issues.apache.org/jira/browse/MNG-6474?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16611144#comment-16611144
]
Michael Osipov edited comment on MNG-6474 at 9/11/18 7:41 PM:
--------------------------------------------------------------
Please reformat the strace as it is outputted by Java. It is very hard to read.
A quick look says me that this is incomplete. There is a Resolver thread
waiting for something, likely an HTTP reponse. I miss what
{{0x000000006038e000}} and {{0x00000000814b9900}} are. Can you provide more
details? Attach to the VM with VisualVM and check for this ref? Can you also
please provide a debug log from Maven 3.5.4 where this hang happens?
was (Author: michael-o):
Please reformat the strace as it is outputted by Java. It is very hard to read.
A quick look says me that this is incomplete. There is a Resolver thread
waiting for something, likely an HTTP reponse. I miss what
{{0x000000006038e000}} and {{0x00000000814b9900}} are. Can you provide more
details? Attach to the VM with VisualVM and check for this ref?
> Maven intermittently hanging at end of multithreaded build
> ----------------------------------------------------------
>
> Key: MNG-6474
> URL: https://issues.apache.org/jira/browse/MNG-6474
> Project: Maven
> Issue Type: Bug
> Affects Versions: 3.5.2
> Reporter: Beirtí Ó'Nunáin
> Priority: Major
>
> I can't reproduce this with a small skeleton project. It has only started
> happening since we upgraded from 3.3 to 3.5.
>
> I have a multithreaded multi-module build which builds a number of large
> (300mb+) artifacts upon SVN commits. I'm running the following goals:
>
> mvn clean deploy -T 1C
>
> Reasonably often, perhaps 1 in 10 builds, the build hangs just before where
> I'd expect the build to have finished. I'm guessing that maven is attempting
> to install an artifact to the local repository (looking at the stack trace)
> while the build is about to complete as when I compare the build log from the
> hung build to a successful build, the following line is the "Reactor Summary"
> This issue happens both on my local machine and on our TeamCity server (Both
> multi-processor, multi-core 14 vs 32 cores)
> The Thread dump isn't indicating any kind of DeadLock. Our sysadmins have
> checked the box for any antivirus scanning which may be impacting the file
> copy indicated in the log but can't see anything going on at that time.
> Here's the thread dump from TeamCity when it times out:
>
> {quote}
> Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.121-b13 mixed mode):
> "resolver-5" #63 daemon prio=5 os_prio=0 tid=0x00000000596ff800 nid=0x1e98
> waiting on condition [0x000000006038e000] java.lang.Thread.State: WAITING
> (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for
> <0x00000000814b9900> (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" #62 daemon prio=5
> os_prio=0 tid=0x00000000596fe800 nid=0x134c waiting on condition
> [0x000000005f42e000] java.lang.Thread.State: WAITING (parking) at
> sun.misc.Unsafe.park(Native Method) - parking to wait for
> <0x00000000814b9900> (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" #61 daemon prio=5
> os_prio=0 tid=0x00000000596fe000 nid=0x17c0 waiting on condition
> [0x000000005fa4e000] java.lang.Thread.State: WAITING (parking) at
> sun.misc.Unsafe.park(Native Method) - parking to wait for
> <0x00000000814b9900> (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" #60 daemon prio=5
> os_prio=0 tid=0x00000000596fc800 nid=0x135c waiting on condition
> [0x000000005ff2f000] java.lang.Thread.State: WAITING (parking) at
> sun.misc.Unsafe.park(Native Method) - parking to wait for
> <0x00000000814b9900> (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" #59 daemon prio=5
> os_prio=0 tid=0x00000000596fb800 nid=0x1538 waiting on condition
> [0x000000005fd9f000] java.lang.Thread.State: WAITING (parking) at
> sun.misc.Unsafe.park(Native Method) - parking to wait for
> <0x00000000814b9900> (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 5" #22 prio=5
> os_prio=0 tid=0x000000005ca94800 nid=0x11b4 waiting on condition
> [0x000000005f54f000] java.lang.Thread.State: WAITING (parking) at
> sun.misc.Unsafe.park(Native Method) - parking to wait for
> <0x0000000082020030> (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 4" #21 prio=5
> os_prio=0 tid=0x000000005cb4f800 nid=0x1278 waiting on condition
> [0x000000005f26f000] java.lang.Thread.State: WAITING (parking) at
> sun.misc.Unsafe.park(Native Method) - parking to wait for
> <0x0000000082020030> (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 3" #20 prio=5
> os_prio=0 tid=0x000000005c83f800 nid=0xfc4 waiting on condition
> [0x000000005dddf000] java.lang.Thread.State: WAITING (parking) at
> sun.misc.Unsafe.park(Native Method) - parking to wait for
> <0x0000000082020030> (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" #19 prio=5
> os_prio=0 tid=0x000000005d059800 nid=0x1c08 waiting on condition
> [0x000000005dfdf000] java.lang.Thread.State: WAITING (parking) at
> sun.misc.Unsafe.park(Native Method) - parking to wait for
> <0x0000000082020030> (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 1" #18 prio=5
> os_prio=0 tid=0x000000005d458800 nid=0x1e7c runnable [0x00000000599ae000]
> java.lang.Thread.State: RUNNABLE at java.io.FileOutputStream.open0(Native
> Method) at java.io.FileOutputStream.open(FileOutputStream.java:270) at
> java.io.FileOutputStream.<init>(FileOutputStream.java:213) at
> java.io.FileOutputStream.<init>(FileOutputStream.java:162) at
> org.eclipse.aether.internal.impl.DefaultFileProcessor.copy(DefaultFileProcessor.java:166)
> at
> org.eclipse.aether.internal.impl.DefaultFileProcessor.copy(DefaultFileProcessor.java:150)
> at
> org.eclipse.aether.internal.impl.DefaultInstaller.install(DefaultInstaller.java:267)
> at
> org.eclipse.aether.internal.impl.DefaultInstaller.install(DefaultInstaller.java:195)
> at
> org.eclipse.aether.internal.impl.DefaultInstaller.install(DefaultInstaller.java:152)
> at
> org.eclipse.aether.internal.impl.DefaultRepositorySystem.install(DefaultRepositorySystem.java:377)
> at
> org.apache.maven.artifact.installer.DefaultArtifactInstaller.install(DefaultArtifactInstaller.java:107)
> at org.apache.maven.plugin.install.InstallMojo.execute(InstallMojo.java:115)
> 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 0" #11 prio=5
> os_prio=0 tid=0x0000000059f2f000 nid=0x1fac waiting on condition
> [0x000000005c27e000] java.lang.Thread.State: WAITING (parking) at
> sun.misc.Unsafe.park(Native Method) - parking to wait for
> <0x0000000082020030> (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" #9 daemon prio=9
> os_prio=0 tid=0x00000000575b9800 nid=0x1ca4 runnable [0x0000000000000000]
> java.lang.Thread.State: RUNNABLE "C1 CompilerThread2" #8 daemon prio=9
> os_prio=2 tid=0x000000005752b000 nid=0x1128 waiting on condition
> [0x0000000000000000] java.lang.Thread.State: RUNNABLE "C2 CompilerThread1" #7
> daemon prio=9 os_prio=2 tid=0x0000000057524800 nid=0x1918 waiting on
> condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "C2
> CompilerThread0" #6 daemon prio=9 os_prio=2 tid=0x00000000565dd000 nid=0x1c94
> waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE
> "Attach Listener" #5 daemon prio=5 os_prio=2 tid=0x00000000565dc000
> nid=0x199c waiting on condition [0x0000000000000000] java.lang.Thread.State:
> RUNNABLE "Signal Dispatcher" #4 daemon prio=9 os_prio=2
> tid=0x00000000565db000 nid=0x16bc runnable [0x0000000000000000]
> java.lang.Thread.State: RUNNABLE "Finalizer" #3 daemon prio=8 os_prio=1
> tid=0x0000000000f5d800 nid=0x1f34 in Object.wait() [0x000000005817f000]
> java.lang.Thread.State: WAITING (on object monitor) at
> java.lang.Object.wait(Native Method) - waiting on <0x000000008176afe0> (a
> java.lang.ref.ReferenceQueue$Lock) at
> java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143) - locked
> <0x000000008176afe0> (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=2 tid=0x0000000000f55000 nid=0xf40 in
> Object.wait() [0x000000005846f000] java.lang.Thread.State: WAITING (on object
> monitor) at java.lang.Object.wait(Native Method) - waiting on
> <0x0000000081aa4ce0> (a java.lang.ref.Reference$Lock) at
> java.lang.Object.wait(Object.java:502) at
> java.lang.ref.Reference.tryHandlePending(Reference.java:191) - locked
> <0x0000000081aa4ce0> (a java.lang.ref.Reference$Lock) at
> java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153) "main" #1
> prio=5 os_prio=0 tid=0x0000000000eb7800 nid=0x958 waiting on condition
> [0x000000000116e000] java.lang.Thread.State: WAITING (parking) at
> sun.misc.Unsafe.park(Native Method) - parking to wait for
> <0x0000000081d86ec8> (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:955) at
> org.apache.maven.cli.MavenCli.doMain(MavenCli.java:290) at
> org.apache.maven.cli.MavenCli.main(MavenCli.java:194) 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=2 tid=0x00000000574e1800 nid=0x18e4 runnable "GC task
> thread#0 (ParallelGC)" os_prio=0 tid=0x0000000000ece000 nid=0x8e8 runnable
> "GC task thread#1 (ParallelGC)" os_prio=0 tid=0x0000000000ecf800 nid=0x155c
> runnable "GC task thread#2 (ParallelGC)" os_prio=0 tid=0x0000000000ed1000
> nid=0x1e90 runnable "GC task thread#3 (ParallelGC)" os_prio=0
> tid=0x0000000000ed4800 nid=0x1afc runnable "GC task thread#4 (ParallelGC)"
> os_prio=0 tid=0x0000000000ed5800 nid=0x44c runnable "GC task thread#5
> (ParallelGC)" os_prio=0 tid=0x0000000000ed8000 nid=0x1e14 runnable "VM
> Periodic Task Thread" os_prio=2 tid=0x00000000575c1800 nid=0x1d68 waiting on
> condition JNI global references: 231_
> {quote}
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
