RabbitMQ 3.7.4 running within docker container (run from official docker image) fails to start with the below error: The issue happens randomly.
2019-07-03 17:08:17.859 [info] <0.33.0> Application lager started on node 'rabbit@rabbit-im-pla-slave-1'
2019-07-03 17:08:19.634 [info] <0.33.0> Application mnesia started on node 'rabbit@rabbit-im-pla-slave-1'
2019-07-03 17:08:19.635 [info] <0.33.0> Application recon started on node 'rabbit@rabbit-im-pla-slave-1'
2019-07-03 17:08:19.635 [info] <0.33.0> Application jsx started on node 'rabbit@rabbit-im-pla-slave-1'
2019-07-03 17:08:19.649 [info] <0.33.0> Application os_mon started on node 'rabbit@rabbit-im-pla-slave-1'
2019-07-03 17:08:19.649 [info] <0.33.0> Application xmerl started on node 'rabbit@rabbit-im-pla-slave-1'
2019-07-03 17:08:19.936 [info] <0.33.0> Application inets started on node 'rabbit@rabbit-im-pla-slave-1'
2019-07-03 17:08:19.937 [info] <0.33.0> Application asn1 started on node 'rabbit@rabbit-im-pla-slave-1'
2019-07-03 17:08:19.937 [info] <0.33.0> Application crypto started on node 'rabbit@rabbit-im-pla-slave-1'
2019-07-03 17:08:19.937 [info] <0.33.0> Application public_key started on node 'rabbit@rabbit-im-pla-slave-1'
2019-07-03 17:08:20.172 [info] <0.33.0> Application ssl started on node 'rabbit@rabbit-im-pla-slave-1'
2019-07-03 17:08:20.178 [info] <0.33.0> Application ranch started on node 'rabbit@rabbit-im-pla-slave-1'
2019-07-03 17:08:20.178 [info] <0.33.0> Application ranch_proxy_protocol started on node 'rabbit@rabbit-im-pla-slave-1'
2019-07-03 17:08:20.178 [info] <0.33.0> Application rabbit_common started on node 'rabbit@rabbit-im-pla-slave-1'
2019-07-03 17:08:20.211 [info] <0.187.0>
Starting RabbitMQ 3.7.4 on Erlang 20.3.4
Copyright (C) 2007-2018 Pivotal Software, Inc.
Licensed under the MPL. See http://www.rabbitmq.com/
epic_rabbitmq.0.ovt2eij5rr0r@im-pla-slave-1 |
## ##
## ## RabbitMQ 3.7.4. Copyright (C) 2007-2018 Pivotal Software, Inc.
########## Licensed under the MPL. See http://www.rabbitmq.com/
###### ##
########## Logs: <stdout>
epic_rabbitmq.0.ovt2eij5rr0r@im-pla-slave-1 |
Starting broker...
2019-07-03 17:08:20.231 [info] <0.187.0>
node : rabbit@rabbit-im-pla-slave-1
home dir : /var/lib/rabbitmq
config file(s) : /etc/paasrabbitmq/paasrabbitmq.conf
cookie hash : Sqvm1ja/eeUKv+fi/FfMKg==
log(s) : <stdout>
database dir : /var/lib/rabbitmq/mnesia/rabbit@rabbit-im-pla-slave-1
2019-07-03 17:08:24.188 [info] <0.199.0> Memory high watermark set to 12867 MiB (13492759756 bytes) of 32169 MiB (33731899392 bytes) total
2019-07-03 17:08:24.197 [info] <0.201.0> Enabling free disk space monitoring
2019-07-03 17:08:24.197 [info] <0.201.0> Disk free limit set to 50MB
2019-07-03 17:08:24.208 [info] <0.204.0> FHC read buffering: OFF
2019-07-03 17:08:24.208 [info] <0.204.0> FHC write buffering: ON
2019-07-03 17:08:24.208 [info] <0.203.0> Limiting to approx 65436 file handles (58890 sockets)
2019-07-03 17:08:24.209 [info] <0.187.0> Node database directory at /var/lib/rabbitmq/mnesia/rabbit@rabbit-im-pla-slave-1 is empty. Assuming we need to join an existing cluster or initialise from scratch...
2019-07-03 17:08:24.209 [info] <0.187.0> Configured peer discovery backend: rabbit_peer_discovery_classic_config
2019-07-03 17:08:24.210 [info] <0.187.0> Will try to lock with peer discovery backend rabbit_peer_discovery_classic_config
2019-07-03 17:08:24.210 [info] <0.187.0> Peer discovery backend does not support locking, falling back to randomized delay
2019-07-03 17:08:24.210 [info] <0.187.0> Peer discovery backend rabbit_peer_discovery_classic_config does not support registration, skipping randomized startup delay.
2019-07-03 17:08:24.210 [info] <0.187.0> All discovered existing cluster peers:
2019-07-03 17:08:24.210 [info] <0.187.0> Discovered no peer nodes to cluster with
2019-07-03 17:08:24.213 [info] <0.33.0> Application mnesia exited with reason: stopped
2019-07-03 17:08:24.700 [info] <0.33.0> Application mnesia started on node 'rabbit@rabbit-im-pla-slave-1'
2019-07-03 17:08:25.845 [info] <0.187.0> Waiting for Mnesia tables for 30000 ms, 9 retries left
2019-07-03 17:08:25.879 [info] <0.187.0> Waiting for Mnesia tables for 30000 ms, 9 retries left
2019-07-03 17:08:26.072 [info] <0.187.0> Waiting for Mnesia tables for 30000 ms, 9 retries left
2019-07-03 17:08:26.072 [info] <0.187.0> Peer discovery backend rabbit_peer_discovery_classic_config does not support registration, skipping registration.
2019-07-03 17:08:26.073 [error] <0.186.0> CRASH REPORT Process <0.186.0> with 0 neighbours exited with reason: no match of right hand value undefined in rabbit_priority_queue:enable/0 line 74 in application_master:init/4 line 134
2019-07-03 17:08:26.074 [info] <0.33.0> Application rabbit exited with reason: no match of right hand value undefined in rabbit_priority_queue:enable/0 line 74
{"Kernel pid terminated",application_controller,"{application_start_failure,rabbit,{bad_return,{{rabbit,start,[normal,[]]},{'EXIT',{{badmatch,undefined},[{rabbit_priority_queue,enable,0,[{file,\"src/rabbit_priority_queue.erl\"},{line,74}]},{rabbit_boot_steps,'-run_step/2-lc$^1/1-1-',1,[{file,\"src/rabbit_boot_steps.erl\"},{line,49}]},{rabbit_boot_steps,run_step,2,[{file,\"src/rabbit_boot_steps.erl\"},{line,49}]},{rabbit_boot_steps,'-run_boot_steps/1-lc$^0/1-0-',1,[{file,\"src/rabbit_boot_steps.erl\"},{line,26}]},{rabbit_boot_steps,run_boot_steps,1,[{file,\"src/rabbit_boot_steps.erl\"},{line,26}]},{rabbit,start,2,[{file,\"src/rabbit.erl\"},{line,793}]},{application_master,start_it_old,4,[{file,\"application_master.erl\"},{line,273}]}]}}}}}"}
Kernel pid terminated (application_controller) ({application_start_failure,rabbit,{bad_return,{{rabbit,start,[normal,[]]},{'EXIT',{{badmatch,undefined},[{rabbit_priority_queue,enable,0,[{file,"src/rab
epic_rabbitmq.0.ovt2eij5rr0r@im-pla-slave-1 |
Crash dump is being written to: /var/log/rabbitmq/erl_crash.dump...done
After restarting the container the following errors pop:
2019-07-03 17:09:21.171 [info] <0.33.0> Application lager started on node 'rabbit@rabbit-im-pla-slave-1'
2019-07-03 17:09:25.718 [info] <0.5.0> upgrades: Backing up mnesia dir to "/var/lib/rabbitmq/mnesia/rabbit@rabbit-im-pla-slave-1-upgrade-backup"
2019-07-03 17:09:25.731 [info] <0.5.0> upgrades: Mnesia dir backed up to "/var/lib/rabbitmq/mnesia/rabbit@rabbit-im-pla-slave-1-upgrade-backup"
2019-07-03 17:09:25.739 [info] <0.5.0> mnesia upgrades: 39 to apply
2019-07-03 17:09:25.828 [info] <0.33.0> Application mnesia started on node 'rabbit@rabbit-im-pla-slave-1'
2019-07-03 17:09:25.836 [info] <0.5.0> mnesia upgrades: Applying rabbit_upgrade_functions:topic_trie_node
2019-07-03 17:09:25.836 [error] <0.5.0>
Error description:
init:start_em/1
rabbit:start_it/1 line 445
rabbit:'-boot/0-fun-0-'/0 line 296
rabbit_upgrade:primary_upgrade/2 line 218
rabbit_upgrade:apply_upgrades/3 line 287
rabbit_upgrade:'-apply_upgrades/3-lc$^0/1-0-'/2 line 287
rabbit_upgrade:apply_upgrade/2 line 294
rabbit_upgrade_functions:create/2 line 626
error:{badmatch,{aborted,{already_exists,rabbit_topic_trie_node}}}
Log file(s) (may contain more information):
<stdout>
epic_rabbitmq.0.d93wu4coniaw@im-pla-slave-1 |
BOOT FAILED
===========
epic_rabbitmq.0.d93wu4coniaw@im-pla-slave-1 |
Error description:
init:start_em/1
rabbit:start_it/1 line 445
rabbit:'-boot/0-fun-0-'/0 line 296
rabbit_upgrade:primary_upgrade/2 line 218
rabbit_upgrade:apply_upgrades/3 line 287
rabbit_upgrade:'-apply_upgrades/3-lc$^0/1-0-'/2 line 287
rabbit_upgrade:apply_upgrade/2 line 294
rabbit_upgrade_functions:create/2 line 626
error:{badmatch,{aborted,{already_exists,rabbit_topic_trie_node}}}
Log file(s) (may contain more information):
<stdout>
epic_rabbitmq.0.d93wu4coniaw@im-pla-slave-1 |
{"init terminating in do_boot",{badmatch,{aborted,{already_exists,rabbit_topic_trie_node}}}}
init terminating in do_boot ({badmatch,{aborted,{already_exists,rabbit_topic_trie_node}}})
epic_rabbitmq.0.d93wu4coniaw@im-pla-slave-1 |
Crash dump is being written to: /var/log/rabbitmq/erl_crash.dump...done
After 3rd restart the following error pop and it pops again on subsequent restarts unless rabbitmq data is deleted and then RabbitMQ starts successfully (unless the the first error happens again and so on)
2019-07-03 17:10:17.641 [info] <0.33.0> Application lager started on node 'rabbit@rabbit-im-pla-slave-1'
2019-07-03 17:10:23.036 [error] <0.5.0> Found lock file at /var/lib/rabbitmq/mnesia/rabbit@rabbit-im-pla-slave-1/schema_upgrade_lock.
Either previous upgrade is in progress or has failed.
Database backup path: /var/lib/rabbitmq/mnesia/rabbit@rabbit-im-pla-slave-1-upgrade-backup
2019-07-03 17:10:23.037 [error] <0.5.0>
Error description:
init:do_boot/3
init:start_em/1
rabbit:start_it/1 line 445
rabbit:'-boot/0-fun-0-'/0 line 296
rabbit_upgrade:maybe_upgrade_mnesia/0 line 148
rabbit_upgrade:ensure_backup_taken/0 line 106
throw:{error,previous_upgrade_failed}
Log file(s) (may contain more information):
<stdout>
epic_rabbitmq.0.jh3ntyb6rtkd@im-pla-slave-1 |
BOOT FAILED
===========
epic_rabbitmq.0.jh3ntyb6rtkd@im-pla-slave-1 |
Error description:
init:do_boot/3
init:start_em/1
rabbit:start_it/1 line 445
rabbit:'-boot/0-fun-0-'/0 line 296
rabbit_upgrade:maybe_upgrade_mnesia/0 line 148
rabbit_upgrade:ensure_backup_taken/0 line 106
throw:{error,previous_upgrade_failed}
Log file(s) (may contain more information):
<stdout>
epic_rabbitmq.0.jh3ntyb6rtkd@im-pla-slave-1 |
init terminating in do_boot ({error,previous_upgrade_failed})
{"init terminating in do_boot",{error,previous_upgrade_failed}}
epic_rabbitmq.0.jh3ntyb6rtkd@im-pla-slave-1 |
Crash dump is being written to: /var/log/rabbitmq/erl_crash.dump...done
epic_rabbitmq.0.kksmf8yyn22m@im-pla-slave-1 | /paas-docker-entrypoint.sh: line 3: 6 Terminated sleep 18000
epic_rabbitmq.0.kksmf8yyn22m@im-pla-slave-1 | 2019-07-03 17:11:17.056 [info] <0.33.0> Application lager started on node 'rabbit@rabbit-im-pla-slave-1'
epic_rabbitmq.0.kksmf8yyn22m@im-pla-slave-1 | 2019-07-03 17:11:23.230 [error] <0.5.0> Found lock file at /var/lib/rabbitmq/mnesia/rabbit@rabbit-im-pla-slave-1/schema_upgrade_lock.
epic_rabbitmq.0.kksmf8yyn22m@im-pla-slave-1 | Either previous upgrade is in progress or has failed.
epic_rabbitmq.0.kksmf8yyn22m@im-pla-slave-1 | Database backup path: /var/lib/rabbitmq/mnesia/rabbit@rabbit-im-pla-slave-1-upgrade-backup
epic_rabbitmq.0.kksmf8yyn22m@im-pla-slave-1 | 2019-07-03 17:11:23.231 [error] <0.5.0>
epic_rabbitmq.0.kksmf8yyn22m@im-pla-slave-1 | Error description:
epic_rabbitmq.0.kksmf8yyn22m@im-pla-slave-1 | init:do_boot/3
epic_rabbitmq.0.kksmf8yyn22m@im-pla-slave-1 | init:start_em/1
epic_rabbitmq.0.kksmf8yyn22m@im-pla-slave-1 | rabbit:start_it/1 line 445
epic_rabbitmq.0.kksmf8yyn22m@im-pla-slave-1 | rabbit:'-boot/0-fun-0-'/0 line 296
epic_rabbitmq.0.kksmf8yyn22m@im-pla-slave-1 | rabbit_upgrade:maybe_upgrade_mnesia/0 line 148
epic_rabbitmq.0.kksmf8yyn22m@im-pla-slave-1 | rabbit_upgrade:ensure_backup_taken/0 line 106
epic_rabbitmq.0.kksmf8yyn22m@im-pla-slave-1 | throw:{error,previous_upgrade_failed}
epic_rabbitmq.0.kksmf8yyn22m@im-pla-slave-1 | Log file(s) (may contain more information):
epic_rabbitmq.0.kksmf8yyn22m@im-pla-slave-1 | <stdout>
Is there an environment issue or rabbitmq bug?
The same issue is reproduced in latest 3.7.16:
Starting RabbitMQ 3.7.16 on Erlang 22.0.5
Copyright (C) 2007-2019 Pivotal Software, Inc.
Licensed under the MPL. See https://www.rabbitmq.com/
## ##
## ## RabbitMQ 3.7.16. Copyright (C) 2007-2019 Pivotal Software, Inc.
########## Licensed under the MPL. See https://www.rabbitmq.com/
###### ##
########## Logs: <stdout>
Starting broker...
2019-07-09 08:42:06.664 [info] <0.222.0>
node : rabbit@rabbit-vm-centos74
home dir : /var/lib/rabbitmq
config file(s) : /etc/paasrabbitmq/paasrabbitmq.conf
cookie hash : Sqvm1ja/eeUKv+fi/FfMKg==
log(s) : <stdout>
database dir : /var/lib/rabbitmq/mnesia/rabbit@rabbit-vm-centos74
2019-07-09 08:42:09.950 [info] <0.222.0> Running boot step pre_boot defined by app rabbit
2019-07-09 08:42:09.950 [info] <0.222.0> Running boot step rabbit_core_metrics defined by app rabbit
2019-07-09 08:42:09.951 [info] <0.222.0> Running boot step rabbit_alarm defined by app rabbit
2019-07-09 08:42:09.972 [info] <0.234.0> Memory high watermark set to 12867 MiB (13492905574 bytes) of 32169 MiB (33732263936 bytes) total
2019-07-09 08:42:10.009 [info] <0.236.0> Enabling free disk space monitoring
2019-07-09 08:42:10.009 [info] <0.236.0> Disk free limit set to 50MB
2019-07-09 08:42:10.024 [info] <0.222.0> Running boot step code_server_cache defined by app rabbit
2019-07-09 08:42:10.025 [info] <0.222.0> Running boot step file_handle_cache defined by app rabbit
2019-07-09 08:42:10.025 [info] <0.240.0> FHC read buffering: OFF
2019-07-09 08:42:10.025 [info] <0.240.0> FHC write buffering: ON
2019-07-09 08:42:10.025 [info] <0.239.0> Limiting to approx 65436 file handles (58890 sockets)
2019-07-09 08:42:10.029 [info] <0.222.0> Running boot step worker_pool defined by app rabbit
2019-07-09 08:42:10.029 [info] <0.223.0> Will use 2 processes for default worker pool
2019-07-09 08:42:10.029 [info] <0.223.0> Starting worker pool 'worker_pool' with 2 processes in it
2019-07-09 08:42:10.029 [info] <0.222.0> Running boot step database defined by app rabbit
2019-07-09 08:42:10.030 [info] <0.222.0> Node database directory at /var/lib/rabbitmq/mnesia/rabbit@rabbit-vm-centos74 is empty. Assuming we need to join an existing cluster or initialise from scratch...
2019-07-09 08:42:10.030 [info] <0.222.0> Configured peer discovery backend: rabbit_peer_discovery_classic_config
2019-07-09 08:42:10.030 [info] <0.222.0> Will try to lock with peer discovery backend rabbit_peer_discovery_classic_config
2019-07-09 08:42:10.030 [info] <0.222.0> Peer discovery backend does not support locking, falling back to randomized delay
2019-07-09 08:42:10.030 [info] <0.222.0> Peer discovery backend rabbit_peer_discovery_classic_config does not support registration, skipping randomized startup delay.
2019-07-09 08:42:10.030 [info] <0.222.0> All discovered existing cluster peers:
2019-07-09 08:42:10.030 [info] <0.222.0> Discovered no peer nodes to cluster with
2019-07-09 08:42:10.035 [info] <0.43.0> Application mnesia exited with reason: stopped
2019-07-09 08:42:11.061 [info] <0.222.0> Waiting for Mnesia tables for 30000 ms, 9 retries left
2019-07-09 08:42:11.114 [info] <0.222.0> Waiting for Mnesia tables for 30000 ms, 9 retries left
2019-07-09 08:42:11.301 [info] <0.222.0> Waiting for Mnesia tables for 30000 ms, 9 retries left
2019-07-09 08:42:11.301 [info] <0.222.0> Peer discovery backend rabbit_peer_discovery_classic_config does not support registration, skipping registration.
2019-07-09 08:42:11.301 [info] <0.222.0> Running boot step database_sync defined by app rabbit
2019-07-09 08:42:11.302 [info] <0.222.0> Running boot step codec_correctness_check defined by app rabbit
2019-07-09 08:42:11.302 [info] <0.222.0> Running boot step external_infrastructure defined by app rabbit
2019-07-09 08:42:11.302 [info] <0.222.0> Running boot step rabbit_registry defined by app rabbit
2019-07-09 08:42:11.302 [info] <0.222.0> Running boot step rabbit_auth_mechanism_cr_demo defined by app rabbit
2019-07-09 08:42:11.302 [info] <0.222.0> Running boot step rabbit_queue_location_random defined by app rabbit
2019-07-09 08:42:11.302 [info] <0.222.0> Running boot step rabbit_event defined by app rabbit
2019-07-09 08:42:11.303 [info] <0.222.0> Running boot step rabbit_auth_mechanism_amqplain defined by app rabbit
2019-07-09 08:42:11.303 [info] <0.222.0> Running boot step rabbit_auth_mechanism_plain defined by app rabbit
2019-07-09 08:42:11.303 [info] <0.222.0> Running boot step rabbit_exchange_type_direct defined by app rabbit
2019-07-09 08:42:11.303 [info] <0.222.0> Running boot step rabbit_exchange_type_fanout defined by app rabbit
2019-07-09 08:42:11.303 [info] <0.222.0> Running boot step rabbit_exchange_type_headers defined by app rabbit
2019-07-09 08:42:11.304 [info] <0.222.0> Running boot step rabbit_exchange_type_topic defined by app rabbit
2019-07-09 08:42:11.304 [info] <0.222.0> Running boot step rabbit_mirror_queue_mode_all defined by app rabbit
2019-07-09 08:42:11.304 [info] <0.222.0> Running boot step rabbit_mirror_queue_mode_exactly defined by app rabbit
2019-07-09 08:42:11.304 [info] <0.222.0> Running boot step rabbit_mirror_queue_mode_nodes defined by app rabbit
2019-07-09 08:42:11.304 [info] <0.222.0> Running boot step rabbit_priority_queue defined by app rabbit
2019-07-09 08:42:11.305 [error] <0.221.0> CRASH REPORT Process <0.221.0> with 0 neighbours exited with reason: no match of right hand value undefined in rabbit_priority_queue:enable/0 line 74 in application_master:init/4 line 138
2019-07-09 08:42:11.305 [info] <0.43.0> Application rabbit exited with reason: no match of right hand value undefined in rabbit_priority_queue:enable/0 line 74
{"Kernel pid terminated",application_controller,"{application_start_failure,rabbit,{bad_return,{{rabbit,start,[normal,[]]},{'EXIT',{{badmatch,undefined},[{rabbit_priority_queue,enable,0,[{file,\"src/rabbit_priority_queue.erl\"},{line,74}]},{rabbit_boot_steps,'-run_step/2-lc$^1/1-1-',1,[{file,\"src/rabbit_boot_steps.erl\"},{line,55}]},{rabbit_boot_steps,run_step,2,[{file,\"src/rabbit_boot_steps.erl\"},{line,52}]},{rabbit_boot_steps,'-run_boot_steps/1-lc$^0/1-0-',1,[{file,\"src/rabbit_boot_steps.erl\"},{line,28}]},{rabbit_boot_steps,run_boot_steps,1,[{file,\"src/rabbit_boot_steps.erl\"},{line,26}]},{rabbit,start,2,[{file,\"src/rabbit.erl\"},{line,913}]},{application_master,start_it_old,4,[{file,\"application_master.erl\"},{line,277}]}]}}}}}"}
Kernel pid terminated (application_controller) ({application_start_failure,rabbit,{bad_return,{{rabbit,start,[normal,[]]},{'EXIT',{{badmatch,undefined},[{rabbit_priority_queue,enable,0,[{file,
"src/rab
