Uploaded image for project: 'WildFly'
  1. WildFly
  2. WFLY-11292

Legacy EJB Client: High fail rate

    XMLWordPrintable

Details

    • Bug
    • Resolution: Done
    • Blocker
    • None
    • 15.0.0.Beta1
    • Clustering, EJB
    • None

    Description

      This bug is being filed as Blocker because we are observing and elevated fail rate: roughly a thousand each run for (about 0.3%).

      WildFly Built from master branch on 6 Nov 2018

      With this WildFly version (client org.jboss:jboss-ejb-client-legacy:3.0.2.Final-redhat-1) in a scenario with 4 clustered nodes where nodes are failed via jboss shut-down / restart: after node 1 of 4 is shut-down, a a series of errors start on the client side the yield to 1097 errors on a total of 340218 samples;

      find here the complete logs;

      the start of client errors is here:

      2018/11/07 05:28:51:255 EST [INFO ][TestController] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Failing node 0 (perf18)
2018/11/07 05:28:51:270 EST [INFO ][StatsRunner] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Total: Sessions: 2000, active: 2000, samples: 5118, throughput: 511.7 samples/s, bandwidth: 0.0 MB/s, response min: 1 ms, mean: 1 ms, max: 54 ms, sampling errors: 0, unhealthy samples: 0, valid samples: 5118 (100%)
2018/11/07 05:28:51:270 EST [INFO ][StatsRunner] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - unknown-node: Sessions: 2000, active: 2000, samples: 5118, throughput: 511.7 samples/s, bandwidth: 0.0 MB/s, response min: 1 ms, mean: 1 ms, max: 54 ms, sampling errors: 0, unhealthy samples: 0, valid samples: 5118 (100%)
05:28:53,257 INFO  [org.jboss.ejb.client.remoting] (Remoting "config-based-ejb-client-endpoint" task-2) EJBCLIENT000016: Channel Channel ID c540daf7 (outbound) of Remoting connection 4ed5523c to perf18/10.16.90.54:8080 of endpoint "config-based-ejb-client-endpoint" <664ac6d5> can no longer process messages
05:28:53,277 ERROR [org.jboss.ejb.client.remoting.RemotingConnectionEJBReceiver] (Remoting "config-based-ejb-client-endpoint" task-2) Failed to open channel for context EJBReceiverContext{clientContext=org.jboss.ejb.client.EJBClientContext@3cd51445, receiver=Remoting connection EJB receiver [connection=org.jboss.ejb.client.remoting.ConnectionPool$PooledConnection@302066a5,channel=jboss.ejb,nodename=perf18]}
org.jboss.remoting3.NotOpenException: Cannot open new channel because close was initiated
	at org.jboss.remoting3.remote.RemoteConnectionHandler.handleOutboundChannelOpen(RemoteConnectionHandler.java:198)
	at org.jboss.remoting3.remote.RemoteConnectionHandler.open(RemoteConnectionHandler.java:335)
	at org.jboss.remoting3.ConnectionImpl.openChannel(ConnectionImpl.java:109)
	at org.jboss.ejb.client.remoting.ConnectionPool$PooledConnection.openChannel(ConnectionPool.java:292)
	at org.jboss.ejb.client.remoting.RemotingConnectionEJBReceiver.associate(RemotingConnectionEJBReceiver.java:180)
	at org.jboss.ejb.client.EJBClientContext.registerEJBReceiver(EJBClientContext.java:399)
	at org.jboss.ejb.client.EJBClientContext.registerEJBReceiver(EJBClientContext.java:349)
	at org.jboss.ejb.client.remoting.EJBClientContextConnectionReconnectHandler.reconnect(EJBClientContextConnectionReconnectHandler.java:67)
	at org.jboss.ejb.client.EJBClientContext$ReconnectAttempt.run(EJBClientContext.java:1474)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

      WildFly Built from master branch on 7 Nov 2018

      Same situation.

      find here the complete logs;

      the start of client errors is here:

      2018/11/07 09:23:22:916 EST [INFO ][TestController] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Failing node 0 (perf18)
2018/11/07 09:23:22:930 EST [INFO ][StatsRunner] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Total: Sessions: 2000, active: 2000, samples: 5125, throughput: 512.4 samples/s, bandwidth: 0.0 MB/s, response min: 1 ms, mean: 2 ms, max: 32 ms, sampling errors: 0, unhealthy samples: 0, valid samples: 5125 (100%)
2018/11/07 09:23:22:930 EST [INFO ][StatsRunner] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - unknown-node: Sessions: 2000, active: 2000, samples: 5125, throughput: 512.4 samples/s, bandwidth: 0.0 MB/s, response min: 1 ms, mean: 2 ms, max: 32 ms, sampling errors: 0, unhealthy samples: 0, valid samples: 5125 (100%)
09:23:24,924 INFO  [org.jboss.ejb.client.remoting] (Remoting "config-based-ejb-client-endpoint" task-4) EJBCLIENT000016: Channel Channel ID d940c707 (outbound) of Remoting connection 73cfdf01 to perf18/10.16.90.54:8080 of endpoint "config-based-ejb-client-endpoint" <7501616b> can no longer process messages
09:23:24,949 ERROR [org.jboss.ejb.client.remoting.RemotingConnectionEJBReceiver] (Remoting "config-based-ejb-client-endpoint" task-6) Failed to open channel for context EJBReceiverContext{clientContext=org.jboss.ejb.client.EJBClientContext@56248025, receiver=Remoting connection EJB receiver [connection=org.jboss.ejb.client.remoting.ConnectionPool$PooledConnection@5269f48d,channel=jboss.ejb,nodename=perf18]}
org.jboss.remoting3.NotOpenException: Cannot open new channel because close was initiated
	at org.jboss.remoting3.remote.RemoteConnectionHandler.handleOutboundChannelOpen(RemoteConnectionHandler.java:198)
	at org.jboss.remoting3.remote.RemoteConnectionHandler.open(RemoteConnectionHandler.java:335)
	at org.jboss.remoting3.ConnectionImpl.openChannel(ConnectionImpl.java:109)
	at org.jboss.ejb.client.remoting.ConnectionPool$PooledConnection.openChannel(ConnectionPool.java:292)
	at org.jboss.ejb.client.remoting.RemotingConnectionEJBReceiver.associate(RemotingConnectionEJBReceiver.java:180)
	at org.jboss.ejb.client.EJBClientContext.registerEJBReceiver(EJBClientContext.java:399)
	at org.jboss.ejb.client.EJBClientContext.registerEJBReceiver(EJBClientContext.java:349)
	at org.jboss.ejb.client.remoting.EJBClientContextConnectionReconnectHandler.reconnect(EJBClientContextConnectionReconnectHandler.java:67)
	at org.jboss.ejb.client.EJBClientContext$ReconnectAttempt.run(EJBClientContext.java:1474)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

      Attachments

        1. jboss-ejb-client.properties
          2 kB
        2. logs.zip
          218 kB
        3. logs-10clients.zip
          128 kB

        Issue Links

          is caused by

          Bug - A problem that impairs or prevents the functions of the product. EJBCLIENT-314 Legacy EJB Client: EJBClientInvocationContext.retryRequest fails

          • Blocker - To be worked above all other priorities. This term is chosen when the severity of the issue is very high, has no workaround, or the effort for the change is comparatively low. Issues that may be very publicly visible and could generate significant media attention may also drive a higher priority.
          • Resolved

          Enhancement - An enhancement to or refactoring of existing functionality that is not configurable by an end user (typically a change made by an internal team that affects users) EJBCLIENT-317 Legacy EJB Client: NotOpenException: Cannot open new channel because close was initiated

          • Major - To be worked after higher priority work items are addressed. When the severity is high and the effort to change it is low to moderate, this term is chosen. Issues in this category likely have an existing workaround but implementation or execution may be non-trivial.
          • Resolved
          is cloned by

          Bug - A problem that impairs or prevents the functions of the product. JBEAP-15787 (7.2.z) EJB-314/EJB-317 - Legacy EJB Client: High communication fail rate during failover

          • Blocker - To be worked above all other priorities. This term is chosen when the severity of the issue is very high, has no workaround, or the effort for the change is comparatively low. Issues that may be very publicly visible and could generate significant media attention may also drive a higher priority.
          • Verified
          is incorporated by

          Component Upgrade - A task tracking an update to a bundled component or revision of component upstream of the project. WFLY-11615 Upgrade legacy EJB Client to 3.0.3.Final

          • Major - To be worked after higher priority work items are addressed. When the severity is high and the effort to change it is low to moderate, this term is chosen. Issues in this category likely have an existing workaround but implementation or execution may be non-trivial.
          • Resolved
          is related to

          Bug - A problem that impairs or prevents the functions of the product. EJBCLIENT-135 Reconnect attempt logic could fail without timing out "reconnect.task.timeout"

          • Major - To be worked after higher priority work items are addressed. When the severity is high and the effort to change it is low to moderate, this term is chosen. Issues in this category likely have an existing workaround but implementation or execution may be non-trivial.
          • Closed

          Bug - A problem that impairs or prevents the functions of the product. EJBCLIENT-136 NotOpenException: Cannot open new channel because close was initiated on server shutdown

          • Major - To be worked after higher priority work items are addressed. When the severity is high and the effort to change it is low to moderate, this term is chosen. Issues in this category likely have an existing workaround but implementation or execution may be non-trivial.
          • Closed

          Activity

            People

              flaviarnn Flavia Rainone
              tborgato@redhat.com Tommaso Borgato
              Votes:
              0 Vote for this issue
              Watchers:
              6 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: