Bhakti and I started noticing that sometimes a build just hangs in the middle of archiving artifact.
This is the thread dump from the Maven process when it happens. The pool-1-thread-1
thread is the main
Maven thread and you can see it's waiting on remote callback invocation.
Thread Dump pool-1-thread-1 java.lang.Object.wait(Native Method) java.lang.Object.wait(Object.java:474) hudson.remoting.Request.call(Request.java:88) hudson.remoting.Channel.call(Channel.java:392) hudson.remoting.RemoteInvocationHandler.invoke(RemoteInvocationHandler.java:126) hudson.maven.$Proxy1.end(Unknown Source) hudson.maven.MavenBuildProxy2$Filter.end(MavenBuildProxy2.java:44) hudson.maven.MavenModuleSetBuild$Builder.postModule(MavenModuleSetBuild.java:564) hudson.maven.MavenBuilder$Adapter.fireLeaveModule(MavenBuilder.java:261) hudson.maven.MavenBuilder$Adapter.endModule(MavenBuilder.java:232) org.apache.maven.lifecycle.LifecycleExecutorInterceptor$EventMonitorImpl.endEvent(LifecycleExecutorInterceptor.java:69) org.apache.maven.monitor.event.DefaultEventDispatcher.dispatchEnd(DefaultEventDispatcher.java:54) org.apache.maven.lifecycle.DefaultLifecycleExecutor.executeTaskSegments(DefaultLifecycleExecutor.java:284) org.apache.maven.lifecycle.DefaultLifecycleExecutor.execute(DefaultLifecycleExecutor.java:143) org.apache.maven.lifecycle.LifecycleExecutorInterceptor.execute(LifecycleExecutorInterceptor.java:42) org.apache.maven.DefaultMaven.doExecute(DefaultMaven.java:334) org.apache.maven.DefaultMaven.execute(DefaultMaven.java:125) org.apache.maven.cli.MavenCli.main(MavenCli.java:280) sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) java.lang.reflect.Method.invoke(Method.java:585) org.codehaus.classworlds.Launcher.launchEnhanced(Launcher.java:315) org.codehaus.classworlds.Launcher.launch(Launcher.java:255) hudson.maven.agent.Main.launch(Main.java:133) hudson.maven.MavenBuilder.call(MavenBuilder.java:129) hudson.maven.MavenModuleSetBuild$Builder.call(MavenModuleSetBuild.java:527) hudson.maven.MavenModuleSetBuild$Builder.call(MavenModuleSetBuild.java:473) hudson.remoting.UserRequest.perform(UserRequest.java:69) hudson.remoting.UserRequest.perform(UserRequest.java:23) hudson.remoting.Request$2.run(Request.java:200) java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:417) java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:269) java.util.concurrent.FutureTask.run(FutureTask.java:123) java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675) java.lang.Thread.run(Thread.java:595)
In the master, this is handled by the following thread (see the attachment for the complete dump):
"pool-3-thread-239" Id=7085 RUNNABLE (in native) at java.lang.UNIXProcess.forkAndExec(Native Method) at java.lang.UNIXProcess.(UNIXProcess.java:53) at java.lang.ProcessImpl.start(ProcessImpl.java:65) at java.lang.ProcessBuilder.start(ProcessBuilder.java:452) at hudson.Proc$LocalProc.(Proc.java:104) at hudson.Proc$LocalProc.(Proc.java:82) at hudson.Proc$LocalProc.(Proc.java:74) at hudson.Util.createSymlink(Util.java:722) at hudson.maven.MavenModuleSetBuild.notifyModuleBuild(MavenModuleSetBuild.java:262) at hudson.maven.MavenBuild$ProxyImpl2.end(MavenBuild.java:348) at sun.reflect.GeneratedMethodAccessor141.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at hudson.remoting.RemoteInvocationHandler$RPCRequest.perform(RemoteInvocationHandler.java:240) at hudson.remoting.RemoteInvocationHandler$RPCRequest.call(RemoteInvocationHandler.java:223) at hudson.remoting.RemoteInvocationHandler$RPCRequest.call(RemoteInvocationHandler.java:183) at hudson.remoting.UserRequest.perform(UserRequest.java:69) at hudson.remoting.UserRequest.perform(UserRequest.java:23) at hudson.remoting.Request$2.run(Request.java:206) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) at java.util.concurrent.FutureTask.run(FutureTask.java:138) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:885) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907) at java.lang.Thread.run(Thread.java:619) Number of locked synchronizers = 1 - java.util.concurrent.locks.ReentrantLock$NonfairSync@1d02eee
So it looks like another symptom of Forked process failing to exec.
Attachments:
hang-threadump.txt (text/plain)