EJB Client threads left waiting to acquire a semaphore.
Hi,
I am using a benchmark to drive load at an application which includes remote RMI calls on a SLSB. Along with other protocol calls but unrelated to the issue I have.
The benchmark has load driven by a number of client machines. On occasion one of the clients stop sending network traffic. This should not happen when the benchmark is midway through.
Using jstack I inspected the thread stack traces for one of the jvm processes. I found several hundred threads WAITING with stack trace like this
"AcmeAgent[0].2234" #2287 daemon prio=5 os_prio=0 tid=0x00007f25b0f60800 nid=0x4f1f waiting on condition [0x00007f231fa76000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000003d4d54850> (a java.util.concurrent.Semaphore$FairSync)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:997)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1304)
at java.util.concurrent.Semaphore.acquire(Semaphore.java:312)
at org.jboss.ejb.client.remoting.ChannelAssociation.acquireChannelMessageOutputStream(ChannelAssociation.java:275)
at org.jboss.ejb.client.remoting.RemotingConnectionEJBReceiver.processInvocationInternal(RemotingConnectionEJBReceiver.java:295)
at org.jboss.ejb.client.remoting.RemotingConnectionEJBReceiver.access$100(RemotingConnectionEJBReceiver.java:77)
at org.jboss.ejb.client.remoting.RemotingConnectionEJBReceiver$2.run(RemotingConnectionEJBReceiver.java:282)
at java.security.AccessController.doPrivileged(Native Method)
at org.jboss.ejb.client.remoting.RemotingConnectionEJBReceiver.processInvocation(RemotingConnectionEJBReceiver.java:279)
at org.jboss.ejb.client.EJBClientInvocationContext.sendRequest(EJBClientInvocationContext.java:184)
at org.jboss.ejb.client.EJBObjectInterceptor.handleInvocation(EJBObjectInterceptor.java:58)
at org.jboss.ejb.client.EJBClientInvocationContext.sendRequest(EJBClientInvocationContext.java:186)
at org.jboss.ejb.client.EJBHomeInterceptor.handleInvocation(EJBHomeInterceptor.java:83)
at org.jboss.ejb.client.EJBClientInvocationContext.sendRequest(EJBClientInvocationContext.java:186)
at org.jboss.ejb.client.TransactionInterceptor.handleInvocation(TransactionInterceptor.java:42)
at org.jboss.ejb.client.EJBClientInvocationContext.sendRequest(EJBClientInvocationContext.java:186)
at org.jboss.ejb.client.ReceiverInterceptor.handleInvocation(ReceiverInterceptor.java:138)
at org.jboss.ejb.client.EJBClientInvocationContext.sendRequest(EJBClientInvocationContext.java:186)
at org.jboss.ejb.client.EJBInvocationHandler.sendRequestWithPossibleRetries(EJBInvocationHandler.java:255)
at org.jboss.ejb.client.EJBInvocationHandler.doInvoke(EJBInvocationHandler.java:200)
at org.jboss.ejb.client.EJBInvocationHandler.doInvoke(EJBInvocationHandler.java:183)
at org.jboss.ejb.client.EJBInvocationHandler.invoke(EJBInvocationHandler.java:146)
at com.sun.proxy.$Proxy4.acmeTask(Unknown Source)
at org.acme.Acme.createVehicle(Acme.java:389)
at org.acme.Acme.createVehicleEJB(Acme.java:112)
at sun.reflect.GeneratedMethodAccessor31.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:497)
at com.sun.faban.driver.engine.TimeThread.doRun(TimeThread.java:169)
at com.sun.faban.driver.engine.AgentThread.run(AgentThread.java:202)
After some minutes of waiting the jvm process still isn't driving load. Still with threads in WAITING parked state.
Looking at this it appears at some point beforehand an exception was thrown in the code. Causing a failure to release the acquired Semaphore. Over time Semaphores might have leaked causing exhaustion of available Semaphores.
I am using Wildfly 10.Final. Which has become EAP 7.0 GA.
The version of the jboss-ejb-client used is 2.1.4.Final. So I checked out the project and looked at the code.
Looking at acquireChannelMessageOutputStream I can see there is a possible cause for the leak.
Say for example if j.l.InterruptedException is thrown and wrapped. Wrapped as j.io.InterruptedIOException the code will return before calling the line
this.channelWriteSemaphore.release();
In fact to release the Semaphore the method has to throw an IOException to access the exception catch block. Containing the call to release the Semaphore.
In an attempt to improve this code I patched the code and tested again using the benchmark. The patch moves the release to a finally block. To ensure Semaphore permits do not leak.
The issue of the jvm threads parked WAITING for a semaphore has gone.
Do you see there is the possibility of leaking Semaphore permits ?
Regards,
Jeremy
