Uploaded image for project: 'EJB Client Library (AS7+)'
  1. EJB Client Library (AS7+)
  2. EJBCLIENT-317

Legacy EJB Client: NotOpenException: Cannot open new channel because close was initiated

    Details

    • Type: Enhancement
    • Status: Resolved (View Workflow)
    • Priority: Major
    • Resolution: Done
    • Affects Version/s: 3.0.2.Final
    • Fix Version/s: 3.0.3.Final
    • Labels:
      None

      Description

      The NotOpenException occurs too often.
      The cause is a race condition between the moment the channel starts sending close notifications and the moment the EJB client connection is removed from the pool (it is just removed after remoting sends the close notification).
      This exception, though, is not any indication of a bug, it is just how the code is architected for reconnection attempts, and is harmless.

      Here is an example of the exception stack trace:

      2018/11/06 11:12:27:263 EST [INFO ][TestController] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Failing node 2 (perf20)
      11:12:29,078 INFO  [org.jboss.ejb.client.remoting] (Remoting "config-based-ejb-client-endpoint" task-1) EJBCLIENT000016: Channel Channel ID fb008f94 (outbound) of Remoting connection 2a00ed12 to /10.16.90.58:8080 of endpoint "config-based-ejb-client-endpoint" <4b824c61> can no longer process messages
      11:12:29,114 INFO  [org.jboss.ejb.client.remoting] (Remoting "config-based-ejb-client-endpoint" task-4) EJBCLIENT000016: Channel Channel ID 8f12f2ec (outbound) of Remoting connection 13f3f7a6 to /10.16.90.72:8080 of endpoint "config-based-ejb-client-endpoint" <4b824c61> can no longer process messages
      11:12:29,132 INFO  [org.jboss.ejb.client.remoting] (Remoting "config-based-ejb-client-endpoint" task-4) EJBCLIENT000017: Received server version 3 and marshalling strategies [river]
      11:12:29,132 INFO  [org.jboss.ejb.client.remoting] (ejb-client-context-tasks-1-thread-22) EJBCLIENT000013: Successful version handshake completed for receiver context EJBReceiverContext{clientContext=org.jboss.ejb.client.EJBClientContext@79a74a25, receiver=Remoting connection EJB receiver [connection=org.jboss.ejb.client.remoting.ConnectionPool$PooledConnection@17bd8cb2,channel=jboss.ejb,nodename=perf21]} on channel Channel ID f6f6b0ba (outbound) of Remoting connection 13f3f7a6 to /10.16.90.72:8080 of endpoint "config-based-ejb-client-endpoint" <4b824c61>
      11:12:29,164 INFO  [org.jboss.ejb.client.remoting] (Remoting "config-based-ejb-client-endpoint" task-3) EJBCLIENT000016: Channel Channel ID f6f6b0ba (outbound) of Remoting connection 13f3f7a6 to /10.16.90.72:8080 of endpoint "config-based-ejb-client-endpoint" <4b824c61> can no longer process messages
      2018/11/06 11:12:29:180 EST [ERROR][Runner - 1922] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Error getting response. <java.lang.IllegalStateException: EJBCLIENT000032: Cannot retry a request which hasn't previously been completed>
              
      2018/11/06 11:12:29:180 EST [ERROR][Runner - 494] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Error getting response. <java.lang.IllegalStateException: EJBCLIENT000032: Cannot retry a request which hasn't previously been completed>
              
      2018/11/06 11:12:29:180 EST [ERROR][Runner - 969] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Error getting response. <java.lang.IllegalStateException: EJBCLIENT000032: Cannot retry a request which hasn't previously been completed>
              
      2018/11/06 11:12:29:181 EST [INFO ][Runner - 494] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Reached treshold of 1 errors, resetting session.
      2018/11/06 11:12:29:180 EST [ERROR][Runner - 1287] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Error getting response. <java.lang.IllegalStateException: EJBCLIENT000032: Cannot retry a request which hasn't previously been completed>
              
      2018/11/06 11:12:29:180 EST [ERROR][Runner - 1761] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Error getting response. <javax.ejb.EJBException: java.io.IOException: Channel Channel ID f6f6b0ba (outbound) of Remoting connection 13f3f7a6 to /10.16.90.72:8080 of endpoint "config-based-ejb-client-endpoint" <4b824c61> has been closed>
              
      2018/11/06 11:12:29:181 EST [INFO ][Runner - 1287] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Reached treshold of 1 errors, resetting session.
      2018/11/06 11:12:29:181 EST [INFO ][Runner - 969] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Reached treshold of 1 errors, resetting session.
      2018/11/06 11:12:29:180 EST [INFO ][Runner - 1922] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Reached treshold of 1 errors, resetting session.
      2018/11/06 11:12:29:181 EST [WARN ][Runner - 494] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Error sampling data:  <org.jboss.smartfrog.loaddriver.RequestProcessingException: Could not get valid response. Runner: 494.>
              
      2018/11/06 11:12:29:189 EST [INFO ][Runner - 1761] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Reached treshold of 1 errors, resetting session.
      11:12:29,181 INFO  [org.jboss.ejb.client.remoting] (Remoting "config-based-ejb-client-endpoint" task-1) EJBCLIENT000017: Received server version 3 and marshalling strategies [river]
      11:12:29,199 INFO  [org.jboss.ejb.client.remoting] (ejb-client-context-tasks-1-thread-22) EJBCLIENT000013: Successful version handshake completed for receiver context EJBReceiverContext{clientContext=org.jboss.ejb.client.EJBClientContext@79a74a25, receiver=Remoting connection EJB receiver [connection=org.jboss.ejb.client.remoting.ConnectionPool$PooledConnection@17bd8cb2,channel=jboss.ejb,nodename=perf21]} on channel Channel ID beeb14c5 (outbound) of Remoting connection 13f3f7a6 to /10.16.90.72:8080 of endpoint "config-based-ejb-client-endpoint" <4b824c61>
      2018/11/06 11:12:29:190 EST [WARN ][Runner - 494] SFCORE_LOG - Error sampling data:  <org.jboss.smartfrog.loaddriver.RequestProcessingException: Could not get valid response. Runner: 494.>
              org.jboss.smartfrog.loaddriver.RequestProcessingException: Could not get valid response. Runner: 494.
      	at org.jboss.smartfrog.clustering.ejb3.StatefulSBProcessorFactoryImplLegacyClient$EJB3RequestProcessor.processRequest(StatefulSBProcessorFactoryImplLegacyClient.java:109)
      	at org.jboss.smartfrog.loaddriver.CompoundRequestProcessorFactoryImpl$CompoundRequestProcessor.processRequest(CompoundRequestProcessorFactoryImpl.java:52)
      	at org.jboss.smartfrog.loaddriver.Runner.run(Runner.java:103)
      	at java.lang.Thread.run(Thread.java:748)
      Caused by: java.lang.IllegalStateException: EJBCLIENT000032: Cannot retry a request which hasn't previously been completed
      	at org.jboss.ejb.client.EJBClientInvocationContext.retryRequest(EJBClientInvocationContext.java:203)
      	at org.jboss.ejb.client.EJBInvocationHandler.sendRequestWithPossibleRetries(EJBInvocationHandler.java:260)
      	at org.jboss.ejb.client.EJBInvocationHandler.sendRequestWithPossibleRetries(EJBInvocationHandler.java:279)
      	at org.jboss.ejb.client.EJBInvocationHandler.doInvoke(EJBInvocationHandler.java:202)
      	at org.jboss.ejb.client.EJBInvocationHandler.doInvoke(EJBInvocationHandler.java:185)
      	at org.jboss.ejb.client.EJBInvocationHandler.invoke(EJBInvocationHandler.java:148)
      	at com.sun.proxy.$Proxy2.getSerialAndIncrement(Unknown Source)
      	at org.jboss.smartfrog.clustering.ejb3.StatefulSBProcessorFactoryImplLegacyClient$EJB3RequestProcessor.processRequest(StatefulSBProcessorFactoryImplLegacyClient.java:79)
      	... 3 more
      

        Gliffy Diagrams

          Attachments

            Issue Links

              Activity

                People

                • Assignee:
                  flavia.rainone Flavia Rainone
                  Reporter:
                  flavia.rainone Flavia Rainone
                • Votes:
                  0 Vote for this issue
                  Watchers:
                  1 Start watching this issue

                  Dates

                  • Created:
                    Updated:
                    Resolved: