Unexpected behavior in CONNECTION_RETRY_STEP logging #9340
Description
Discussed in #9269
Originally posted by guoard September 15, 2024
When consumers are unable to establish a connection to a RabbitMQ broker, the following error log is typically generated:
[2024-09-15 12:00:39,191: ERROR/MainProcess] consumer: Cannot connect to amqp://guest:**@127.0.0.1:5672//: [Errno 111] Connection refused.
Trying again in 2.00 seconds... (1/100)
In this example, the system attempts to reconnect and retries progressively, showing the retry count (e.g., (1/100)). However, after 16 retries, you'll notice that the retry count no longer increments. Instead, you begin seeing repeated logs like this:
[2024-09-15 12:04:09,244: ERROR/MainProcess] consumer: Cannot connect to amqp://guest:**@127.0.0.1:5672//: [Errno 111] Connection refused.
Trying again in 30.00 seconds... (15/100)
[2024-09-15 12:04:39,250: ERROR/MainProcess] consumer: Cannot connect to amqp://guest:**@127.0.0.1:5672//: [Errno 111] Connection refused.
Trying again in 32.00 seconds... (16/100)
[2024-09-15 12:05:11,253: ERROR/MainProcess] consumer: Cannot connect to amqp://guest:**@127.0.0.1:5672//: [Errno 111] Connection refused.
Trying again in 32.00 seconds... (16/100)
[2024-09-15 12:05:43,258: ERROR/MainProcess] consumer: Cannot connect to amqp://guest:**@127.0.0.1:5672//: [Errno 111] Connection refused.
Trying again in 32.00 seconds... (16/100)
This behavior occurs because the interval_max parameter in the retry_over_time function (as seen here) is set to a default of 30 seconds. When combined with the interval_start value, the total interval reaches 32 seconds (source).
The number of retries is then determined by the formula interval / 2, as introduced in PR #5915. In this case, 32 / 2 results in 16 retries, which explains why the retry count stalls at 16.