You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@activemq.apache.org by "Eric Wyles (JIRA)" <ji...@apache.org> on 2015/06/02 18:05:44 UTC
[jira] [Updated] (AMQ-5819) Failover Transport - Sleep for
Reconnect Delay happens twice
[ https://issues.apache.org/jira/browse/AMQ-5819?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Eric Wyles updated AMQ-5819:
----------------------------
Description:
When the failover transport is attempting to reconnect, it appears to sleep two different times, resulting in more than the expected reconnect delay.
To reproduce:
- start a jms client with brokerUrl: failover:(tcp://hostname:61616)?randomize=false&warnAfterReconnectAttempts=1
- turn on debug logging for logger 'org.apache.activemq.transport.failover.FailoverTransport'
- Once the application has connected, stop the broker on hostname
While the broker is down, observe the logs from org.apache.activemq.transport.failover.FailoverTransport, and you will see the following pattern for each iteration:
=====================
WARN - Failed to connect to [tcp://hostname:61616] after: n attempt(s) continuing to retry.
DEBUG - Waiting <reconnectDelay> ms before attempting connection
-- sleep happens here
DEBUG - urlList connectionList:[tcp://hostname:61616], from: [tcp://hostname:61616]
DEBUG - Waiting <reconnectDelay> ms before attempting connection
--- sleep happens here
DEBUG - Attempting nth connect to: tcp://hostname:61616
DEBUG - Connect fail to: tcp://hostname:61616, reason: java.net.ConnectException: Connection refused: connect
=====================
The above sequence is repeated for as long as the broker is down, with the exponent applied to the reconnectDelay in between the above two instances of sleep. In the configuration above, once the maxReconnectDelay is reached (30 seconds) it is actually 1 minute between attempts to reconnect to the broker. Log output with timestamps is shown below, and you can see that it is 1 minute between attempting the 13th connection and attempting to 14th connection, even though maxReconnectDelay is 30 seconds:
=====================
2015-06-02 10:39:19,824 [org.apache.activemq.transport.failover.FailoverTransport:1024] DEBUG - Attempting 13th connect to: tcp://hostname:61616
2015-06-02 10:39:20,860 [org.apache.activemq.transport.failover.FailoverTransport:1075] DEBUG - Connect fail to: tcp://hostname:61616, reason: java.net.ConnectException: Connection refused: connect
2015-06-02 10:39:20,860 [org.apache.activemq.transport.failover.FailoverTransport:1119] WARN - Failed to connect to [tcp://hostname:61616] after: 14 attempt(s) continuing to retry.
2015-06-02 10:39:20,860 [org.apache.activemq.transport.failover.FailoverTransport:1135] DEBUG - Waiting 30000 ms before attempting connection
2015-06-02 10:39:50,868 [org.apache.activemq.transport.failover.FailoverTransport:814 ] DEBUG - urlList connectionList:[tcp://hostname:61616], from: [tcp://hostname:61616]
2015-06-02 10:39:50,868 [org.apache.activemq.transport.failover.FailoverTransport:1000] DEBUG - Waiting 30000 ms before attempting connection.
2015-06-02 10:40:20,870 [org.apache.activemq.transport.failover.FailoverTransport:1024] DEBUG - Attempting 14th connect to: tcp://hostname:61616
=====================
was:
When the failover transport is attempting to reconnect, it appears to sleep two different times, resulting in more than the expected number of reconnect attempts.
To reproduce:
- start a jms client with brokerUrl: failover:(tcp://hostname:61616)?randomize=false&warnAfterReconnectAttempts=1
- turn on debug logging for logger 'org.apache.activemq.transport.failover.FailoverTransport'
- Once the application has connected, stop the broker on hostname
While the broker is down, observe the logs from org.apache.activemq.transport.failover.FailoverTransport, and you will see the following pattern for each iteration:
=====================
WARN - Failed to connect to [tcp://hostname:61616] after: n attempt(s) continuing to retry.
DEBUG - Waiting <reconnectDelay> ms before attempting connection
-- sleep happens here
DEBUG - urlList connectionList:[tcp://hostname:61616], from: [tcp://hostname:61616]
DEBUG - Waiting <reconnectDelay> ms before attempting connection
--- sleep happens here
DEBUG - Attempting nth connect to: tcp://hostname:61616
DEBUG - Connect fail to: tcp://hostname:61616, reason: java.net.ConnectException: Connection refused: connect
=====================
The above sequence is repeated for as long as the broker is down, with the exponent applied to the reconnectDelay in between the above two instances of sleep. In the configuration above, once the maxReconnectDelay is reached (30 seconds) it is actually 1 minute between attempts to reconnect to the broker. Log output with timestamps is shown below, and you can see that it is 1 minute between attempting the 13th connection and attempting to 14th connection, even though maxReconnectDelay is 30 seconds:
=====================
2015-06-02 10:39:19,824 [org.apache.activemq.transport.failover.FailoverTransport:1024] DEBUG - Attempting 13th connect to: tcp://hostname:61616
2015-06-02 10:39:20,860 [org.apache.activemq.transport.failover.FailoverTransport:1075] DEBUG - Connect fail to: tcp://hostname:61616, reason: java.net.ConnectException: Connection refused: connect
2015-06-02 10:39:20,860 [org.apache.activemq.transport.failover.FailoverTransport:1119] WARN - Failed to connect to [tcp://hostname:61616] after: 14 attempt(s) continuing to retry.
2015-06-02 10:39:20,860 [org.apache.activemq.transport.failover.FailoverTransport:1135] DEBUG - Waiting 30000 ms before attempting connection
2015-06-02 10:39:50,868 [org.apache.activemq.transport.failover.FailoverTransport:814 ] DEBUG - urlList connectionList:[tcp://hostname:61616], from: [tcp://hostname:61616]
2015-06-02 10:39:50,868 [org.apache.activemq.transport.failover.FailoverTransport:1000] DEBUG - Waiting 30000 ms before attempting connection.
2015-06-02 10:40:20,870 [org.apache.activemq.transport.failover.FailoverTransport:1024] DEBUG - Attempting 14th connect to: tcp://hostname:61616
=====================
> Failover Transport - Sleep for Reconnect Delay happens twice
> ------------------------------------------------------------
>
> Key: AMQ-5819
> URL: https://issues.apache.org/jira/browse/AMQ-5819
> Project: ActiveMQ
> Issue Type: Bug
> Components: JMS client
> Affects Versions: 5.10.0, 5.10.1, 5.10.2, 5.11.0, 5.11.1
> Reporter: Eric Wyles
> Priority: Minor
>
> When the failover transport is attempting to reconnect, it appears to sleep two different times, resulting in more than the expected reconnect delay.
> To reproduce:
> - start a jms client with brokerUrl: failover:(tcp://hostname:61616)?randomize=false&warnAfterReconnectAttempts=1
> - turn on debug logging for logger 'org.apache.activemq.transport.failover.FailoverTransport'
> - Once the application has connected, stop the broker on hostname
> While the broker is down, observe the logs from org.apache.activemq.transport.failover.FailoverTransport, and you will see the following pattern for each iteration:
> =====================
> WARN - Failed to connect to [tcp://hostname:61616] after: n attempt(s) continuing to retry.
> DEBUG - Waiting <reconnectDelay> ms before attempting connection
> -- sleep happens here
> DEBUG - urlList connectionList:[tcp://hostname:61616], from: [tcp://hostname:61616]
> DEBUG - Waiting <reconnectDelay> ms before attempting connection
> --- sleep happens here
> DEBUG - Attempting nth connect to: tcp://hostname:61616
> DEBUG - Connect fail to: tcp://hostname:61616, reason: java.net.ConnectException: Connection refused: connect
> =====================
> The above sequence is repeated for as long as the broker is down, with the exponent applied to the reconnectDelay in between the above two instances of sleep. In the configuration above, once the maxReconnectDelay is reached (30 seconds) it is actually 1 minute between attempts to reconnect to the broker. Log output with timestamps is shown below, and you can see that it is 1 minute between attempting the 13th connection and attempting to 14th connection, even though maxReconnectDelay is 30 seconds:
> =====================
> 2015-06-02 10:39:19,824 [org.apache.activemq.transport.failover.FailoverTransport:1024] DEBUG - Attempting 13th connect to: tcp://hostname:61616
> 2015-06-02 10:39:20,860 [org.apache.activemq.transport.failover.FailoverTransport:1075] DEBUG - Connect fail to: tcp://hostname:61616, reason: java.net.ConnectException: Connection refused: connect
> 2015-06-02 10:39:20,860 [org.apache.activemq.transport.failover.FailoverTransport:1119] WARN - Failed to connect to [tcp://hostname:61616] after: 14 attempt(s) continuing to retry.
> 2015-06-02 10:39:20,860 [org.apache.activemq.transport.failover.FailoverTransport:1135] DEBUG - Waiting 30000 ms before attempting connection
> 2015-06-02 10:39:50,868 [org.apache.activemq.transport.failover.FailoverTransport:814 ] DEBUG - urlList connectionList:[tcp://hostname:61616], from: [tcp://hostname:61616]
> 2015-06-02 10:39:50,868 [org.apache.activemq.transport.failover.FailoverTransport:1000] DEBUG - Waiting 30000 ms before attempting connection.
> 2015-06-02 10:40:20,870 [org.apache.activemq.transport.failover.FailoverTransport:1024] DEBUG - Attempting 14th connect to: tcp://hostname:61616
> =====================
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)