Potential heartbeat misconfiguration

[boncea]

Problem (it occurs randomly):

GO library error: Exception (504) Reason: "channel/connection is not open"
RabbitMQ related log: missed heartbeats from client, timeout: 10s

Important to refresh - rabbitMQ doc:

Heartbeat frames are sent about every heartbeat timeout / 2 seconds. This value is sometimes referred to as the heartbeat interval. After two missed heartbeats, the peer is considered to be unreachable.
[...]
It is important to not confuse the timeout value with the interval one. RabbitMQ configuration exposes the timeout value, so do the officially supported client libraries. However some clients might expose the interval, potentially causing confusion.
source - rabbitMQ doc

Investigation details

According to the doc and to the rabbitMQ log message, the heartbeat should be sent every 5 seconds. Still, based on my investigation this is not the case. My guess is that the heartbeat is sent only once per timeout interval and in the case of race conditions (the heartbeat client time aligns well with the rabbitMQ server heartbeat timeout time), the server will close the channel. Please check my reasoning below:

• The 10s timeout from the config is set as a default value by the GO client here https://github.com/streadway/amqp/blob/master/connection.go#L142
• even though the doc specifies that the heartbeat frames should be sent every timeout / 2 seconds, it appears to me that the timeout is actually treated as an interval, thus the heartbeat messages get sent every timeout seconds
• how the heartbeat config is decided -> https://github.com/streadway/amqp/blob/master/connection.go#L781
• heartbeater call with config -> https://github.com/streadway/amqp/blob/master/connection.go#L787
• heartbeater ticker using the interval -> https://github.com/streadway/amqp/blob/master/connection.go#L548

Suggestions:

• use the heartbeat configuration as timeout configuration and set the ticker to config / 2 seconds (this shall be a very small change done here https://github.com/streadway/amqp/blob/master/connection.go#L548 )
• delay the start of the heartbeater by a short period of time in order to prevent race conditions (I think the .NET client does something similar here https://github.com/rabbitmq/rabbitmq-dotnet-client/blob/aa71dc1a6dbbb12b36dc196b0e611fdc83b2885e/projects/RabbitMQ.Client/client/impl/Connection.cs#L206 )
• Clarify in the doc if the heartbeat config refers to the interval or to the timeout

Considering that I didn't spend time to test my theory, my assumptions might be wrong, so please correct me in this case.

[Neal]

@boncea thanks for the detailed report -- wish I had searched here before debugging on my own but I came here for exactly this issue as I'm seeing similar behavior as well and came up with the same conclusion after some investigation.

[boncea]

@Neal glad that at least there is one more person confirming my theory. I could do the fix by myself as we just have to use half of the heartbeat value to send signals, but considering that there was no response in two months, I'm wondering if this library is still maintained.

[Neal]

considering that there was no response in two months, I'm wondering if this library is still maintained.

This recent #497 (comment) suggests that unfortunately, it is not. However, this #497 (comment) suggests that Team RabbitMQ plans to take over soon. So hopefully we start getting these fixes in soon (including other open PRs).

This particular issue, though, I am only seeing on one of our environments (which is configured the same way as far as I can tell except that it's a single node cluster vs. the other ones being 3 nodes).