]
Radoslav Husar commented on WFLY-11292:
---------------------------------------
[~flavia.rainone] Just to keep the records correct, can you clarify what fixed the issue
and what's the fix version? We always set the fix version when resolving issues as
"done".
Legacy EJB Client: High fail rate
---------------------------------
Key: WFLY-11292
URL:
https://issues.jboss.org/browse/WFLY-11292
Project: WildFly
Issue Type: Bug
Components: Clustering, EJB
Affects Versions: 15.0.0.Beta1
Reporter: tommaso borgato
Assignee: Flavia Rainone
Priority: Blocker
Attachments: jboss-ejb-client.properties, logs-10clients.zip, logs.zip
This bug is being filed as Blocker because we are observing and elevated fail rate:
roughly a thousand each run for (about 0.3%).
h2. 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|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/...]
the complete logs;
the start of client errors is here:
{noformat}
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(a)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)
{noformat}
h2. WildFly Built from master branch on 7 Nov 2018
Same situation.
find
[
here|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/...]
the complete logs;
the start of client errors is here:
{noformat}
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(a)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)
{noformat}