RabbitMQ sometimes unresponsive ("doing siesta")

[robertdahlem]

I am running RabbitMQ 3.11.5 / Erlang 25.1.2 on a RHEL 8.6 system, patched until Nov 30, 2022.

My system is running as a three node cluster, I use quorum queues. In front of that is a HAproxy load balancer, but my issue is independent from HAproxy.

After "some time" my nodes seem to go into a status where they do not respond (correctly) to connection attempts but instead the client runs into a timeout after 12 seconds. The next connection attempt to the same node will succeed. "Some time" is anything below 30 minutes, I did not measure that yet.

Naturally, in this scenario load balancer clients will get up to three timeouts before they can connect successfully. But as I said: the issue is independent from the load balancer.

To produce some diagnostic data I wrote a small Perl script, attached as send.txt. It only does connect(), channel_open() and close(). It tends to run into "request timed out" while doing connect() the first time. See attached send.out.txt.

My users use the Java client and other libraries and experience the same. This is not a Perl issue, I use Perl just bc I'm old. :-)

When the timeout happens, I see this in the log (but with a different number than the failing connection):

Description: "Authenticity is not established by certificate path validation"
     Reason: "Option {verify, verify_peer} and cacertfile/cacerts is missing"

Description: "Authenticity is not established by certificate path validation"
     Reason: "Option {verify, verify_peer} and cacertfile/cacerts is missing"

I habe attached [email protected], rabbitmq.conf.txt, advanced.config.txt, output of rabbitmq-diagnostics.report.txt and rabbitmq-diagnostics.cluster_status.txt.

Can I add any other diagnostic data to help solving this issue?

One a side note - this link gets displayed when opening a new issue but does not exist
https://github.com/rabbitmq/rabbitmq-server/blob/main/CONTRIBUTING.md#github-issues

[michaelklishin]

2023-01-19 13:17:27.870566+01:00 [debug] <0.19115.8> User 'rmq-dev-itsbls-writer' failed authenticatation by backend rabbit_auth_backend_internal
2023-01-19 13:17:27.870762+01:00 [debug] <0.19115.8> User 'rmq-dev-itsbls-writer' authenticated successfully by backend rabbit_auth_backend_cache

Does not match what's inside your config files but you seem to be using the caching auth backend.
It does not cache authentication failures by default but if it did, for example, a client with correct
credentials would not be able to repeatedly connect until those cache results expired.

Another hypothesis: you use LDAP, an external dependency, which, if it slows down of fails to accept connection without refusing them immediately, will make the node wait before it can respond to the client.

Start by removing both of those backends, then re-introduce LDAP, then get that to work.

[robertdahlem]

Does not match what's inside your config files [...]

I will re-introduce the LDAP backend.

Meanwhile: what exactly is not matched by my config files? This user is in LDAP, so the internal backend fails and the cache backend succeeds.

But I get your drift. In the timeout case the log can be reduced to:

2023-01-19 13:15:45.339881+01:00 [debug] <0.18645.8> User 'rmq-dev-itsbls-writer' failed authenticatation by backend rabbit_auth_backend_internal
2023-01-19 13:16:00.365667+01:00 [debug] <0.18645.8> User 'rmq-dev-itsbls-writer' authenticated successfully by backend rabbit_auth_backend_cache

The cache backend seems to talk to LDAP and that takes 15 seconds - beyond the 12 second patience the client has.

[michaelklishin]

auth_cache.cache_refusals in the cache backend controls if auth failures will be cached. You can control caching interval/expiration as well.

[robertdahlem]

Start by removing both of those backends, then re-introduce LDAP, then get that to work.

Thank you for the hint!

Failure on our side: reviewing the LDAP configuration revealed a decommissioned LDAP server. This lead to long response times during connect() and to timeouts for impatient clients.

[robertdahlem]

I suggest to make it clear in the log files when there is an unresponsive LDAP server.
Also: while there are other servers that do respond: do not wait for the dead one.

[michaelklishin]

RabbitMQ does not implement an LDAP client, it uses the one that ship with Erlang/OTP.

What constitutes a "dead server" and what timeout interval should be used by default is a great question with many nuances. I would not oversimplify this. Our 10+ years experience with RabbitMQ suggests that all timeout defaults are wrong.

[robertdahlem]

RabbitMQ does not implement an LDAP client, it uses the one that ship with Erlang/OTP.

What constitutes a "dead server" and what timeout interval should be used by default is a great question with many nuances. I would not oversimplify this. Our 10+ years experience with RabbitMQ suggests that all timeout defaults are wrong.

I hope that we can agree that not covering up the dead server might have spared us this discussion. :-)

I see that eldap_open() has a timeout parameter that seems to default to infinity. That is a bit unusual because in the end it probably uses connect() which at least has ETIMEDOUT. Anyway: we are using TCP, which means the timeout depends on net.ipv4.tcp_syn_retries, default value 6. This gives us a default TCP connection timeout of 1+2+4+8+16+32=63 seconds on Linux.

I think something like "LDAP server %s did not respond to open() within %d seconds" would justify the trouble.

There actually IS some timeout configuration in deps/rabbitmq_auth_backend_ldap/src/rabbit_auth_backend_ldap.erl, it just doesn't seem to do anything with a "timeout" outcome.

[michaelklishin]

We will take a look at the timeout propagation, thank you for digging in.

[lukebakken]

I see that eldap_open() has a timeout parameter that seems to default to infinity

The default is infinity, but a connection timeout is set here in RabbitMQ if one is specified in configuration:

https://github.com/rabbitmq/rabbitmq-server/blob/main/deps/rabbitmq_auth_backend_ldap/src/rabbit_auth_backend_ldap.erl#L640

I see in your rabbitmq.conf file that you are setting the connection timeout to 15 seconds:

auth_ldap.timeout   = 15000

@robertdahlem have you tried a much lower timeout (like 1 second), such that a dead server would cause the next one to be tried before a client auth timeout happens?