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.