Mi created EXEC-103:
-----------------------
Summary: Hanging during closing the streams; FileInputStream
blocks read
Key: EXEC-103
URL: https://issues.apache.org/jira/browse/EXEC-103
Project: Commons Exec
Issue Type: Bug
Affects Versions: 1.3
Environment: Ubuntu Wily, using Oracle JRE 8, but also affects OpenJDK
1.7 and OpenJDK 1.8
Reporter: Mi
DefaultExecutor is used in
https://github.com/eclipse/tycho/blob/master/sisu-equinox/sisu-equinox-launching/src/main/java/org/eclipse/sisu/equinox/launching/internal/DefaultEquinoxLauncher.java
so just with the default PumpStreamHandler.
It is used to launch an eclipse instance for testing. Although the launched
process has exited (have verified that multiple times), the DefaultExecutor
does not come back, since it cannot use its streams.
Apparently the JVM knows the process has exited, nevertheless the "Exec Stream
Pumper" does still want to read the input stream and is holding a monitor; it
is waiting until the eternety in the FileInputStream, reading from the process
(although the process has ended...).
The "process reaper" thread wants to notify everyone the process has exited,
but it can't, because the Exec Stream Pumper is owning the monitor. The problem
occurs every time (tested like 10 times).
Interestingly enough, I can launch other applications using the same Commons
Exec library without any problem.
Here is a thread dump:
2016-04-15 13:19:45
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.45-b02 mixed mode):
"JMX server connection timeout 153" #153 daemon prio=9 os_prio=0
tid=0x00007f225400f000 nid=0x6910 in Object.wait() [0x00007f22acb63000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at
com.sun.jmx.remote.internal.ServerCommunicatorAdmin$Timeout.run(ServerCommunicatorAdmin.java:168)
- locked <0x000000078c676810> (a [I)
at java.lang.Thread.run(Thread.java:745)
Locked ownable synchronizers:
- None
"RMI Scheduler(0)" #152 daemon prio=9 os_prio=0 tid=0x00007f225400c000
nid=0x690e waiting on condition [0x00007f22ace66000]
java.lang.Thread.State: TIMED_WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x000000078bfd7468> (a
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at
java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
at
java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
at
java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
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)
Locked ownable synchronizers:
- None
"RMI TCP Connection(1)-127.0.0.1" #151 daemon prio=9 os_prio=0
tid=0x00007f2258003800 nid=0x690d runnable [0x00007f22adece000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
at java.net.SocketInputStream.read(SocketInputStream.java:170)
at java.net.SocketInputStream.read(SocketInputStream.java:141)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
at java.io.BufferedInputStream.read(BufferedInputStream.java:265)
- locked <0x000000078c64b1d8> (a java.io.BufferedInputStream)
at java.io.FilterInputStream.read(FilterInputStream.java:83)
at
sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:550)
at
sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:826)
at
sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.lambda$run$241(TCPTransport.java:683)
at
sun.rmi.transport.tcp.TCPTransport$ConnectionHandler$$Lambda$9/2030397396.run(Unknown
Source)
at java.security.AccessController.doPrivileged(Native Method)
at
sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:682)
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)
Locked ownable synchronizers:
- <0x000000078c29d308> (a
java.util.concurrent.ThreadPoolExecutor$Worker)
"RMI TCP Accept-0" #150 daemon prio=9 os_prio=0 tid=0x00007f22600af800
nid=0x690a runnable [0x00007f22aca62000]
java.lang.Thread.State: RUNNABLE
at java.net.PlainSocketImpl.socketAccept(Native Method)
at
java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:404)
at java.net.ServerSocket.implAccept(ServerSocket.java:545)
at java.net.ServerSocket.accept(ServerSocket.java:513)
at
sun.management.jmxremote.LocalRMIServerSocketFactory$1.accept(LocalRMIServerSocketFactory.java:52)
at
sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(TCPTransport.java:400)
at
sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(TCPTransport.java:372)
at java.lang.Thread.run(Thread.java:745)
Locked ownable synchronizers:
- None
"Attach Listener" #149 daemon prio=9 os_prio=0 tid=0x00007f22c0001000
nid=0x6907 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
Locked ownable synchronizers:
- None
"Exec Stream Pumper" #146 daemon prio=5 os_prio=0 tid=0x00007f23122b5000
nid=0x657c runnable [0x00007f22ad068000]
java.lang.Thread.State: RUNNABLE
at java.io.FileInputStream.readBytes(Native Method)
at java.io.FileInputStream.read(FileInputStream.java:255)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
at java.io.BufferedInputStream.read1(BufferedInputStream.java:286)
at java.io.BufferedInputStream.read(BufferedInputStream.java:345)
- locked <0x0000000789cbd9c0> (a
java.lang.UNIXProcess$ProcessPipeInputStream)
at java.io.FilterInputStream.read(FilterInputStream.java:107)
at org.apache.commons.exec.StreamPumper.run(StreamPumper.java:105)
at java.lang.Thread.run(Thread.java:745)
Locked ownable synchronizers:
- None
"process reaper" #76 daemon prio=10 os_prio=0 tid=0x00007f23123fb000 nid=0x64dc
waiting for monitor entry [0x00007f2253844000]
java.lang.Thread.State: BLOCKED (on object monitor)
at
java.lang.UNIXProcess$ProcessPipeInputStream.processExited(UNIXProcess.java:525)
- waiting to lock <0x0000000789cbd9c0> (a
java.lang.UNIXProcess$ProcessPipeInputStream)
at java.lang.UNIXProcess.lambda$initStreams$266(UNIXProcess.java:299)
at java.lang.UNIXProcess$$Lambda$8/1103297875.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)
Locked ownable synchronizers:
- <0x00000007b8b21ed8> (a
java.util.concurrent.ThreadPoolExecutor$Worker)
"Provisioning Event Dispatcher" #44 daemon prio=5 os_prio=0
tid=0x00007f23122c4000 nid=0x64ae in Object.wait() [0x00007f22acf67000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:502)
at
org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.getNextEvent(EventManager.java:400)
- locked <0x00000006d099aa90> (a
org.eclipse.osgi.framework.eventmgr.EventManager$EventThread)
at
org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:336)
Locked ownable synchronizers:
- None
"Worker-3" #30 prio=5 os_prio=0 tid=0x00007f227400e000 nid=0x63bf in
Object.wait() [0x00007f22ae5d0000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at org.eclipse.core.internal.jobs.WorkerPool.sleep(WorkerPool.java:188)
- locked <0x00000006c66c9750> (a
org.eclipse.core.internal.jobs.WorkerPool)
at
org.eclipse.core.internal.jobs.WorkerPool.startJob(WorkerPool.java:220)
at org.eclipse.core.internal.jobs.Worker.run(Worker.java:52)
Locked ownable synchronizers:
- None
"Provisioning Event Dispatcher" #28 daemon prio=5 os_prio=0
tid=0x00007f2311697800 nid=0x63bd in Object.wait() [0x00007f22ae7d2000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:502)
at
org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.getNextEvent(EventManager.java:400)
- locked <0x00000006c836bc90> (a
org.eclipse.osgi.framework.eventmgr.EventManager$EventThread)
at
org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:336)
Locked ownable synchronizers:
- None
"Worker-0" #26 prio=5 os_prio=0 tid=0x00007f23115c0000 nid=0x63bb in
Object.wait() [0x00007f22aebd4000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at org.eclipse.core.internal.jobs.WorkerPool.sleep(WorkerPool.java:188)
- locked <0x00000006c66c9750> (a
org.eclipse.core.internal.jobs.WorkerPool)
at
org.eclipse.core.internal.jobs.WorkerPool.startJob(WorkerPool.java:220)
at org.eclipse.core.internal.jobs.Worker.run(Worker.java:52)
Locked ownable synchronizers:
- None
"Worker-JM" #18 prio=5 os_prio=0 tid=0x00007f2311367000 nid=0x637e in
Object.wait() [0x00007f22aeed5000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at
org.eclipse.core.internal.jobs.InternalWorker.run(InternalWorker.java:59)
- locked <0x00000006c66c9a60> (a java.util.ArrayList)
Locked ownable synchronizers:
- None
"[ThreadPool Manager] - Idle Thread" #17 prio=5 os_prio=0
tid=0x00007f2311356800 nid=0x637d in Object.wait() [0x00007f22af1d6000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:502)
at
org.eclipse.equinox.internal.util.impl.tpt.threadpool.Executor.run(Executor.java:106)
- locked <0x00000006c66dc090> (a
org.eclipse.equinox.internal.util.impl.tpt.threadpool.Executor)
Locked ownable synchronizers:
- None
"[Timer] - Main Queue Handler" #16 prio=5 os_prio=0 tid=0x00007f2310fee800
nid=0x637c in Object.wait() [0x00007f22af4d7000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at
org.eclipse.equinox.internal.util.impl.tpt.timer.TimerImpl.run(TimerImpl.java:141)
- locked <0x00000006c6a0e050> (a java.lang.Object)
at java.lang.Thread.run(Thread.java:745)
Locked ownable synchronizers:
- None
"Refresh Thread: Equinox Container: 40472b22-fa02-0016-1e02-dec04b77a704" #15
daemon prio=5 os_prio=0 tid=0x00007f2310424000 nid=0x637b in Object.wait()
[0x00007f22af5d8000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:502)
at
org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.getNextEvent(EventManager.java:400)
- locked <0x00000006c667a530> (a
org.eclipse.osgi.framework.eventmgr.EventManager$EventThread)
at
org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:336)
Locked ownable synchronizers:
- None
"Start Level: Equinox Container: 40472b22-fa02-0016-1e02-dec04b77a704" #14
daemon prio=5 os_prio=0 tid=0x00007f231054b000 nid=0x637a in Object.wait()
[0x00007f22af6d9000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:502)
at
org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.getNextEvent(EventManager.java:400)
- locked <0x00000006c667b5f8> (a
org.eclipse.osgi.framework.eventmgr.EventManager$EventThread)
at
org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:336)
Locked ownable synchronizers:
- None
"Framework Event Dispatcher: Equinox Container:
40472b22-fa02-0016-1e02-dec04b77a704" #13 daemon prio=5 os_prio=0
tid=0x00007f231054a000 nid=0x6379 in Object.wait() [0x00007f22af7da000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:502)
at
org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.getNextEvent(EventManager.java:400)
- locked <0x00000006c6b4ebc0> (a
org.eclipse.osgi.framework.eventmgr.EventManager$EventThread)
at
org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:336)
Locked ownable synchronizers:
- None
"Active Thread: Equinox Container: 40472b22-fa02-0016-1e02-dec04b77a704" #11
prio=5 os_prio=0 tid=0x00007f23109e0800 nid=0x6378 waiting on condition
[0x00007f22d41e8000]
java.lang.Thread.State: TIMED_WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000006c6b75360> (a
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at
java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
at
java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
at
java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
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)
Locked ownable synchronizers:
- None
"Service Thread" #9 daemon prio=9 os_prio=0 tid=0x00007f23100cd800 nid=0x6374
runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
Locked ownable synchronizers:
- None
"C1 CompilerThread3" #8 daemon prio=9 os_prio=0 tid=0x00007f23100c8800
nid=0x6373 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
Locked ownable synchronizers:
- None
"C2 CompilerThread2" #7 daemon prio=9 os_prio=0 tid=0x00007f23100c6800
nid=0x6372 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
Locked ownable synchronizers:
- None
"C2 CompilerThread1" #6 daemon prio=9 os_prio=0 tid=0x00007f23100c4800
nid=0x6371 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
Locked ownable synchronizers:
- None
"C2 CompilerThread0" #5 daemon prio=9 os_prio=0 tid=0x00007f23100c1800
nid=0x6370 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
Locked ownable synchronizers:
- None
"Signal Dispatcher" #4 daemon prio=9 os_prio=0 tid=0x00007f23100c0000
nid=0x636f runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
Locked ownable synchronizers:
- None
"Finalizer" #3 daemon prio=8 os_prio=0 tid=0x00007f2310087800 nid=0x636e in
Object.wait() [0x00007f22d6a63000]
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 <0x00000006c5c0d940> (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)
Locked ownable synchronizers:
- None
"Reference Handler" #2 daemon prio=10 os_prio=0 tid=0x00007f2310085800
nid=0x636d in Object.wait() [0x00007f22d6b64000]
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$ReferenceHandler.run(Reference.java:157)
- locked <0x00000006c5c082b8> (a java.lang.ref.Reference$Lock)
Locked ownable synchronizers:
- None
"main" #1 prio=5 os_prio=0 tid=0x00007f231000a000 nid=0x6363 in Object.wait()
[0x00007f231905c000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at java.lang.Thread.join(Thread.java:1245)
- locked <0x0000000789cc1de0> (a java.lang.Thread)
at java.lang.Thread.join(Thread.java:1319)
at
org.apache.commons.exec.PumpStreamHandler.stopThread(PumpStreamHandler.java:286)
at
org.apache.commons.exec.PumpStreamHandler.stop(PumpStreamHandler.java:178)
at
org.apache.commons.exec.DefaultExecutor.executeInternal(DefaultExecutor.java:379)
at
org.apache.commons.exec.DefaultExecutor.execute(DefaultExecutor.java:164)
at
org.eclipse.sisu.equinox.launching.internal.DefaultEquinoxLauncher.execute(DefaultEquinoxLauncher.java:68)
at org.eclipse.tycho.surefire.TestMojo.runTest(TestMojo.java:942)
at org.eclipse.tycho.surefire.TestMojo.execute(TestMojo.java:647)
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:153)
at
org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:145)
at
org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject(LifecycleModuleBuilder.java:116)
at
org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject(LifecycleModuleBuilder.java:80)
at
org.apache.maven.lifecycle.internal.builder.singlethreaded.SingleThreadedBuilder.build(SingleThreadedBuilder.java:51)
at
org.apache.maven.lifecycle.internal.LifecycleStarter.execute(LifecycleStarter.java:128)
at org.apache.maven.DefaultMaven.doExecute(DefaultMaven.java:307)
at org.apache.maven.DefaultMaven.doExecute(DefaultMaven.java:193)
at org.apache.maven.DefaultMaven.execute(DefaultMaven.java:106)
at org.apache.maven.cli.MavenCli.execute(MavenCli.java:862)
at org.apache.maven.cli.MavenCli.doMain(MavenCli.java:286)
at org.apache.maven.cli.MavenCli.main(MavenCli.java:197)
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:497)
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)
Locked ownable synchronizers:
- None
"VM Thread" os_prio=0 tid=0x00007f2310080800 nid=0x636c runnable
"GC task thread#0 (ParallelGC)" os_prio=0 tid=0x00007f231001f000 nid=0x6364
runnable
"GC task thread#1 (ParallelGC)" os_prio=0 tid=0x00007f2310021000 nid=0x6365
runnable
"GC task thread#2 (ParallelGC)" os_prio=0 tid=0x00007f2310022800 nid=0x6366
runnable
"GC task thread#3 (ParallelGC)" os_prio=0 tid=0x00007f2310024800 nid=0x6367
runnable
"GC task thread#4 (ParallelGC)" os_prio=0 tid=0x00007f2310026800 nid=0x6368
runnable
"GC task thread#5 (ParallelGC)" os_prio=0 tid=0x00007f2310028000 nid=0x6369
runnable
"GC task thread#6 (ParallelGC)" os_prio=0 tid=0x00007f231002a000 nid=0x636a
runnable
"GC task thread#7 (ParallelGC)" os_prio=0 tid=0x00007f231002c000 nid=0x636b
runnable
"VM Periodic Task Thread" os_prio=0 tid=0x00007f23100d0800 nid=0x6375 waiting
on condition
JNI global references: 424
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
