-
Bug
-
Resolution: Done
-
Major
-
10.1.0.Final
-
None
-
None
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).