[jboss-jira] [JBoss JIRA] (WFLY-10725) Repeating WARN log message "Notified of connection failure" after every xa recovery when read-timeout is configure with a smaller value than default client-failure-check-period (30 seconds)

Repeating WARN log message "Notified of connection failure" after every xa recovery when read-timeout is configure with a smaller value than default client-failure-check-period (30 seconds) --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- Key: WFLY-10725 URL: https://issues.jboss.org/browse/WFLY-10725 Project: WildFly Issue Type: Bug Components: JMS Affects Versions: 13.0.0.Final Environment: - two JBoss EAP instances which are based on standalone-full.xml - one instance is configured as JMS server, which has {{read-timeout}} setting on the undertow {{http-listener}} and the specified value is smaller than *default* {{client-failure-check-period}} (30 seconds) {code:xml} <subsystem xmlns="urn:jboss:domain:messaging-activemq:2.0"> <server name="default"> <security enabled="false"/> ... <http-acceptor name="http-jms-acceptor" http-listener="default"/> <jms-queue name="jms.TEST" entries="java:jboss/exported/jms.TEST"/> </server> </subsystem> ... <subsystem xmlns="urn:jboss:domain:undertow:4.0"> <buffer-cache name="default"/> <server name="default-server"> <http-listener name="default" socket-binding="http" redirect-socket="https" enable-http2="true" read-timeout="5000"/> <!-- this issue happens when a smaller value than *default* client-failure-check-period (30 seconds) is specified to read-timeout. --> ... </server> ... </subsystem> {code} - another instance is configured as JMS client, which connects to the remote JMS server using {{pooled-connection-factory}} {code:xml} <subsystem xmlns="urn:jboss:domain:messaging-activemq:2.0"> <server name="default"> <security enabled="false"/> ... <http-connector name="remote-http-jms-connector" endpoint="http-jms-acceptor" socket-binding="jms-remote-server"/> <pooled-connection-factory name="remote-jms.TEST" entries="java:/jms/jms.TEST" connectors="remote-http-jms-connector" client-failure-check-period="4000"/> <!-- this issue happens even if client-failure-check-period is configured with a smaller value than read-timeout --> </server> </subsystem> {code} Reporter: Masafumi Miura Assignee: Martyn Taylor Attachments: config-to-reproduce.zip With the above configuration, The following WARN log message "{{Notified of connection failure ...: ActiveMQNotConnectedException\[errorType=NOT_CONNECTED message=AMQ119006: Channel disconnected\]}}" is thrown when passing {{read-timeout}} (5 seconds in the above config) after every xa recovery: {code} 14:38:41,362 WARN [org.jboss.activemq.artemis.wildfly.integration.recovery] (Thread-1 (ActiveMQ-client-global-threads)) Notified of connection failure in xa discovery, we will retry on the next recovery: ActiveMQNotConnectedException[errorType=NOT_CONNECTED message=AMQ119006: Channel disconnected] at org.apache.activemq.artemis.core.client.impl.ClientSessionFactoryImpl.connectionDestroyed(ClientSessionFactoryImpl.java:353) at org.apache.activemq.artemis.core.remoting.impl.netty.NettyConnector$Listener$1.run(NettyConnector.java:956) at org.apache.activemq.artemis.utils.OrderedExecutorFactory$OrderedExecutor$ExecutorTask.run(OrderedExecutorFactory.java:122) 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) 14:38:41,392 WARN [org.apache.activemq.artemis.service.extensions.xa.recovery] (Thread-1 (ActiveMQ-client-global-threads)) AMQ122014: Notified of connection failure in xa recovery connectionFactory for provider org.apache.activemq.artemis.core.client.impl.ClientSessionFactoryImpl@4f7f708 will attempt reconnect on next pass: ActiveMQNotConnectedException[errorType=NOT_CONNECTED message=AMQ119006: Channel disconnected] at org.apache.activemq.artemis.core.client.impl.ClientSessionFactoryImpl.connectionDestroyed(ClientSessionFactoryImpl.java:353) at org.apache.activemq.artemis.core.remoting.impl.netty.NettyConnector$Listener$1.run(NettyConnector.java:956) at org.apache.activemq.artemis.utils.OrderedExecutorFactory$OrderedExecutor$ExecutorTask.run(OrderedExecutorFactory.java:122) 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) 14:38:51,402 WARN [org.apache.activemq.artemis.service.extensions.xa.recovery] (Thread-1 (ActiveMQ-client-global-threads)) AMQ122014: Notified of connection failure in xa recovery connectionFactory for provider org.apache.activemq.artemis.core.client.impl.ClientSessionFactoryImpl@49e1f93a will attempt reconnect on next pass: ActiveMQNotConnectedException[errorType=NOT_CONNECTED message=AMQ119006: Channel disconnected] at org.apache.activemq.artemis.core.client.impl.ClientSessionFactoryImpl.connectionDestroyed(ClientSessionFactoryImpl.java:353) at org.apache.activemq.artemis.core.remoting.impl.netty.NettyConnector$Listener$1.run(NettyConnector.java:956) at org.apache.activemq.artemis.utils.OrderedExecutorFactory$OrderedExecutor$ExecutorTask.run(OrderedExecutorFactory.java:122) 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) {code} Note that this happens even if {{client-failure-check-period}} is configured with a smaller value than {{read-timeout}} on the {{pooled-connection-factory}} in the JMS client instance. From the byteman debug, it looks {{org.jboss.activemq.artemis.wildfly.integration.recovery.WildFlyRecoveryDiscovery#start}} and {{org.apache.activemq.artemis.service.extensions.xa.recovery.ActiveMQXAResourceWrapper#connect}} does not use the parameters specified on the {{pooled-connection-factory}} (like {{client-failure-check-period}} and {{connection-ttl}}). So, it uses the default values. Hence, {{read-timeout}} will close the connection due to inactivity on the server side and this WARN log message is thrown on the client. A new connection can be established correctly on the next xa recovery, so I think this WARN log message can be ignored. However, if xa recovery can establish a connection with the configured parameters (like {{client-failure-check-period}} and {{connection-ttl}}) on {{pooled-connection-factory}}, we can avoid this WARN log message by setting a smaller value to {{client-failure-check-period}}.