Deadlock in iPojo when stopping Felix
-------------------------------------
Key: FELIX-951
URL: https://issues.apache.org/jira/browse/FELIX-951
Project: Felix
Issue Type: Bug
Components: iPOJO
Affects Versions: iPOJO-1.2.0
Environment: JDK 1.6 / Windows XP
Reporter: David GAY
Priority: Critical
I suspect a deadlock when iPojo register services while Felix framework
stopping the bundles (shutdown)
This is the thread dump of the JVM :
Full thread dump Java HotSpot(TM) Client VM (11.0-b16 mixed mode, sharing):
"FelixShutdown" daemon prio=6 tid=0x030ba400 nid=0x1168 in Object.wait()
[0x03b1f000..0x03b1fc14]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x230fb080> (a java.lang.Integer)
at java.lang.Object.wait(Object.java:485)
at
org.apache.felix.framework.StartLevelImpl.setStartLevelAndWait(StartLevelImpl.java:136)
- locked <0x230fb080> (a java.lang.Integer)
at
org.apache.felix.framework.Felix$SystemBundleActivator.run(Felix.java:3876)
at java.lang.Thread.run(Thread.java:619)
"RMI TCP Connection(idle)" daemon prio=6 tid=0x03542800 nid=0x1478 waiting on
condition [0x03a7f000..0x03a7fd94]
java.lang.Thread.State: TIMED_WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x22eaeec8> (a
java.util.concurrent.SynchronousQueue$TransferStack)
at
java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:198)
at
java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:424)
at
java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:323)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:874)
at
java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:945)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
at java.lang.Thread.run(Thread.java:619)
"RMI TCP Connection(idle)" daemon prio=6 tid=0x03548800 nid=0x14e0 waiting on
condition [0x03a2f000..0x03a2fa14]
java.lang.Thread.State: TIMED_WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x22eaeec8> (a
java.util.concurrent.SynchronousQueue$TransferStack)
at
java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:198)
at
java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:424)
at
java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:323)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:874)
at
java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:945)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
at java.lang.Thread.run(Thread.java:619)
"Prototyper" daemon prio=6 tid=0x030bb400 nid=0x146c in Object.wait()
[0x039df000..0x039dfa94]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x230ec668> (a
org.logicalcobwebs.proxool.PrototyperThread)
at java.lang.Object.wait(Object.java:485)
at
org.logicalcobwebs.proxool.PrototyperThread.doWait(PrototyperThread.java:69)
- locked <0x230ec668> (a org.logicalcobwebs.proxool.PrototyperThread)
at
org.logicalcobwebs.proxool.PrototyperThread.run(PrototyperThread.java:58)
"HouseKeeper" daemon prio=6 tid=0x030c4400 nid=0x14c4 waiting on condition
[0x0398f000..0x0398fb14]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at
org.logicalcobwebs.proxool.HouseKeeperThread.run(HouseKeeperThread.java:46)
"SelectorThread-9998" daemon prio=6 tid=0x03064400 nid=0x14d8 runnable
[0x0353f000..0x0353fb94]
java.lang.Thread.State: RUNNABLE
at sun.nio.ch.WindowsSelectorImpl$SubSelector.poll0(Native Method)
at
sun.nio.ch.WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:274)
at
sun.nio.ch.WindowsSelectorImpl$SubSelector.access$400(WindowsSelectorImpl.java:256)
at sun.nio.ch.WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:137)
at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:69)
- locked <0x23095600> (a sun.nio.ch.Util$1)
- locked <0x23095610> (a java.util.Collections$UnmodifiableSet)
- locked <0x23095588> (a sun.nio.ch.WindowsSelectorImpl)
at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:80)
at
com.sun.grizzly.TCPSelectorHandler.select(TCPSelectorHandler.java:483)
at com.sun.grizzly.Controller.doSelect(Controller.java:372)
at
com.sun.grizzly.SelectorHandlerRunner.run(SelectorHandlerRunner.java:82)
at
com.sun.grizzly.Controller.startSelectorHandlerRunner(Controller.java:1169)
at com.sun.grizzly.Controller.start(Controller.java:976)
at
com.sun.grizzly.http.SelectorThread.startListener(SelectorThread.java:1148)
- locked <0x22fa95f0> (a java.lang.Object)
at com.sun.grizzly.http.SelectorThread.run(SelectorThread.java:1000)
"JMX server connection timeout 20" daemon prio=6 tid=0x02fed800 nid=0x1300 in
Object.wait() [0x034ef000..0x034efc14]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x22f56378> (a [I)
at
com.sun.jmx.remote.internal.ServerCommunicatorAdmin$Timeout.run(ServerCommunicatorAdmin.java:150)
- locked <0x22f56378> (a [I)
at java.lang.Thread.run(Thread.java:619)
"Thread-1" daemon prio=6 tid=0x02fc0c00 nid=0x1324 in Object.wait()
[0x0349f000..0x0349fc94]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x22eb5318> (a [Ljava.lang.Object;)
at java.lang.Object.wait(Object.java:485)
at org.apache.felix.framework.Felix.acquireBundleLock(Felix.java:4227)
- locked <0x22eb5318> (a [Ljava.lang.Object;)
at org.apache.felix.framework.Felix.registerService(Felix.java:2736)
at
org.apache.felix.framework.BundleContextImpl.registerService(BundleContextImpl.java:252)
at
org.apache.felix.ipojo.IPojoContext.registerService(IPojoContext.java:336)
at
org.apache.felix.ipojo.handlers.providedservice.ProvidedService.registerService(ProvidedService.java:285)
- locked <0x230c7630> (a
org.apache.felix.ipojo.handlers.providedservice.ProvidedService)
at
org.apache.felix.ipojo.handlers.providedservice.ProvidedServiceHandler.__stateChanged(ProvidedServiceHandler.
java:441)
at
org.apache.felix.ipojo.handlers.providedservice.ProvidedServiceHandler.stateChanged(ProvidedServiceHandler.ja
va)
at
org.apache.felix.ipojo.InstanceManager.setState(InstanceManager.java:428)
at
org.apache.felix.ipojo.InstanceManager.start(InstanceManager.java:309)
at
org.apache.felix.ipojo.ComponentFactory.createInstance(ComponentFactory.java:155)
at
org.apache.felix.ipojo.IPojoFactory.createComponentInstance(IPojoFactory.java:283)
- locked <0x230a5ac0> (a org.apache.felix.ipojo.ComponentFactory)
at
org.apache.felix.ipojo.IPojoFactory.createComponentInstance(IPojoFactory.java:220)
at
org.apache.felix.ipojo.InstanceCreator$ManagedInstance.create(InstanceCreator.java:349)
at
org.apache.felix.ipojo.InstanceCreator.addInstance(InstanceCreator.java:84)
- locked <0x22f31748> (a org.apache.felix.ipojo.InstanceCreator)
at org.apache.felix.ipojo.Extender.parse(Extender.java:269)
at org.apache.felix.ipojo.Extender.startManagementFor(Extender.java:208)
at org.apache.felix.ipojo.Extender.access$600(Extender.java:52)
at org.apache.felix.ipojo.Extender$CreatorThread.run(Extender.java:669)
at java.lang.Thread.run(Thread.java:619)
"RMI TCP Connection(2)-172.16.173.69" daemon prio=6 tid=0x02f73c00 nid=0x1338
runnable [0x0344f000..0x0344fd14]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
at java.io.BufferedInputStream.read(BufferedInputStream.java:237)
- locked <0x22f58548> (a java.io.BufferedInputStream)
at java.io.FilterInputStream.read(FilterInputStream.java:66)
at
sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:517)
at
sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:790)
at
sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:649)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)
"RMI Scheduler(0)" daemon prio=6 tid=0x02f90800 nid=0xddc waiting on condition
[0x033ff000..0x033ffd94]
java.lang.Thread.State: TIMED_WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x22eb1098> (a
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at
java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:198)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.j
ava:1963)
at java.util.concurrent.DelayQueue.take(DelayQueue.java:164)
at
java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:583)
at
java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:576)
at
java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:947)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
at java.lang.Thread.run(Thread.java:619)
"RMI TCP Connection(1)-172.16.173.69" daemon prio=6 tid=0x02fbf800 nid=0x137c
runnable [0x033af000..0x033afa14]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
at java.io.BufferedInputStream.read(BufferedInputStream.java:237)
- locked <0x22f44358> (a java.io.BufferedInputStream)
at java.io.FilterInputStream.read(FilterInputStream.java:66)
at
sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:517)
at
sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:790)
at
sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:649)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)
"telnetconsole.Listener" daemon prio=6 tid=0x02fa7c00 nid=0x12fc runnable
[0x0335f000..0x0335fa94]
java.lang.Thread.State: RUNNABLE
at java.net.PlainSocketImpl.socketAccept(Native Method)
at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:384)
- locked <0x22f27e68> (a java.net.SocksSocketImpl)
at java.net.ServerSocket.implAccept(ServerSocket.java:453)
at java.net.ServerSocket.accept(ServerSocket.java:421)
at
org.apache.felix.shell.remote.Listener$Acceptor.run(Listener.java:109)
at java.lang.Thread.run(Thread.java:619)
"FelixPackageAdmin" daemon prio=6 tid=0x02f80400 nid=0x1040 in Object.wait()
[0x0330f000..0x0330fb14]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x22f23510> (a
org.apache.felix.framework.PackageAdminImpl)
at java.lang.Object.wait(Object.java:485)
at
org.apache.felix.framework.PackageAdminImpl.run(PackageAdminImpl.java:322)
- locked <0x22f23510> (a org.apache.felix.framework.PackageAdminImpl)
at java.lang.Thread.run(Thread.java:619)
"FelixStartLevel" daemon prio=6 tid=0x02f65400 nid=0x1304 waiting for monitor
entry [0x032bf000..0x032bfb94]
java.lang.Thread.State: BLOCKED (on object monitor)
at
org.apache.felix.ipojo.IPojoFactory.removeFactoryStateListener(IPojoFactory.java:470)
- waiting to lock <0x230a5ac0> (a
org.apache.felix.ipojo.ComponentFactory)
at
org.apache.felix.ipojo.InstanceCreator.removeFactory(InstanceCreator.java:182)
at org.apache.felix.ipojo.Extender.closeManagementFor(Extender.java:156)
at org.apache.felix.ipojo.Extender.bundleChanged(Extender.java:129)
- locked <0x22f2ff28> (a org.apache.felix.ipojo.Extender)
at
org.apache.felix.framework.util.EventDispatcher.invokeBundleListenerCallback(EventDispatcher.java:745)
at
org.apache.felix.framework.util.EventDispatcher.fireEventImmediately(EventDispatcher.java:674)
at
org.apache.felix.framework.util.EventDispatcher.fireBundleEvent(EventDispatcher.java:587)
at org.apache.felix.framework.Felix.fireBundleEvent(Felix.java:3629)
at org.apache.felix.framework.Felix._stopBundle(Felix.java:2076)
at org.apache.felix.framework.Felix.stopBundle(Felix.java:2034)
at
org.apache.felix.framework.Felix.setFrameworkStartLevel(Felix.java:1197)
at
org.apache.felix.framework.StartLevelImpl.run(StartLevelImpl.java:265)
at java.lang.Thread.run(Thread.java:619)
"FelixDispatchQueue" prio=6 tid=0x02f75800 nid=0x11a8 in Object.wait()
[0x0326f000..0x0326fc14]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x22ebfce0> (a java.util.ArrayList)
at java.lang.Object.wait(Object.java:485)
at
org.apache.felix.framework.util.EventDispatcher.run(EventDispatcher.java:849)
- locked <0x22ebfce0> (a java.util.ArrayList)
at
org.apache.felix.framework.util.EventDispatcher.access$000(EventDispatcher.java:45)
at
org.apache.felix.framework.util.EventDispatcher$1.run(EventDispatcher.java:97)
at java.lang.Thread.run(Thread.java:619)
"RMI TCP Accept-0" daemon prio=6 tid=0x02f30c00 nid=0x5e4 runnable
[0x031bf000..0x031bfd14]
java.lang.Thread.State: RUNNABLE
at java.net.PlainSocketImpl.socketAccept(Native Method)
at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:384)
- locked <0x22ea5788> (a java.net.SocksSocketImpl)
at java.net.ServerSocket.implAccept(ServerSocket.java:453)
at java.net.ServerSocket.accept(ServerSocket.java:421)
at
sun.management.jmxremote.LocalRMIServerSocketFactory$1.accept(LocalRMIServerSocketFactory.java:34)
at
sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(TCPTransport.java:369)
at
sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(TCPTransport.java:341)
at java.lang.Thread.run(Thread.java:619)
"RMI TCP Accept-1199" daemon prio=6 tid=0x02f29c00 nid=0x8dc runnable
[0x0316f000..0x0316fd94]
java.lang.Thread.State: RUNNABLE
at java.net.PlainSocketImpl.socketAccept(Native Method)
at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:384)
- locked <0x22ea5978> (a java.net.SocksSocketImpl)
at java.net.ServerSocket.implAccept(ServerSocket.java:453)
at java.net.ServerSocket.accept(ServerSocket.java:421)
at
sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(TCPTransport.java:369)
at
sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(TCPTransport.java:341)
at java.lang.Thread.run(Thread.java:619)
"RMI TCP Accept-0" daemon prio=6 tid=0x02f25c00 nid=0x1138 runnable
[0x0311f000..0x0311fa14]
java.lang.Thread.State: RUNNABLE
at java.net.PlainSocketImpl.socketAccept(Native Method)
at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:384)
- locked <0x22ea5b68> (a java.net.SocksSocketImpl)
at java.net.ServerSocket.implAccept(ServerSocket.java:453)
at java.net.ServerSocket.accept(ServerSocket.java:421)
at
sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(TCPTransport.java:369)
at
sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(TCPTransport.java:341)
at java.lang.Thread.run(Thread.java:619)
"Low Memory Detector" daemon prio=6 tid=0x02a6ec00 nid=0x13e0 runnable
[0x00000000..0x00000000]
java.lang.Thread.State: RUNNABLE
"CompilerThread0" daemon prio=10 tid=0x02a6b800 nid=0x17dc waiting on condition
[0x00000000..0x02d1f840]
java.lang.Thread.State: RUNNABLE
"Attach Listener" daemon prio=10 tid=0x02a6a000 nid=0xdbc runnable
[0x00000000..0x00000000]
java.lang.Thread.State: RUNNABLE
"Signal Dispatcher" daemon prio=10 tid=0x02a68c00 nid=0xaf0 waiting on
condition [0x00000000..0x00000000]
java.lang.Thread.State: RUNNABLE
"Finalizer" daemon prio=8 tid=0x02a63c00 nid=0x127c in Object.wait()
[0x02c2f000..0x02c2fc94]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x22e96ee8> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)
- locked <0x22e96ee8> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:132)
at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)
"Reference Handler" daemon prio=10 tid=0x02a5f400 nid=0x12a0 in Object.wait()
[0x02bdf000..0x02bdfd14]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x22e96f70> (a java.lang.ref.Reference$Lock)
at java.lang.Object.wait(Object.java:485)
at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
- locked <0x22e96f70> (a java.lang.ref.Reference$Lock)
"main" prio=6 tid=0x002a6c00 nid=0x12a4 in Object.wait()
[0x0090f000..0x0090fe54]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x22f16ed0> (a org.apache.felix.framework.util.ThreadGate)
at org.apache.felix.framework.util.ThreadGate.await(ThreadGate.java:48)
- locked <0x22f16ed0> (a org.apache.felix.framework.util.ThreadGate)
at org.apache.felix.framework.Felix.waitForStop(Felix.java:997)
at
com.axway.visualization.server.bootstrap.Bootstrap.main(Bootstrap.java:112)
"VM Thread" prio=10 tid=0x02a5d800 nid=0x1038 runnable
"VM Periodic Task Thread" prio=10 tid=0x02f32800 nid=0x1190 waiting on condition
JNI global references: 1144
Heap
def new generation total 960K, used 476K [0x22970000, 0x22a70000, 0x22e50000)
eden space 896K, 48% used [0x22970000, 0x229dd688, 0x22a50000)
from space 64K, 99% used [0x22a60000, 0x22a6fff8, 0x22a70000)
to space 64K, 0% used [0x22a50000, 0x22a50000, 0x22a60000)
tenured generation total 6424K, used 5802K [0x22e50000, 0x23496000,
0x26970000)
the space 6424K, 90% used [0x22e50000, 0x233fa800, 0x233fa800, 0x23496000)
compacting perm gen total 12288K, used 9883K [0x26970000, 0x27570000,
0x2a970000)
the space 12288K, 80% used [0x26970000, 0x27316fb0, 0x27317000, 0x27570000)
ro space 8192K, 67% used [0x2a970000, 0x2aed2d98, 0x2aed2e00, 0x2b170000)
rw space 12288K, 53% used [0x2b170000, 0x2b7e0640, 0x2b7e0800, 0x2bd70000)
What I understand is that the thread "FelixStartLevel" is blocked by the thread
"Thread-1" from iPojo.
In my case iPojo is in the process of validating a service while a shutdown
felix command is started.
I suspect this is maybe related to this bug :
https://issues.apache.org/jira/browse/FELIX-911
Tell me if you need more information other than the thread dump.
Thanks.
Regards
David
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
