[jboss-jira] [JBoss JIRA] (AS7-2110) Deadlock condition in Management API

Deadlock condition in Management API ------------------------------------ Key: AS7-2110 URL: https://issues.jboss.org/browse/AS7-2110 Project: Application Server 7 Issue Type: Bug Components: IIOP, Test Suite Affects Versions: 7.1.0.Alpha1 Environment: RHEL6 x86_64 Reporter: Karel Piwko Assignee: Brian Stansberry I experience deadlock conditions during AS7 startup or archive deployment using Arquillian and Surefire. Thread dumps looks like: {code} Full thread dump Java HotSpot(TM) 64-Bit Server VM (19.1-b02 mixed mode): "XNIO NIO Write 1113" prio=10 tid=0x00007f4172b13800 nid=0x4604 runnable [0x00007f4159182000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:210) at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:65) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:69) - locked <0x00000000eb66def8> (a sun.nio.ch.Util$2) - locked <0x00000000eb66dee8> (a java.util.Collections$UnmodifiableSet) - locked <0x00000000eb66dce0> (a sun.nio.ch.EPollSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:80) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:84) at org.xnio.nio.AbstractNioChannelThread$1.run(AbstractNioChannelThread.java:124) at java.lang.Thread.run(Thread.java:662) "XNIO NIO Read 1113" prio=10 tid=0x00007f4172af8800 nid=0x4603 runnable [0x00007f4159283000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:210) at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:65) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:69) - locked <0x00000000eb66d188> (a sun.nio.ch.Util$2) - locked <0x00000000eb66d178> (a java.util.Collections$UnmodifiableSet) - locked <0x00000000eb66cf70> (a sun.nio.ch.EPollSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:80) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:84) at org.xnio.nio.AbstractNioChannelThread$1.run(AbstractNioChannelThread.java:124) at java.lang.Thread.run(Thread.java:662) "XNIO NIO Write 1112" prio=10 tid=0x00007f4172add800 nid=0x44aa runnable [0x00007f4159384000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:210) at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:65) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:69) - locked <0x00000000eb6079e0> (a sun.nio.ch.Util$2) - locked <0x00000000eb6079d0> (a java.util.Collections$UnmodifiableSet) - locked <0x00000000eb6077c8> (a sun.nio.ch.EPollSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:80) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:84) at org.xnio.nio.AbstractNioChannelThread$1.run(AbstractNioChannelThread.java:124) at java.lang.Thread.run(Thread.java:662) "XNIO NIO Read 1112" prio=10 tid=0x00007f4172ac2800 nid=0x44a8 runnable [0x00007f4159485000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:210) at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:65) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:69) - locked <0x00000000eb606c70> (a sun.nio.ch.Util$2) - locked <0x00000000eb606c60> (a java.util.Collections$UnmodifiableSet) - locked <0x00000000eb606a58> (a sun.nio.ch.EPollSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:80) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:84) at org.xnio.nio.AbstractNioChannelThread$1.run(AbstractNioChannelThread.java:124) at java.lang.Thread.run(Thread.java:662) ... more 1000 threads ... "process reaper" daemon prio=10 tid=0x00007f4274904000 nid=0x6a09 runnable [0x00007f424d3ea000] java.lang.Thread.State: RUNNABLE at java.lang.UNIXProcess.waitForProcessExit(Native Method) at java.lang.UNIXProcess.access$900(UNIXProcess.java:20) at java.lang.UNIXProcess$1$1.run(UNIXProcess.java:132) "SocketListener0-1" prio=10 tid=0x00007f42748aa800 nid=0x6a08 in Object.wait() [0x00007f424d4eb000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000c2cbfc50> (a org.openqa.jetty.util.ThreadPool$PoolThread) at org.openqa.jetty.util.ThreadPool$PoolThread.run(ThreadPool.java:522) - locked <0x00000000c2cbfc50> (a org.openqa.jetty.util.ThreadPool$PoolThread) "SocketListener0-0" prio=10 tid=0x00007f4274380000 nid=0x6a07 in Object.wait() [0x00007f424d5ec000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000c2cbfe58> (a org.openqa.jetty.util.ThreadPool$PoolThread) at org.openqa.jetty.util.ThreadPool$PoolThread.run(ThreadPool.java:522) - locked <0x00000000c2cbfe58> (a org.openqa.jetty.util.ThreadPool$PoolThread) "Acceptor ServerSocket[addr=0.0.0.0/0.0.0.0,port=0,localport=14444]" prio=10 tid=0x00007f4274506800 nid=0x6a06 runnable [0x00007f424d6ed000] java.lang.Thread.State: RUNNABLE at java.net.PlainSocketImpl.socketAccept(Native Method) at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:408) - locked <0x00000000c2cc5288> (a java.net.SocksSocketImpl) at java.net.ServerSocket.implAccept(ServerSocket.java:462) at java.net.ServerSocket.accept(ServerSocket.java:430) at org.openqa.jetty.util.ThreadedServer.acceptSocket(ThreadedServer.java:432) at org.openqa.jetty.util.ThreadedServer$Acceptor.run(ThreadedServer.java:634) "SessionScavenger" daemon prio=10 tid=0x00007f427451d000 nid=0x6a05 waiting on condition [0x00007f424d7ee000] java.lang.Thread.State: TIMED_WAITING (sleeping) at java.lang.Thread.sleep(Native Method) at org.openqa.jetty.jetty.servlet.AbstractSessionManager$SessionScavenger.run(AbstractSessionManager.java:617) "Timer-0" daemon prio=10 tid=0x00007f4274778800 nid=0x6a04 in Object.wait() [0x00007f424d8ef000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000c2caa0a8> (a java.util.TaskQueue) at java.util.TimerThread.mainLoop(Timer.java:509) - locked <0x00000000c2caa0a8> (a java.util.TaskQueue) at java.util.TimerThread.run(Timer.java:462) "Low Memory Detector" daemon prio=10 tid=0x00007f42740b7800 nid=0x6a00 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE "CompilerThread1" daemon prio=10 tid=0x00007f42740b5000 nid=0x69ff waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "CompilerThread0" daemon prio=10 tid=0x00007f42740b2000 nid=0x69fe waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Signal Dispatcher" daemon prio=10 tid=0x00007f42740b0000 nid=0x69fd waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Finalizer" daemon prio=10 tid=0x00007f4274093800 nid=0x69fc in Object.wait() [0x00007f427045c000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000c21d5c30> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118) - locked <0x00000000c21d5c30> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:134) at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159) "Reference Handler" daemon prio=10 tid=0x00007f4274091800 nid=0x69fb in Object.wait() [0x00007f427055d000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000c223b2a8> (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 <0x00000000c223b2a8> (a java.lang.ref.Reference$Lock) "main" prio=10 tid=0x00007f4274006800 nid=0x69f5 sleeping[0x00007f4278eef000] java.lang.Thread.State: TIMED_WAITING (sleeping) at java.lang.Thread.sleep(Native Method) at org.jboss.as.arquillian.container.managed.ManagedDeployableContainer.startInternal(ManagedDeployableContainer.java:138) at org.jboss.as.arquillian.container.CommonDeployableContainer.start(CommonDeployableContainer.java:69) at org.jboss.arquillian.container.impl.client.container.ContainerLifecycleController$5.perform(ContainerLifecycleController.java:144) at org.jboss.arquillian.container.impl.client.container.ContainerLifecycleController$5.perform(ContainerLifecycleController.java:134) at org.jboss.arquillian.container.impl.client.container.ContainerLifecycleController.forContainer(ContainerLifecycleController.java:186) at org.jboss.arquillian.container.impl.client.container.ContainerLifecycleController.startContainer(ContainerLifecycleController.java:133) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:90) at org.jboss.arquillian.core.impl.EventContextImpl.invokeObservers(EventContextImpl.java:99) at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:81) at org.jboss.arquillian.container.impl.client.ContainerDeploymentContextHandler.createContainerContext(ContainerDeploymentContextHandler.java:57) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:90) at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:88) at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:134) at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:114) at org.jboss.arquillian.core.impl.EventImpl.fire(EventImpl.java:67) at org.jboss.arquillian.container.impl.client.container.ContainerLifecycleController$2.perform(ContainerLifecycleController.java:83) at org.jboss.arquillian.container.impl.client.container.ContainerLifecycleController$2.perform(ContainerLifecycleController.java:76) at org.jboss.arquillian.container.impl.client.container.ContainerLifecycleController.forEachContainer(ContainerLifecycleController.java:179) at org.jboss.arquillian.container.impl.client.container.ContainerLifecycleController.startContainers(ContainerLifecycleController.java:75) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:90) at org.jboss.arquillian.core.impl.EventContextImpl.invokeObservers(EventContextImpl.java:99) at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:81) at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:134) at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:114) at org.jboss.arquillian.core.impl.EventImpl.fire(EventImpl.java:67) at org.jboss.arquillian.container.test.impl.client.ContainerEventController.execute(ContainerEventController.java:83) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:90) at org.jboss.arquillian.core.impl.EventContextImpl.invokeObservers(EventContextImpl.java:99) at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:81) at org.jboss.arquillian.test.impl.TestContextHandler.createSuiteContext(TestContextHandler.java:54) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:90) at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:88) at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:134) at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:114) at org.jboss.arquillian.test.impl.EventTestRunnerAdaptor.beforeSuite(EventTestRunnerAdaptor.java:68) at org.jboss.arquillian.junit.Arquillian.run(Arquillian.java:76) at org.apache.maven.surefire.junit4.JUnit4TestSet.execute(JUnit4TestSet.java:53) at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:123) at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:104) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.apache.maven.surefire.util.ReflectionUtils.invokeMethodWithArray(ReflectionUtils.java:164) at org.apache.maven.surefire.booter.ProviderFactory$ProviderProxy.invoke(ProviderFactory.java:110) at org.apache.maven.surefire.booter.SurefireStarter.invokeProvider(SurefireStarter.java:172) at org.apache.maven.surefire.booter.SurefireStarter.runSuitesInProcessWhenForked(SurefireStarter.java:104) at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:70) "VM Thread" prio=10 tid=0x00007f427408b000 nid=0x69fa runnable "GC task thread#0 (ParallelGC)" prio=10 tid=0x00007f4274019800 nid=0x69f6 runnable "GC task thread#1 (ParallelGC)" prio=10 tid=0x00007f427401b000 nid=0x69f7 runnable "GC task thread#2 (ParallelGC)" prio=10 tid=0x00007f427401d000 nid=0x69f8 runnable "GC task thread#3 (ParallelGC)" prio=10 tid=0x00007f427401f000 nid=0x69f9 runnable "VM Periodic Task Thread" prio=10 tid=0x00007f42740ca000 nid=0x6a01 waiting on condition JNI global references: 1589 Heap PSYoungGen total 25536K, used 3708K [0x00000000eb560000, 0x00000000ed5c0000, 0x0000000100000000) eden space 19200K, 7% used [0x00000000eb560000,0x00000000eb6c6ed0,0x00000000ec820000) from space 6336K, 35% used [0x00000000ecf90000,0x00000000ed1c8388,0x00000000ed5c0000) to space 6976K, 0% used [0x00000000ec820000,0x00000000ec820000,0x00000000ecef0000) PSOldGen total 63552K, used 55568K [0x00000000c2000000, 0x00000000c5e10000, 0x00000000eb560000) object space 63552K, 87% used [0x00000000c2000000,0x00000000c56442f8,0x00000000c5e10000) PSPermGen total 31616K, used 17083K [0x00000000bce00000, 0x00000000bece0000, 0x00000000c2000000) object space 31616K, 54% used [0x00000000bce00000,0x00000000bdeaef10,0x00000000bece0000) {code} Finally, process fails with: {code} Exception in thread "pool-1-thread-1" java.lang.OutOfMemoryError: unable to create new native thread at java.lang.Thread.start0(Native Method) at java.lang.Thread.start(Thread.java:640) at org.xnio.nio.AbstractNioChannelThread.start(AbstractNioChannelThread.java:194) at org.xnio.nio.NioXnio.createWriteChannelThread(NioXnio.java:155) at org.xnio.ChannelThreadPools.addWriteThreadsToPool(ChannelThreadPools.java:171) at org.xnio.ChannelThreadPools.addWriteThreadsToPool(ChannelThreadPools.java:151) at org.jboss.remoting3.remote.RemoteConnectionProvider.<init>(RemoteConnectionProvider.java:95) at org.jboss.remoting3.remote.RemoteConnectionProviderFactory.createInstance(RemoteConnectionProviderFactory.java:52) at org.jboss.remoting3.EndpointImpl.addConnectionProvider(EndpointImpl.java:279) at org.jboss.as.protocol.ProtocolChannelClient.create(ProtocolChannelClient.java:99) at org.jboss.as.protocol.mgmt.ManagementClientChannelStrategy$Establishing.getChannel(ManagementClientChannelStrategy.java:120) at org.jboss.as.protocol.mgmt.ManagementRequest$1.run(ManagementRequest.java:101) 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:662) Terminating xvnc. {code} Analysis of the situation: During deployment an XNIO NIO Write XYZ and XNIO NIO Read XYZ threads are created to read the status of the deployment but they are blocked. Process continues to create multiple read/write threads until the ulimit is reached and then it fails. I've reached this deadlock for following operations: public boolean isServerInRunningState() { try { ModelNode op = Util.getEmptyOperation(READ_ATTRIBUTE_OPERATION, PathAddress.EMPTY_ADDRESS.toModelNode()); op.get(NAME).set("server-state"); ModelNode rsp = client.execute(op); return SUCCESS.equals(rsp.get(OUTCOME).asString()) && !ControlledProcessState.State.STARTING.toString().equals(rsp.get(RESULT).asString()) && !ControlledProcessState.State.STOPPING.toString().equals(rsp.get(RESULT).asString()); } catch (Exception ignored) { return false; } } or public String deploy(Archive<?> archive) throws DeploymentException { try { InputStream input = archive.as(ZipExporter.class).exportAsInputStream(); DeploymentPlanBuilder builder = deploymentManager.newDeploymentPlan(); builder = builder.add(archive.getName(), input).andDeploy(); DeploymentPlan plan = builder.build(); DeploymentAction deployAction = builder.getLastAction(); return executeDeploymentPlan(plan, deployAction); } catch (Exception e) { throw new DeploymentException("Could not deploy to container", e); } } influencing both sync and async calls. Please check linked JBPAPP-7388 for further information or provide me more information how to isolate this issue.