Uploaded image for project: 'AMQ Broker'
  1. AMQ Broker
  2. ENTMQBR-4428

[LTS] [ARTEMIS-3004] 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)

    XMLWordPrintable

Details

    • Bug
    • Resolution: Done
    • Major
    • None
    • None
    • None
    • None
    • +
    • Verified in a release
    • Hide

      Either of the following configuration change can avoid this WARN log message:

      • Configure read-timeout of undertow http-listener with a larger value than default client-failure-check-period (30 seconds)
      • Configure another undertow http-listener which does not have read-timeout and specify the new listener as messaging http-acceptor
      Show
      Either of the following configuration change can avoid this WARN log message: Configure read-timeout of undertow http-listener with a larger value than default client-failure-check-period (30 seconds) Configure another undertow http-listener which does not have read-timeout and specify the new listener as messaging http-acceptor
    • Hide

      1. Create new EAP server:

      $ cd $JBOSS_HOME
$ cp -a standalone node1
$ cp -a standalone node2

      2. Copy the reproducible configuration to each nodes:

      $ unzip config-to-reproduce.zip
$ cp ./config-to-reproduce/standalone-full-node1.xml $JBOSS_HOME/node1/configuration/.
$ cp ./config-to-reproduce/standalone-full-node2.xml $JBOSS_HOME/node2/configuration/.

      3 Start node2 (jms server)

      $ cd $JBOSS_HOME
$ ./bin/standalone.sh -c standalone-full-node2.xml -Djboss.server.base.dir=node2 -Djboss.node.name=node2 -Djboss.socket.binding.port-offset=100

      4 Start node1 (jms client)

      $ cd $JBOSS_HOME
$ ./bin/standalone.sh -c standalone-full-node1.xml -Djboss.server.base.dir=node1 -Djboss.node.name=node1
      Show
      1. Create new EAP server: $ cd $JBOSS_HOME $ cp -a standalone node1 $ cp -a standalone node2 2. Copy the reproducible configuration to each nodes: $ unzip config-to-reproduce.zip $ cp ./config-to-reproduce/standalone-full-node1.xml $JBOSS_HOME/node1/configuration/. $ cp ./config-to-reproduce/standalone-full-node2.xml $JBOSS_HOME/node2/configuration/. 3 Start node2 (jms server) $ cd $JBOSS_HOME $ ./bin/standalone.sh -c standalone-full-node2.xml -Djboss.server.base.dir=node2 -Djboss.node.name=node2 -Djboss.socket.binding.port-offset=100 4 Start node1 (jms client) $ cd $JBOSS_HOME $ ./bin/standalone.sh -c standalone-full-node1.xml -Djboss.server.base.dir=node1 -Djboss.node.name=node1

    Description

      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:

      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)

      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.

      Attachments

        Issue Links

          causes

          Bug - A problem that impairs or prevents the functions of the product. ENTMQBR-4678 [LTS] Artemis keeps logging XA recovery warnings

          • 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
          clones

          Bug - A problem that impairs or prevents the functions of the product. ENTMQBR-3702 [ARTEMIS-3004] 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)

          • 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
          is related to

          Bug - A problem that impairs or prevents the functions of the product. JBEAP-20996 [QE](7.3.z) ARTEMIS-3120 Artemis keeps logging XA recovery warnings

          • 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

          Activity

            People

              rhn-support-jbertram Justin Bertram
              dbruscin Domenico Francesco Bruscino
              Tiago Bueno Tiago Bueno
              Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: