commons-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Mi (JIRA)" <j...@apache.org>
Subject [jira] [Created] (EXEC-103) Hanging during closing the streams; FileInputStream blocks read
Date Mon, 18 Apr 2016 16:01:25 GMT
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)

Mime
View raw message