Uploaded image for project: 'Application Server 7'
  1. Application Server 7
  2. AS7-2110

Deadlock condition in Management API

    XMLWordPrintable

Details

    Description

      I experience deadlock conditions during AS7 startup or archive deployment using Arquillian and Surefire.

      Thread dumps looks like:

      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)

      Finally, process fails with:

      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.

      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.

      Attachments

        Issue Links

          is related to

          Bug - A problem that impairs or prevents the functions of the product. JBPAPP-7388 Deadlock condition in Management API

          • Major - To be worked after higher priority work items are addressed. When the severity is high and the effort to change it is low to moderate, this term is chosen. Issues in this category likely have an existing workaround but implementation or execution may be non-trivial.
          • Resolved

          Activity

            People

              bstansbe@redhat.com Brian Stansberry
              kpiwko Karel Piwko
              Votes:
              0 Vote for this issue
              Watchers:
              4 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: