Created attachment 743180 [details] Original quickstart, jboss-ejb3.xml DS added to mark all beans as clustered, change the jboss-ejb-client.properties Description of problem: A client hung if a SLSB, marked as Clustered should invoked. This happen only for the first invocation after rebooting or redeploying the cluster instances. Also the problem does not occur if only one cluster node is available. It is not necessary to add the clusters properties to the jboss-ejb-client.propeties. How reproducible: See attached extended ejb-remote quickstart as reproducer. Steps to Reproduce: 1. compile the project 2. clone two instance of EAP6.0.1 3. copy ejb-remote/server-side/target/jboss-as-ejb-remote-server-side.jar to both standalone/deployments directories 4. start servers bin/standalone.sh -c standalone-ha.xml -Djboss.node.name=node1 bin/standalone.sh -c standalone-ha.xml -Djboss.socket.binding.port-offset=100 -Djboss.node.name=node2 - start client (java is used direct to avoid wrong mvn dependencies) java -cp ../../jboss1/bin/client/jboss-client.jar:target/jboss-as-ejb-remote-client.jar:../server-side/target/jboss-as-ejb-remote-server-side-client.jar org.jboss.as.quickstarts.ejb.remote.client.RemoteEJBClient Actual results: The client hung and after it is killed the servers must be also killed because a shutdown will hung. See attached file with thread dump of client and servers
Created attachment 743181 [details] Thread dumps of client and servers during hanging client
jaikiran pai <jpai> made a comment on jira EJBCLIENT-81 Pull requests sent. The details of what's causing this issue is explained in those pull requests.
jaikiran pai <jpai> made a comment on jira EJBCLIENT-81 Here's the thread dump for easy reference: {code} ================ Client dump [wfink@home client]$ mvn exec:exec /usr/lib/jvm/java [INFO] Scanning for projects... [INFO] [INFO] ------------------------------------------------------------------------ [INFO] Building JBoss AS Quickstarts: EJB Remote Client 7.1.2-SNAPSHOT [INFO] ------------------------------------------------------------------------ [INFO] [INFO] --- exec-maven-plugin:1.2.1:exec (default-cli) @ jboss-as-ejb-remote-client --- May 03, 2013 7:57:00 AM org.jboss.ejb.client.EJBClient <clinit> INFO: JBoss EJB Client version 1.0.16.Final Obtained a remote stateless calculator for invocation Adding 204 and 340 via the remote stateless calculator deployed on the server May 03, 2013 7:57:00 AM org.xnio.Xnio <clinit> INFO: XNIO Version 3.0.7.GA May 03, 2013 7:57:00 AM org.xnio.nio.NioXnio <clinit> INFO: XNIO NIO Implementation Version 3.0.7.GA May 03, 2013 7:57:00 AM org.jboss.remoting3.EndpointImpl <clinit> INFO: JBoss Remoting version 3.2.14.GA May 03, 2013 7:57:01 AM org.jboss.ejb.client.remoting.VersionReceiver handleMessage INFO: EJBCLIENT000017: Received server version 1 and marshalling strategies [river] May 03, 2013 7:57:01 AM org.jboss.ejb.client.remoting.RemotingConnectionEJBReceiver associate INFO: EJBCLIENT000013: Successful version handshake completed for receiver context EJBReceiverContext{clientContext=org.jboss.ejb.client.EJBClientContext@2a41da1c, receiver=Remoting connection EJB receiver [connection=Remoting connection <4a89fc68>,channel=jboss.ejb,nodename=node1]} on channel Channel ID 9d6d6a64 (outbound) of Remoting connection 3adf8f81 to localhost/127.0.0.1:4447 2013-05-03 07:57:31 Full thread dump OpenJDK 64-Bit Server VM (23.7-b01 mixed mode): "ejb-client-cluster-node-connection-creation-2-thread-2" daemon prio=10 tid=0x00007f32b0007000 nid=0xdfb waiting for monitor entry [0x00007f3328384000] java.lang.Thread.State: BLOCKED (on object monitor) at org.jboss.ejb.client.EJBClientContext.registerEJBReceiver(EJBClientContext.java:352) - waiting to lock <0x0000000783026150> (a java.util.IdentityHashMap) at org.jboss.ejb.client.ClusterContext.registerEJBReceiver(ClusterContext.java:319) at org.jboss.ejb.client.ClusterContext$EJBReceiverAssociationTask.call(ClusterContext.java:411) at org.jboss.ejb.client.ClusterContext$EJBReceiverAssociationTask.call(ClusterContext.java:380) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) at java.util.concurrent.FutureTask.run(FutureTask.java:166) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:722) "ejb-client-cluster-node-connection-creation-2-thread-1" daemon prio=10 tid=0x00007f32b0006800 nid=0xdfa in Object.wait() [0x00007f3328485000] java.lang.Thread.State: RUNNABLE at org.jboss.ejb.client.EJBClientContext.registerEJBReceiver(EJBClientContext.java:361) - locked <0x0000000783026150> (a java.util.IdentityHashMap) at org.jboss.ejb.client.ClusterContext.registerEJBReceiver(ClusterContext.java:319) at org.jboss.ejb.client.ClusterContext$EJBReceiverAssociationTask.call(ClusterContext.java:411) at org.jboss.ejb.client.ClusterContext$EJBReceiverAssociationTask.call(ClusterContext.java:380) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) at java.util.concurrent.FutureTask.run(FutureTask.java:166) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:722) "Remoting "client-endpoint" task-4" daemon prio=10 tid=0x00007f32b4055800 nid=0xdf8 waiting on condition [0x00007f3328586000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x0000000783203c78> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at org.xnio.LimitedBlockingQueue.take(LimitedBlockingQueue.java:95) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:722) "Remoting "client-endpoint" task-3" daemon prio=10 tid=0x00007f32b4053800 nid=0xdf6 waiting on condition [0x00007f3328687000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x0000000783203c78> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at org.xnio.LimitedBlockingQueue.take(LimitedBlockingQueue.java:95) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:722) "Remoting "client-endpoint" task-2" daemon prio=10 tid=0x00007f32b4052800 nid=0xdf4 waiting on condition [0x00007f3328788000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x0000000783203c78> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at org.xnio.LimitedBlockingQueue.take(LimitedBlockingQueue.java:95) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:722) "Remoting "client-endpoint" task-1" daemon prio=10 tid=0x00007f32b4050000 nid=0xdf2 waiting on condition [0x00007f3328889000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x0000000783203c78> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at org.xnio.LimitedBlockingQueue.take(LimitedBlockingQueue.java:95) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:722) "Remoting "client-endpoint" write-1" daemon prio=10 tid=0x00007f33342f0000 nid=0xdf1 runnable [0x00007f3328b92000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:228) at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:81) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) - locked <0x000000078321c8c8> (a sun.nio.ch.Util$2) - locked <0x000000078321c8b8> (a java.util.Collections$UnmodifiableSet) - locked <0x000000078321c698> (a sun.nio.ch.EPollSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) at org.xnio.nio.WorkerThread.run(WorkerThread.java:157) "Remoting "client-endpoint" read-1" daemon prio=10 tid=0x00007f33342ef000 nid=0xdf0 runnable [0x00007f333019f000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:228) at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:81) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) - locked <0x000000078321b1f0> (a sun.nio.ch.Util$2) - locked <0x000000078321b170> (a java.util.Collections$UnmodifiableSet) - locked <0x000000078321acb0> (a sun.nio.ch.EPollSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:102) at org.xnio.nio.WorkerThread.run(WorkerThread.java:153) "Service Thread" daemon prio=10 tid=0x00007f3334117000 nid=0xdee runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE "C2 CompilerThread1" daemon prio=10 tid=0x00007f3334115000 nid=0xded waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "C2 CompilerThread0" daemon prio=10 tid=0x00007f3334112000 nid=0xdec waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Signal Dispatcher" daemon prio=10 tid=0x00007f3334110000 nid=0xdeb waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Finalizer" daemon prio=10 tid=0x00007f33340ba000 nid=0xdea in Object.wait() [0x00007f33307d6000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x0000000782c05728> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135) - locked <0x0000000782c05728> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151) at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:189) "Reference Handler" daemon prio=10 tid=0x00007f33340b7800 nid=0xde9 in Object.wait() [0x00007f33308d7000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x0000000782c052b0> (a java.lang.ref.Reference$Lock) at java.lang.Object.wait(Object.java:503) at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133) - locked <0x0000000782c052b0> (a java.lang.ref.Reference$Lock) "main" prio=10 tid=0x00007f3334008800 nid=0xddf waiting for monitor entry [0x00007f333bee1000] java.lang.Thread.State: BLOCKED (on object monitor) at org.jboss.ejb.client.EJBClientContext.registerEJBReceiver(EJBClientContext.java:352) - waiting to lock <0x0000000783026150> (a java.util.IdentityHashMap) at org.jboss.ejb.client.EJBClientContext.registerEJBReceiver(EJBClientContext.java:327) at org.jboss.ejb.client.remoting.ConfigBasedEJBClientContextSelector.setupEJBReceivers(ConfigBasedEJBClientContextSelector.java:155) at org.jboss.ejb.client.remoting.ConfigBasedEJBClientContextSelector.<init>(ConfigBasedEJBClientContextSelector.java:105) at org.jboss.ejb.client.remoting.ConfigBasedEJBClientContextSelector.<init>(ConfigBasedEJBClientContextSelector.java:73) at org.jboss.ejb.client.EJBClientContext.<clinit>(EJBClientContext.java:81) at org.jboss.ejb.client.EJBInvocationHandler.doInvoke(EJBInvocationHandler.java:156) at org.jboss.ejb.client.EJBInvocationHandler.invoke(EJBInvocationHandler.java:124) at com.sun.proxy.$Proxy0.add(Unknown Source) at org.jboss.as.quickstarts.ejb.remote.client.RemoteEJBClient.invokeStatelessBean(RemoteEJBClient.java:56) at org.jboss.as.quickstarts.ejb.remote.client.RemoteEJBClient.main(RemoteEJBClient.java:37) "VM Thread" prio=10 tid=0x00007f33340af000 nid=0xde8 runnable "GC task thread#0 (ParallelGC)" prio=10 tid=0x00007f3334016800 nid=0xde0 runnable "GC task thread#1 (ParallelGC)" prio=10 tid=0x00007f3334018000 nid=0xde1 runnable "GC task thread#2 (ParallelGC)" prio=10 tid=0x00007f333401a000 nid=0xde2 runnable "GC task thread#3 (ParallelGC)" prio=10 tid=0x00007f333401c000 nid=0xde3 runnable "GC task thread#4 (ParallelGC)" prio=10 tid=0x00007f333401d800 nid=0xde4 runnable "GC task thread#5 (ParallelGC)" prio=10 tid=0x00007f333401f800 nid=0xde5 runnable "GC task thread#6 (ParallelGC)" prio=10 tid=0x00007f3334021800 nid=0xde6 runnable "GC task thread#7 (ParallelGC)" prio=10 tid=0x00007f3334023000 nid=0xde7 runnable "VM Periodic Task Thread" prio=10 tid=0x00007f3334122000 nid=0xdef waiting on condition JNI global references: 147 Heap PSYoungGen total 112192K, used 28870K [0x0000000782c00000, 0x000000078a930000, 0x0000000800000000) eden space 96192K, 30% used [0x0000000782c00000,0x0000000784831be0,0x00000007889f0000) from space 16000K, 0% used [0x0000000789990000,0x0000000789990000,0x000000078a930000) to space 16000K, 0% used [0x00000007889f0000,0x00000007889f0000,0x0000000789990000) ParOldGen total 256512K, used 0K [0x0000000688400000, 0x0000000697e80000, 0x0000000782c00000) object space 256512K, 0% used [0x0000000688400000,0x0000000688400000,0x0000000697e80000) PSPermGen total 21248K, used 9391K [0x000000067de00000, 0x000000067f2c0000, 0x0000000688400000) object space 21248K, 44% used [0x000000067de00000,0x000000067e72be98,0x000000067f2c0000) {code}
Verified the fix in EAP 6.1.1.ER3