[jboss-jira] [JBoss JIRA] (WFLY-9364) Closing an EJBClientContext sometimes hangs causing high CPU usage

David Lloyd (JIRA) issues at jboss.org
Thu Jun 7 15:20:00 EDT 2018


     [ https://issues.jboss.org/browse/WFLY-9364?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

David Lloyd resolved WFLY-9364.
-------------------------------
    Fix Version/s: 11.0.0.Final
       Resolution: Done


This issue should be fixed on WildFly 11.  The client from WildFly 11 can be used to talk to WildFly 10, but it is unlikely that the individual fix can be easily backported.  There are some fixes in the XNIO 3.5 branch that might be of use if you want to try that out.

> Closing an EJBClientContext sometimes hangs causing high CPU usage
> ------------------------------------------------------------------
>
>                 Key: WFLY-9364
>                 URL: https://issues.jboss.org/browse/WFLY-9364
>             Project: WildFly
>          Issue Type: Bug
>    Affects Versions: 10.1.0.Final
>         Environment: Server: 
> - OS:
>   Red Hat Enterprise Linux Server release 7.2 (Maipo)
> - JDK:
>   java version "1.8.0_144"
>   Java(TM) SE Runtime Environment (build 1.8.0_144-b01)
>   Java HotSpot(TM) 64-Bit Server VM (build 25.144-b01, mixed mode)
> - WildFly:
>   WildFly 10.1.0.Final
> Client:
> - OS:
>   Red Hat Enterprise Linux Server release 7.2 (Maipo)
> - JDK:
>   java version "1.8.0_144"
>   Java(TM) SE Runtime Environment (build 1.8.0_144-b01)
>   Java HotSpot(TM) 64-Bit Server VM (build 25.144-b01, mixed mode)
>            Reporter: Marius Tantareanu
>            Assignee: Jason Greene
>             Fix For: 11.0.0.Final
>
>         Attachments: echo-client.zip, output_rhel7.txt, output_win10.txt, simple-ear.ear, td_rhel7.txt, td_win10.txt
>
>
> EJBClientContext.close() sometimes hangs and causes high CPU usage. We have a WildFly client that uses EJB client API to invoke some EJBs remotely.
> Basically the client executes the following actions in a loop:
> - setup an EJBClientContext programatically
> - create a JNDI context
> - lookup an EJB and invoke some operations on it
> - close the JNDI context and the EJBClientContext
> After the client runs a few hundreds iterations (the actual number of iterations varies quite a lot from one run to another) it blocks while invoking EJBClientContext.close(). Also one XNIO thread in the client app is constantly consuming one CPU core (full thread dump from the client app is attached). I was only able to reproduce this when connecting over TLS (port 8443). When using the unsecure port (8080) the problem does not reproduce (or it reproduces much less frequently and I didn't run enough iterations to catch it).
> Once the client app enters this state, top shows something like (notice the CPU usage of thread 12512):
> >top -H -p 6463
>   PID USER      PR  NI    VIRT    RES    SHR S %CPU %MEM     TIME+ COMMAND
> 12512 root      20   0 11.527g 222680  13788 R 99.3  0.7 141:10.99 java
>  6466 root      20   0 11.527g 222680  13788 S  0.3  0.7   0:07.05 java
>  6467 root      20   0 11.527g 222680  13788 S  0.3  0.7   0:06.97 java
>  6477 root      20   0 11.527g 222680  13788 S  0.3  0.7   0:04.24 java
>  6463 root      20   0 11.527g 222680  13788 S  0.0  0.7   0:00.00 java
>  6464 root      20   0 11.527g 222680  13788 S  0.0  0.7   0:03.46 java
>  6465 root      20   0 11.527g 222680  13788 S  0.0  0.7   0:06.94 java
>  6468 root      20   0 11.527g 222680  13788 S  0.0  0.7   0:07.02 java
>  6469 root      20   0 11.527g 222680  13788 S  0.0  0.7   0:16.42 java
>  6470 root      20   0 11.527g 222680  13788 S  0.0  0.7   0:00.01 java
>  6471 root      20   0 11.527g 222680  13788 S  0.0  0.7   0:00.01 java
>  6472 root      20   0 11.527g 222680  13788 S  0.0  0.7   0:00.00 java
>  6473 root      20   0 11.527g 222680  13788 S  0.0  0.7   0:06.87 java
>  6474 root      20   0 11.527g 222680  13788 S  0.0  0.7   0:06.70 java
>  6475 root      20   0 11.527g 222680  13788 S  0.0  0.7   0:03.09 java
>  6476 root      20   0 11.527g 222680  13788 S  0.0  0.7   0:00.00 java
> 12513 root      20   0 11.527g 222680  13788 S  0.0  0.7   0:00.00 java
> 12514 root      20   0 11.527g 222680  13788 S  0.0  0.7   0:00.00 java
> 12515 root      20   0 11.527g 222680  13788 S  0.0  0.7   0:00.00 java
> 12516 root      20   0 11.527g 222680  13788 S  0.0  0.7   0:00.00 java
> 12517 root      20   0 11.527g 222680  13788 S  0.0  0.7   0:00.00 java
> 12518 root      20   0 11.527g 222680  13788 S  0.0  0.7   0:00.00 java
> 12519 root      20   0 11.527g 222680  13788 S  0.0  0.7   0:00.00 java
> 12520 root      20   0 11.527g 222680  13788 S  0.0  0.7   0:00.00 java
> 12523 root      20   0 11.527g 222680  13788 S  0.0  0.7   0:00.00 java
> 12524 root      20   0 11.527g 222680  13788 S  0.0  0.7   0:00.00 java
> 12597 root      20   0 11.527g 222680  13788 S  0.0  0.7   0:00.00 java
> The thread that causes the CPU usage is the following:
> "Remoting "config-based-ejb-client-endpoint" I/O-1" #6025 daemon prio=5 os_prio=0 tid=0x00007f2f709d3000 nid=0x30e0 runnable [0x00007f2e7f9be000]
>    java.lang.Thread.State: RUNNABLE
>         at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
>         at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
>         at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93)
>         at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
>         - locked <0x00000005cc1844e8> (a sun.nio.ch.Util$3)
>         - locked <0x00000005cc19f258> (a java.util.Collections$UnmodifiableSet)
>         - locked <0x00000005cc184468> (a sun.nio.ch.EPollSelectorImpl)
>         at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
>         at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:101)
>         at org.xnio.nio.WorkerThread.run(WorkerThread.java:515)
> The client app main thread is blocked as below:
> "main" #1 prio=5 os_prio=0 tid=0x00007f2f70008800 nid=0x1940 in Object.wait() [0x00007f2f76350000]
>    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.jboss.remoting3.spi.AbstractHandleableCloseable.close(AbstractHandleableCloseable.java:190)
>         - locked <0x00000005cc18de48> (a java.lang.Object)
>         at org.jboss.ejb.client.remoting.ConnectionPool.safeClose(ConnectionPool.java:177)
>         at org.jboss.ejb.client.remoting.ConnectionPool.release(ConnectionPool.java:104)
>         - locked <0x00000005cbd369e0> (a org.jboss.ejb.client.remoting.ConnectionPool)
>         at org.jboss.ejb.client.remoting.ConnectionPool$PooledConnection.close(ConnectionPool.java:198)
>         at org.jboss.ejb.client.remoting.RemotingConnectionManager.safeClose(RemotingConnectionManager.java:65)
>         - locked <0x00000005cc1a6840> (a java.util.Collections$SynchronizedRandomAccessList)
>         at org.jboss.ejb.client.remoting.ConfigBasedEJBClientContextSelector$ContextCloseListener.contextClosed(ConfigBasedEJBClientContextSelector.java:220)
>         at org.jboss.ejb.client.EJBClientContext.close(EJBClientContext.java:1305)
>         - locked <0x00000005cc1a6888> (a org.jboss.ejb.client.EJBClientContext)
>         at com.microfocus.echoclient.EchoClient.disconnect(EchoClient.java:66)
>         at com.microfocus.echoclient.EchoClient.connectDisconnect(EchoClient.java:54)
>         at com.microfocus.echoclient.EchoClient.main(EchoClient.java:36)
> The problem also reproduces on Windows (full thread dump of the client app is attached).



--
This message was sent by Atlassian JIRA
(v7.5.0#75005)


More information about the jboss-jira mailing list