Systemd prevents pause_minority re-join by restarting RabbitMQ

[robertdahlem]

I have a three node cluster to test pause_minority. All nodes run RHEL 7.9, Erlang 23.3.4.5 and RabbitMQ 3.9.0. I use RPMs from https://github.com/rabbitmq (erlang-rpm and rabbitmq-server). Nodes are joined manually to the cluster, I use the same rabbitmq.conf for all three nodes (rabbit1, rabbit2, rabbit3).

When I pull the network cable from rabbit2, a minute later it detects minority status and stops the applications. 90 seconds later, systemd detects that something is wrong with rabbitmq-server and restarts it:

systemd: rabbitmq-server.service: main process exited, code=killed, status=9/KILL
systemd: Unit rabbitmq-server.service entered failed state.
systemd: rabbitmq-server.service failed.
systemd: rabbitmq-server.service holdoff time over, scheduling restart.
systemd: Stopped RabbitMQ broker.
systemd: Starting RabbitMQ broker...

After that, nothing else happens although I reconnect the cable. I would expect rabbit2 to re-join the cluster, but that seems to be sabotaged by systemd restarting RabbitMQ.

The node re-joins the cluster when I reconnect the cable before 90 seconds, but systemd mercilessly kills and restarts RabbitMQ anyway after 90 seconds.

Here is the time table for the things I did:

17:57:08 disconnect eth0
17:58:10 Node rabbit2 detects loss of connectivity
17:59:40 systemd reports: stop-sigterm timed out. Killing
18:01:41 reconnect eth0

Log files and rabbitmq.conf attached.
rabbit@rabbit2.log
/var/log/messages
rabbitmq.conf

[michaelklishin]

I will convert this issue to a GitHub discussion. Currently GitHub will automatically close and lock the issue even though your question will be transferred and responded to elsewhere. This is to let you know that we do not intend to ignore this but this is how the current GitHub conversion mechanism makes it seem for the users :(

[michaelklishin]

You can override the Restart property and other things in the systemd unit file: https://serverfault.com/questions/840996/modify-systemd-unit-file-without-altering-upstream-unit-file.

Some want systemd to restart nodes , others don’t.
Unfortunately there is no way a default value can satisfy everyone. Here is the unit file that ships with RabbitMQ: https://github.com/rabbitmq/rabbitmq-packaging/blob/master/RPMS/Fedora/rabbitmq-server.service

a much better long term solution would be for replace the schema data store used in RabbitMQ with something that recovers the same way any Raft replica would. That work is ongoing for 4.0. We don’t offer any ETA promises.

[robertdahlem]

I fail to understand why systemd would see any failure at all. Documentation states about pause_minority:

The Erlang VM on the paused nodes will continue running but the nodes will not listen on any ports or be otherwise available. They will check once per second to see if the rest of the cluster has reappeared, and start up again if it has.

To me that basically says: the server process (the Erlang VM that systemd sees) changes its mode but continues to run.

With Type=notify it seems like RabbitMQ notifies systemd about going down. systemctl status says Active: deactivating (stop-sigterm) before actually killing the main process. To me it looks like a bug that RabbitMQ tells systemd it is going down when it is only changing its run mode.

[michaelklishin]

Modern RabbitMQ versions communicate with systemd using a library instead of socat. I can see it does the following:

prep_stop(State) ->
    ok = systemd:notify(stopping),
    State.

so anything that depends on this Erlang application will notify systemd whether it is warranted or not. I do not see that application
listed during the dependency graph traversal in the provided log:

2021-08-01 17:58:10.278153+02:00 [info] <0.739.0> Stopping RabbitMQ applications and their dependencies in the following order:
2021-08-01 17:58:10.278153+02:00 [info] <0.739.0>     rabbitmq_management
2021-08-01 17:58:10.278153+02:00 [info] <0.739.0>     amqp_client
2021-08-01 17:58:10.278153+02:00 [info] <0.739.0>     rabbitmq_web_dispatch
2021-08-01 17:58:10.278153+02:00 [info] <0.739.0>     cowboy
2021-08-01 17:58:10.278153+02:00 [info] <0.739.0>     cowlib
2021-08-01 17:58:10.278153+02:00 [info] <0.739.0>     rabbitmq_management_agent
2021-08-01 17:58:10.278153+02:00 [info] <0.739.0>     rabbit
2021-08-01 17:58:10.278153+02:00 [info] <0.739.0>     rabbitmq_prelaunch
2021-08-01 17:58:10.278153+02:00 [info] <0.739.0>     rabbit_common
2021-08-01 17:58:10.278153+02:00 [info] <0.739.0>     sysmon_handler
2021-08-01 17:58:10.278153+02:00 [info] <0.739.0>     os_mon
2021-08-01 17:58:10.278153+02:00 [info] <0.739.0>     osiris
2021-08-01 17:58:10.278153+02:00 [info] <0.739.0>     ra
2021-08-01 17:58:10.278153+02:00 [info] <0.739.0>     mnesia

While RabbitMQ depends on the library, I
do not see it depending on systemd_app (from rabbit.app):

{applications, [kernel,stdlib,sasl,rabbitmq_prelaunch,os_mon,inets,compiler,public_key,crypto,ssl,syntax_tools,xmerl,ranch,rabbit_common,ra,sysmon_handler,stdout_formatter,recon,observer_cli,osiris,amqp10_common,syslog,systemd,seshat]}

In addition, systemd status notifications should log notifying of state … at debug log level.

So without debug logging, I don't know what specifically may be notifying systemd but the case where you stop the RabbitMQ
app but not the runtime is indeed unusual for systemd services. As far as RabbitMQ is concerned, it is stopping, though.

If we find out what notifies systemd maybe there is a chance that this can be made conditional.

[michaelklishin]

In rabbit.erl, we have

prep_stop(State) ->
    rabbit_boot_state:set(stopping),
    rabbit_peer_discovery:maybe_unregister(),
    State.

which will be triggered for pause_minority, rabbitmqctl stop_app, rabbitmqctl shutdown and so on. That callback doesn't
have much context and in general, a pause minority stop is still a stop.

I'm not sure what options we have here, besides not combining pause_minority with systemd Restart. @dumbbell do you have an opinion?

[dumbbell]

I need to think about this issue a bit more, but indeed, there must be a conflict between systemd's monitoring and pause_minority's one.

[michaelklishin]

Our team doesn't have an immediate answer. Two systems here, RabbitMQ's node monitor and systemd, assume that they have all the context
in order to decide when to stop or start the node, and end up stepping over each others' toes.

[robertdahlem]

Attached please find a debug log of my case. I unplugged the network at about 22:47.

We see:

2021-08-04 22:48:05.472117+02:00 [debug] <0.132.0> Boot state/systemd: notifying of state `stopping`
2021-08-04 22:48:05.483490+02:00 [debug] <0.132.0> Boot state/systemd: sending non-systemd state (stopped) as status description:

and after the restart:

2021-08-04 22:50:06.459883+02:00 [debug] <0.132.0> Boot state/systemd: sending non-systemd state (core_started) as status description: Startup in progress (core ready, starting plugins)
2021-08-04 22:50:06.608939+02:00 [debug] <0.132.0> Boot state/systemd: notifying of state `ready`

rabbit2.debug.log

[robertdahlem]

I think there might be another issue: Ok, let's accept that systemd delivers a coup de grâce (read: kill the dead horse again, this time for good) and spawns a new one. Shouldn't this new instance reconnect to the cluster once network connectivity is restored? I can't see it doing that.

[dumbbell]

Hi @robertdahlem!

I prepared the following patch as an attempt to fix this issue: #3280.

Could you please give it a try?

[robertdahlem]

Hi @dumbbell!

Is there an RPM available including this fix? Otherwise I would need to build from source which would require me to find out how to do that in the first place. :-)

I will happily do so, but if there would be something downloadable already ...

[dumbbell]

There are no packages built from branches by CI out-of-the-box.

I can give you a file to copy to all hosts with an already installed RPM if that's ok with you:
rabbit_boot_state_systemd.beam.zip

You can unzip this archive to get the file. Then copy the file to /usr/lib/rabbitmq/lib/rabbitmq_server-*/plugins/rabbitmq_prelaunch-*/ebin, overwriting the existing one (you can keep a backup if you want) on all RabbitMQ nodes.

[robertdahlem]

Will do tomorrow. Thank you!

[robertdahlem]

Here is what I did: I upgraded to 3.9.2-1 and re-tested. As expected, systemd killed the remaining Erlang process after I cut the system from the network. Then I stopped all RabbitMQ servers in the cluster, replaced rabbit_boot_state_systemd.beam with your version and restarted RabbitMQ. After that I again cut the network for one machine. This time, RabbitMQ detected its minority status, but wasn't bothered by systemd.

So I can confirm that your patch fixes #3261.

[dumbbell]

Awesome, thank you!

I just converted this discussion back to an issue: #3289.