rabbitmq:3.8.5 fails at startup with some plugin exchanges in definitions.json

[khamadiev]

Hi guys.
Today we faced a strange issue after updating rabbitmq docker image up to 3.8.5. We have some exchanges from plugins in our setup, like rabbitmq_consistent_hash_exchange and rabbitmq_delayed_message_exchange, after update rabbitmq-server start fails at server startup with error message:

2020-07-26 12:26:40.085 [error] <0.558.0>
BOOT FAILED
2020-07-26 12:26:40.085 [error] <0.558.0> BOOT FAILED
===========
2020-07-26 12:26:40.086 [error] <0.558.0> ===========
2020-07-26 12:26:40.086 [error] <0.558.0> Exception during startup:
Exception during startup:
2020-07-26 12:26:40.086 [error] <0.558.0>

2020-07-26 12:26:40.086 [error] <0.558.0>     rabbit:do_run_postlaunch_phase/0 line 932
    rabbit:do_run_postlaunch_phase/0 line 932
2020-07-26 12:26:40.086 [error] <0.558.0>     lists:foreach/2 line 1338
    lists:foreach/2 line 1338
2020-07-26 12:26:40.086 [error] <0.558.0>     rabbit:'-do_run_postlaunch_phase/0-fun-12-'/1 line 934
    rabbit:'-do_run_postlaunch_phase/0-fun-12-'/1 line 934
2020-07-26 12:26:40.086 [error] <0.558.0>     rabbit_boot_steps:run_boot_steps/1 line 29
    rabbit_boot_steps:run_boot_steps/1 line 29
2020-07-26 12:26:40.087 [error] <0.558.0>     rabbit_boot_steps:'-run_boot_steps/1-lc$^0/1-0-'/1 line 28
    rabbit_boot_steps:'-run_boot_steps/1-lc$^0/1-0-'/1 line 28
2020-07-26 12:26:40.087 [error] <0.558.0>     rabbit_boot_steps:run_step/2 line 55
    rabbit_boot_steps:run_step/2 line 55
2020-07-26 12:26:40.087 [error] <0.558.0>     rabbit_boot_steps:'-run_step/2-lc$^0/1-0-'/2 line 52
    rabbit_boot_steps:'-run_step/2-lc$^0/1-0-'/2 line 52
2020-07-26 12:26:40.087 [error] <0.558.0> exit:{error,{amqp_error,command_invalid,
exit:{error,{amqp_error,command_invalid,
2020-07-26 12:26:40.087 [error] <0.558.0>                         "invalid exchange type 'x-consistent-hash'",none}}
                        "invalid exchange type 'x-consistent-hash'",none}}

Full startup log
erl_crash.dump.txt

But if I delete these exchanges from definitions.json, start server and import same definitions, everything seems fine:

Importing exchanges from file to server

# rabbitmqadmin list exchanges
+--------------------+---------+
|        name        |  type   |
+--------------------+---------+
|                    | direct  |
| amq.direct         | direct  |
| amq.fanout         | fanout  |
| amq.headers        | headers |
| amq.match          | headers |
| amq.rabbitmq.trace | topic   |
| amq.topic          | topic   |
| regular_dx         | direct  |
+--------------------+---------+
# rabbitmqadmin import /etc/rabbitmq/definitions_broken.json 
Uploaded definitions from "localhost" to /etc/rabbitmq/definitions_broken.json. The import process may take some time. Consult server logs to track progress.
# rabbitmqadmin list exchanges
+--------------------+-------------------+
|        name        |       type        |
+--------------------+-------------------+
|                    | direct            |
| amq.direct         | direct            |
| amq.fanout         | fanout            |
| amq.headers        | headers           |
| amq.match          | headers           |
| amq.rabbitmq.trace | topic             |
| amq.topic          | topic             |
| regular_dx         | direct            |
| test_dx            | x-delayed-message |
| test_hx            | x-consistent-hash |
+--------------------+-------------------+

Meanwhile in server logs

2020-07-26 12:54:26.790 [info] <0.1063.0> Importing concurrently 2 users...
2020-07-26 12:54:26.797 [info] <0.616.0> Successfully changed password for user 'admin'
2020-07-26 12:54:26.799 [info] <0.617.0> Successfully changed password for user 'exporter'
2020-07-26 12:54:26.802 [info] <0.616.0> Successfully set user tags for user 'admin' to [administrator]
2020-07-26 12:54:26.805 [info] <0.617.0> Successfully set user tags for user 'exporter' to [monitoring,policymaker]
2020-07-26 12:54:26.806 [info] <0.1063.0> Importing concurrently 1 vhosts...
2020-07-26 12:54:26.806 [info] <0.1063.0> Importing concurrently 2 permissions...
2020-07-26 12:54:26.809 [info] <0.616.0> Successfully set permissions for 'exporter' in virtual host '/' to '.*', '.*', '.*'
2020-07-26 12:54:26.809 [info] <0.617.0> Successfully set permissions for 'admin' in virtual host '/' to '.*', '.*', '.*'
2020-07-26 12:54:26.810 [info] <0.1063.0> Importing sequentially 1 policies...
2020-07-26 12:54:26.813 [info] <0.1063.0> Importing concurrently 3 exchanges...

How to reproduce

1. Use rabbitmq:3.8.5-management from official docker hub
2. Try to start server with provided definitions.json and enabled_plugins (for x-delayed-messages exchange you probably gonna need install this plugin)
   definitions.txt
   enabled_plugins.txt
3. It won't start

At this moment we rolled back to 3.8.2-management and everything works perfectly.

[michaelklishin]

This has nothing to do with this image. You are looking at rabbitmq/rabbitmq-server#2384 which will ship in 3.8.6.

[khamadiev]

Ok thanks, I'm gonna close this issue.
But I'm wondering, why this behavior isn't observed in 3.8.2 is there some changes in startup logic after that version?

[michaelklishin]

Because in RabbitMQ 3.8.4 we backported a major refactoring around node boot code paths. This exacerbated the chicken-and-egg problem around plugin activation and definition import (the problem isn't new, just did not affect this specific plugin before).

[khamadiev]

now it's clear, many thanks!