docker-library / rabbitmq

Docker Official Image packaging for RabbitMQ
http://www.rabbitmq.com/
MIT License
779 stars 412 forks source link

Management image no longer recognising management configuration options #402

Closed nick-george closed 4 years ago

nick-george commented 4 years ago

Hi,

The problem I'm facing appears identical to #362. The thing is, this docker image was previously working fine, but I can no longer get it to start. I'm using the 3.8.3-management image.

Something has happened to trigger this behaviour, although I'm not sure what. Here's the obligatory output.

BOOT FAILED
===========

Config file generation failed:
22:02:37.583 [error] You've tried to set management.ssl.port, but there is no setting with that name.
22:02:37.583 [error]   Did you mean one of these?
22:02:37.597 [error]     log.syslog.port
22:02:37.597 [error]     listeners.ssl
22:02:37.597 [error]     listeners.ssl.$name
22:02:37.597 [error] You've tried to set management.ssl.cacertfile, but there is no setting with that name.
22:02:37.597 [error]   Did you mean one of these?
22:02:37.613 [error]     ssl_options.cacertfile
22:02:37.613 [error]     max_message_size
22:02:37.613 [error]     ssl_options.certfile
22:02:37.613 [error] You've tried to set management.ssl.certfile, but there is no setting with that name.
22:02:37.613 [error]   Did you mean one of these?
22:02:37.629 [error]     ssl_options.certfile
22:02:37.629 [error]     max_message_size
22:02:37.629 [error]     ssl_options.cacertfile
22:02:37.629 [error] You've tried to set management.ssl.depth, but there is no setting with that name.
22:02:37.629 [error]   Did you mean one of these?
22:02:37.642 [error]     listeners.ssl.$name
22:02:37.642 [error]     ssl_options.depth
22:02:37.642 [error]     listeners.ssl
22:02:37.642 [error] You've tried to set management.ssl.fail_if_no_peer_cert, but there is no setting with that name.
22:02:37.642 [error]   Did you mean one of these?
22:02:37.664 [error]     ssl_options.fail_if_no_peer_cert
22:02:37.664 [error]     log.syslog.ssl_options.fail_if_no_peer_cert
22:02:37.664 [error]     credential_validator.regexp
22:02:37.665 [error] You've tried to set management.ssl.keyfile, but there is no setting with that name.
22:02:37.665 [error]   Did you mean one of these?
22:02:37.680 [error]     max_message_size
22:02:37.680 [error]     ssl_options.keyfile
22:02:37.680 [error]     listeners.ssl.$name
22:02:37.680 [error] You've tried to set management.ssl.verify, but there is no setting with that name.
22:02:37.680 [error]   Did you mean one of these?
22:02:37.694 [error]     ssl_options.verify
22:02:37.694 [error]     listeners.ssl.$name
22:02:37.694 [error]     max_message_size
22:02:37.694 [error] You've tried to set management.http_log_dir, but there is no setting with that name.
22:02:37.694 [error]   Did you mean one of these?
22:02:37.709 [error]     queue_master_locator
22:02:37.709 [error]     log.dir
22:02:37.709 [error]     log.syslog.ip
22:02:37.709 [error] Error generating configuration in phase transform_datatypes
22:02:37.709 [error] Conf file attempted to set unknown variable: management.http_log_dir
22:02:37.709 [error] Conf file attempted to set unknown variable: management.ssl.verify
22:02:37.709 [error] Conf file attempted to set unknown variable: management.ssl.keyfile
22:02:37.709 [error] Conf file attempted to set unknown variable: management.ssl.fail_if_no_peer_cert
22:02:37.709 [error] Conf file attempted to set unknown variable: management.ssl.depth
22:02:37.709 [error] Conf file attempted to set unknown variable: management.ssl.certfile
22:02:37.709 [error] Conf file attempted to set unknown variable: management.ssl.cacertfile
22:02:37.709 [error] Conf file attempted to set unknown variable: management.ssl.port
In case the setting comes from a plugin, make sure that the plugin is enabled.
Alternatively remove the setting from the config.

{"init terminating in do_boot",generate_config_file}
init terminating in do_boot (generate_config_file)

Crash dump is being written to: /var/log/rabbitmq/erl_crash.dump...done

Here's my rabbitmq.conf

log.file = /var/log/rabbitmq/rabbitmq.log
log.file.level = debug
loopback_users.guest = false
listeners.ssl.default = 5671
ssl_options.cacertfile = /etc/rabbitmq/mgmt_ca_bundle.crt
ssl_options.certfile = /etc/rabbitmq/rabbitmq-server.crt
ssl_options.depth = 10
ssl_options.fail_if_no_peer_cert = true
ssl_options.keyfile = /etc/rabbitmq/rabbitmq-server.key
ssl_options.verify = verify_peer
management.ssl.port = 15671
management.ssl.cacertfile = /etc/rabbitmq/mgmt_ca_bundle.crt
management.ssl.certfile = /etc/rabbitmq/rabbitmq-server.crt
management.ssl.depth = 10
management.ssl.fail_if_no_peer_cert = true
management.ssl.keyfile = /etc/rabbitmq/rabbitmq-server.key
management.ssl.verify = verify_peer
management.http_log_dir = /var/log/rabbitmq

Is there the possibility that there is some kind of race condition between getting the schema file in place vs reading the configuration file? Note that I'm mounting the host system's /etc/rabbitmq into the container's filesystem at the same location (-v /etc/rabbitmq:/etc/rabbitmq)

I guess I will have to run the non-management version of the container until there is some kind of solution.

Many thanks, Nick

wglambert commented 4 years ago

I'm not able to reproduce, I've changed the ssl file locations to match the ssl generation script here https://github.com/docker-library/rabbitmq/issues/362#issuecomment-528609237

rabbitmq.conf

$ cat rabbitmq.conf 
log.file = /var/log/rabbitmq/rabbitmq.log
log.file.level = debug
loopback_users.guest = false
listeners.ssl.default = 5671
ssl_options.cacertfile = /etc/rabbitmq-secret/ca
ssl_options.certfile = /etc/rabbitmq-secret/cert
ssl_options.depth = 10
ssl_options.fail_if_no_peer_cert = true
ssl_options.keyfile = /etc/rabbitmq-secret/key
ssl_options.verify = verify_peer
management.ssl.port = 15671
management.ssl.cacertfile = /etc/rabbitmq-secret/ca
management.ssl.certfile = /etc/rabbitmq-secret/cert
management.ssl.depth = 10
management.ssl.fail_if_no_peer_cert = true
management.ssl.keyfile = /etc/rabbitmq-secret/key
management.ssl.verify = verify_peer
management.http_log_dir = /var/log/rabbitmq

Docker build

$ docker build . -t rabbitmq:test
Sending build context to Docker daemon  352.8MB
Step 1/3 : FROM rabbitmq:3-management
 ---> 30e33de9be86
Step 2/3 : RUN set -eux;        mkdir /etc/rabbitmq-secret;     openssl genrsa -out /etc/rabbitmq-secret/ca-key 8192;   openssl req -new -x509          -key /etc/rabbitmq-secret/ca-key               -out /etc/rabbitmq-secret/ca            -days $(( 365 * 30 ))           -subj '/CN=lolca';      openssl genrsa -out /etc/rabbitmq-secret/key 4096;    openssl req -new -key /etc/rabbitmq-secret/key           -out /etc/rabbitmq-secret/cert.csr -subj '/CN=lolcert';         openssl x509 -req -in /etc/rabbitmq-secret/cert.csr   -CA /etc/rabbitmq-secret/ca -CAkey /etc/rabbitmq-secret/ca-key -CAcreateserial           -out /etc/rabbitmq-secret/cert -days $(( 365 * 30 ));   openssl verify -CAfile /etc/rabbitmq-secret/ca /etc/rabbitmq-secret/cert;      chown -R rabbitmq:rabbitmq /etc/rabbitmq-secret
 ---> Running in a671c1223626
+ mkdir /etc/rabbitmq-secret
+ openssl genrsa -out /etc/rabbitmq-secret/ca-key 8192
Generating RSA private key, 8192 bit long modulus (2 primes)
..........................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................+++
.........................................................................................................................................................................................................................................................................................................................................................................................+++
e is 65537 (0x010001)
+ openssl req -new -x509 -key /etc/rabbitmq-secret/ca-key -out /etc/rabbitmq-secret/ca -days 10950 -subj /CN=lolca
+ openssl genrsa -out /etc/rabbitmq-secret/key 4096
Generating RSA private key, 4096 bit long modulus (2 primes)
................++++
..++++
e is 65537 (0x010001)
+ openssl req -new -key /etc/rabbitmq-secret/key -out /etc/rabbitmq-secret/cert.csr -subj /CN=lolcert
+ openssl x509 -req -in /etc/rabbitmq-secret/cert.csr -CA /etc/rabbitmq-secret/ca -CAkey /etc/rabbitmq-secret/ca-key -CAcreateserial -out /etc/rabbitmq-secret/cert -days 10950
Signature ok
subject=CN = lolcert
Getting CA Private Key
+ openssl verify -CAfile /etc/rabbitmq-secret/ca /etc/rabbitmq-secret/cert
/etc/rabbitmq-secret/cert: OK
+ chown -R rabbitmq:rabbitmq /etc/rabbitmq-secret
Removing intermediate container a671c1223626
 ---> ebc6246c3ae5
Step 3/3 : COPY rabbitmq.conf /etc/rabbitmq/
 ---> 61c292dfa187
Successfully built 61c292dfa187
Successfully tagged rabbitmq:test
$ docker run -d --name rabbit rabbitmq:test
dfedfbae5ca7db4f361f3ccbe8309bd8adcfc69eede9e1c5e9b59e306656bfd0

$ docker logs -f rabbit
2020-04-20 16:38:14.553 [info] <0.9.0> Feature flags: list of feature flags found:
2020-04-20 16:38:14.553 [info] <0.9.0> Feature flags:   [ ] drop_unroutable_metric
2020-04-20 16:38:14.554 [info] <0.9.0> Feature flags:   [ ] empty_basic_get_metric
2020-04-20 16:38:14.554 [info] <0.9.0> Feature flags:   [ ] implicit_default_bindings
2020-04-20 16:38:14.554 [info] <0.9.0> Feature flags:   [ ] quorum_queue
2020-04-20 16:38:14.554 [info] <0.9.0> Feature flags:   [ ] virtual_host_metadata
2020-04-20 16:38:14.554 [info] <0.9.0> Feature flags: feature flag states written to disk: yes
2020-04-20 16:38:14.582 [info] <0.269.0> ra: meta data store initialised. 0 record(s) recovered
2020-04-20 16:38:14.582 [info] <0.274.0> WAL: recovering []
2020-04-20 16:38:14.584 [info] <0.278.0> 
 Starting RabbitMQ 3.8.3 on Erlang 22.3.2
 Copyright (c) 2007-2020 Pivotal Software, Inc.
 Licensed under the MPL 1.1. Website: https://rabbitmq.com

  ##  ##      RabbitMQ 3.8.3
  ##  ##
  ##########  Copyright (c) 2007-2020 Pivotal Software, Inc.
  ######  ##
  ##########  Licensed under the MPL 1.1. Website: https://rabbitmq.com

  Doc guides: https://rabbitmq.com/documentation.html
  Support:    https://rabbitmq.com/contact.html
  Tutorials:  https://rabbitmq.com/getstarted.html
  Monitoring: https://rabbitmq.com/monitoring.html

  Logs: <stdout>

  Config file(s): /etc/rabbitmq/rabbitmq.conf

  Starting broker...2020-04-20 16:38:14.585 [info] <0.278.0> 
 node           : rabbit@dfedfbae5ca7
 home dir       : /var/lib/rabbitmq
 config file(s) : /etc/rabbitmq/rabbitmq.conf
 cookie hash    : 8Z6KeFFnUgCbIHuZBuqUwQ==
 log(s)         : <stdout>
 database dir   : /var/lib/rabbitmq/mnesia/rabbit@dfedfbae5ca7
2020-04-20 16:38:14.605 [info] <0.278.0> Running boot step pre_boot defined by app rabbit
2020-04-20 16:38:14.605 [info] <0.278.0> Running boot step rabbit_core_metrics defined by app rabbit
2020-04-20 16:38:14.606 [info] <0.278.0> Running boot step rabbit_alarm defined by app rabbit
2020-04-20 16:38:14.613 [info] <0.284.0> Memory high watermark set to 12863 MiB (13488129638 bytes) of 32158 MiB (33720324096 bytes) total
2020-04-20 16:38:14.622 [info] <0.286.0> Enabling free disk space monitoring
2020-04-20 16:38:14.622 [info] <0.286.0> Disk free limit set to 50MB
2020-04-20 16:38:14.626 [info] <0.278.0> Running boot step code_server_cache defined by app rabbit
2020-04-20 16:38:14.626 [info] <0.278.0> Running boot step file_handle_cache defined by app rabbit
2020-04-20 16:38:14.626 [info] <0.289.0> Limiting to approx 1048479 file handles (943629 sockets)
2020-04-20 16:38:14.626 [info] <0.290.0> FHC read buffering:  OFF
2020-04-20 16:38:14.626 [info] <0.290.0> FHC write buffering: ON
2020-04-20 16:38:14.627 [info] <0.278.0> Running boot step worker_pool defined by app rabbit
2020-04-20 16:38:14.627 [info] <0.279.0> Will use 8 processes for default worker pool
2020-04-20 16:38:14.627 [info] <0.279.0> Starting worker pool 'worker_pool' with 8 processes in it
2020-04-20 16:38:14.628 [info] <0.278.0> Running boot step database defined by app rabbit
2020-04-20 16:38:14.628 [info] <0.278.0> Node database directory at /var/lib/rabbitmq/mnesia/rabbit@dfedfbae5ca7 is empty. Assuming we need to join an existing cluster or initialise from scratch...
2020-04-20 16:38:14.628 [info] <0.278.0> Configured peer discovery backend: rabbit_peer_discovery_classic_config
2020-04-20 16:38:14.628 [info] <0.278.0> Will try to lock with peer discovery backend rabbit_peer_discovery_classic_config
2020-04-20 16:38:14.628 [info] <0.278.0> Peer discovery backend does not support locking, falling back to randomized delay
2020-04-20 16:38:14.628 [info] <0.278.0> Peer discovery backend rabbit_peer_discovery_classic_config does not support registration, skipping randomized startup delay.
2020-04-20 16:38:14.628 [info] <0.278.0> All discovered existing cluster peers: 
2020-04-20 16:38:14.628 [info] <0.278.0> Discovered no peer nodes to cluster with. Some discovery backends can filter nodes out based on a readiness criteria. Enabling debug logging might help troubleshoot.
2020-04-20 16:38:14.631 [info] <0.44.0> Application mnesia exited with reason: stopped
2020-04-20 16:38:14.717 [info] <0.278.0> Waiting for Mnesia tables for 30000 ms, 9 retries left
2020-04-20 16:38:14.754 [info] <0.278.0> Waiting for Mnesia tables for 30000 ms, 9 retries left
2020-04-20 16:38:14.754 [info] <0.278.0> Feature flag `drop_unroutable_metric`: supported, attempt to enable...
2020-04-20 16:38:14.754 [info] <0.278.0> Feature flag `drop_unroutable_metric`: mark as enabled=state_changing
2020-04-20 16:38:14.769 [info] <0.278.0> Feature flags: list of feature flags found:
2020-04-20 16:38:14.769 [info] <0.278.0> Feature flags:   [~] drop_unroutable_metric
2020-04-20 16:38:14.769 [info] <0.278.0> Feature flags:   [ ] empty_basic_get_metric
2020-04-20 16:38:14.769 [info] <0.278.0> Feature flags:   [ ] implicit_default_bindings
2020-04-20 16:38:14.769 [info] <0.278.0> Feature flags:   [ ] quorum_queue
2020-04-20 16:38:14.769 [info] <0.278.0> Feature flags:   [ ] virtual_host_metadata
2020-04-20 16:38:14.769 [info] <0.278.0> Feature flags: feature flag states written to disk: yes
2020-04-20 16:38:14.784 [info] <0.278.0> Feature flag `drop_unroutable_metric`: mark as enabled=true
2020-04-20 16:38:14.802 [info] <0.278.0> Feature flags: list of feature flags found:
2020-04-20 16:38:14.802 [info] <0.278.0> Feature flags:   [x] drop_unroutable_metric
2020-04-20 16:38:14.802 [info] <0.278.0> Feature flags:   [ ] empty_basic_get_metric
2020-04-20 16:38:14.802 [info] <0.278.0> Feature flags:   [ ] implicit_default_bindings
2020-04-20 16:38:14.802 [info] <0.278.0> Feature flags:   [ ] quorum_queue
2020-04-20 16:38:14.802 [info] <0.278.0> Feature flags:   [ ] virtual_host_metadata
2020-04-20 16:38:14.802 [info] <0.278.0> Feature flags: feature flag states written to disk: yes
2020-04-20 16:38:14.815 [info] <0.278.0> Feature flag `empty_basic_get_metric`: supported, attempt to enable...
2020-04-20 16:38:14.815 [info] <0.278.0> Feature flag `empty_basic_get_metric`: mark as enabled=state_changing
2020-04-20 16:38:14.835 [info] <0.278.0> Feature flags: list of feature flags found:
2020-04-20 16:38:14.835 [info] <0.278.0> Feature flags:   [x] drop_unroutable_metric
2020-04-20 16:38:14.835 [info] <0.278.0> Feature flags:   [~] empty_basic_get_metric
2020-04-20 16:38:14.835 [info] <0.278.0> Feature flags:   [ ] implicit_default_bindings
2020-04-20 16:38:14.835 [info] <0.278.0> Feature flags:   [ ] quorum_queue
2020-04-20 16:38:14.835 [info] <0.278.0> Feature flags:   [ ] virtual_host_metadata
2020-04-20 16:38:14.835 [info] <0.278.0> Feature flags: feature flag states written to disk: yes
2020-04-20 16:38:14.848 [info] <0.278.0> Feature flag `empty_basic_get_metric`: mark as enabled=true
2020-04-20 16:38:14.866 [info] <0.278.0> Feature flags: list of feature flags found:
2020-04-20 16:38:14.866 [info] <0.278.0> Feature flags:   [x] drop_unroutable_metric
2020-04-20 16:38:14.866 [info] <0.278.0> Feature flags:   [x] empty_basic_get_metric
2020-04-20 16:38:14.866 [info] <0.278.0> Feature flags:   [ ] implicit_default_bindings
2020-04-20 16:38:14.866 [info] <0.278.0> Feature flags:   [ ] quorum_queue
2020-04-20 16:38:14.866 [info] <0.278.0> Feature flags:   [ ] virtual_host_metadata
2020-04-20 16:38:14.866 [info] <0.278.0> Feature flags: feature flag states written to disk: yes
2020-04-20 16:38:14.877 [info] <0.278.0> Feature flag `implicit_default_bindings`: supported, attempt to enable...
2020-04-20 16:38:14.877 [info] <0.278.0> Feature flag `implicit_default_bindings`: mark as enabled=state_changing
2020-04-20 16:38:14.902 [info] <0.278.0> Feature flags: list of feature flags found:
2020-04-20 16:38:14.902 [info] <0.278.0> Feature flags:   [x] drop_unroutable_metric
2020-04-20 16:38:14.902 [info] <0.278.0> Feature flags:   [x] empty_basic_get_metric
2020-04-20 16:38:14.902 [info] <0.278.0> Feature flags:   [~] implicit_default_bindings
2020-04-20 16:38:14.902 [info] <0.278.0> Feature flags:   [ ] quorum_queue
2020-04-20 16:38:14.903 [info] <0.278.0> Feature flags:   [ ] virtual_host_metadata
2020-04-20 16:38:14.903 [info] <0.278.0> Feature flags: feature flag states written to disk: yes
2020-04-20 16:38:14.915 [info] <0.278.0> Waiting for Mnesia tables for 30000 ms, 0 retries left
2020-04-20 16:38:14.916 [info] <0.278.0> Feature flag `implicit_default_bindings`: mark as enabled=true
2020-04-20 16:38:14.930 [info] <0.278.0> Feature flags: list of feature flags found:
2020-04-20 16:38:14.930 [info] <0.278.0> Feature flags:   [x] drop_unroutable_metric
2020-04-20 16:38:14.931 [info] <0.278.0> Feature flags:   [x] empty_basic_get_metric
2020-04-20 16:38:14.931 [info] <0.278.0> Feature flags:   [x] implicit_default_bindings
2020-04-20 16:38:14.931 [info] <0.278.0> Feature flags:   [ ] quorum_queue
2020-04-20 16:38:14.931 [info] <0.278.0> Feature flags:   [ ] virtual_host_metadata
2020-04-20 16:38:14.931 [info] <0.278.0> Feature flags: feature flag states written to disk: yes
2020-04-20 16:38:14.943 [info] <0.278.0> Feature flag `quorum_queue`: supported, attempt to enable...
2020-04-20 16:38:14.943 [info] <0.278.0> Feature flag `quorum_queue`: mark as enabled=state_changing
2020-04-20 16:38:14.956 [info] <0.278.0> Feature flags: list of feature flags found:
2020-04-20 16:38:14.956 [info] <0.278.0> Feature flags:   [x] drop_unroutable_metric
2020-04-20 16:38:14.956 [info] <0.278.0> Feature flags:   [x] empty_basic_get_metric
2020-04-20 16:38:14.956 [info] <0.278.0> Feature flags:   [x] implicit_default_bindings
2020-04-20 16:38:14.956 [info] <0.278.0> Feature flags:   [~] quorum_queue
2020-04-20 16:38:14.956 [info] <0.278.0> Feature flags:   [ ] virtual_host_metadata
2020-04-20 16:38:14.956 [info] <0.278.0> Feature flags: feature flag states written to disk: yes
2020-04-20 16:38:14.966 [info] <0.278.0> Waiting for Mnesia tables for 30000 ms, 9 retries left
2020-04-20 16:38:14.966 [info] <0.278.0> Feature flag `quorum_queue`:   migrating Mnesia table rabbit_queue...
2020-04-20 16:38:14.977 [info] <0.278.0> Feature flag `quorum_queue`:   migrating Mnesia table rabbit_durable_queue...
2020-04-20 16:38:14.985 [info] <0.278.0> Feature flag `quorum_queue`:   Mnesia tables migration done
2020-04-20 16:38:14.985 [info] <0.278.0> Feature flag `quorum_queue`: mark as enabled=true
2020-04-20 16:38:15.004 [info] <0.278.0> Feature flags: list of feature flags found:
2020-04-20 16:38:15.004 [info] <0.278.0> Feature flags:   [x] drop_unroutable_metric
2020-04-20 16:38:15.004 [info] <0.278.0> Feature flags:   [x] empty_basic_get_metric
2020-04-20 16:38:15.004 [info] <0.278.0> Feature flags:   [x] implicit_default_bindings
2020-04-20 16:38:15.004 [info] <0.278.0> Feature flags:   [x] quorum_queue
2020-04-20 16:38:15.004 [info] <0.278.0> Feature flags:   [ ] virtual_host_metadata
2020-04-20 16:38:15.004 [info] <0.278.0> Feature flags: feature flag states written to disk: yes
2020-04-20 16:38:15.018 [info] <0.278.0> Feature flag `virtual_host_metadata`: supported, attempt to enable...
2020-04-20 16:38:15.018 [info] <0.278.0> Feature flag `virtual_host_metadata`: mark as enabled=state_changing
2020-04-20 16:38:15.035 [info] <0.278.0> Feature flags: list of feature flags found:
2020-04-20 16:38:15.035 [info] <0.278.0> Feature flags:   [x] drop_unroutable_metric
2020-04-20 16:38:15.035 [info] <0.278.0> Feature flags:   [x] empty_basic_get_metric
2020-04-20 16:38:15.035 [info] <0.278.0> Feature flags:   [x] implicit_default_bindings
2020-04-20 16:38:15.035 [info] <0.278.0> Feature flags:   [x] quorum_queue
2020-04-20 16:38:15.035 [info] <0.278.0> Feature flags:   [~] virtual_host_metadata
2020-04-20 16:38:15.035 [info] <0.278.0> Feature flags: feature flag states written to disk: yes
2020-04-20 16:38:15.052 [info] <0.278.0> Waiting for Mnesia tables for 30000 ms, 9 retries left
2020-04-20 16:38:15.061 [info] <0.278.0> Feature flag `virtual_host_metadata`: mark as enabled=true
2020-04-20 16:38:15.081 [info] <0.278.0> Feature flags: list of feature flags found:
2020-04-20 16:38:15.081 [info] <0.278.0> Feature flags:   [x] drop_unroutable_metric
2020-04-20 16:38:15.081 [info] <0.278.0> Feature flags:   [x] empty_basic_get_metric
2020-04-20 16:38:15.081 [info] <0.278.0> Feature flags:   [x] implicit_default_bindings
2020-04-20 16:38:15.081 [info] <0.278.0> Feature flags:   [x] quorum_queue
2020-04-20 16:38:15.081 [info] <0.278.0> Feature flags:   [x] virtual_host_metadata
2020-04-20 16:38:15.081 [info] <0.278.0> Feature flags: feature flag states written to disk: yes
2020-04-20 16:38:15.096 [info] <0.278.0> Waiting for Mnesia tables for 30000 ms, 9 retries left
2020-04-20 16:38:15.140 [info] <0.278.0> Waiting for Mnesia tables for 30000 ms, 9 retries left
2020-04-20 16:38:15.140 [info] <0.278.0> Peer discovery backend rabbit_peer_discovery_classic_config does not support registration, skipping registration.
2020-04-20 16:38:15.140 [info] <0.278.0> Running boot step database_sync defined by app rabbit
2020-04-20 16:38:15.141 [info] <0.278.0> Running boot step feature_flags defined by app rabbit
2020-04-20 16:38:15.141 [info] <0.278.0> Running boot step codec_correctness_check defined by app rabbit
2020-04-20 16:38:15.141 [info] <0.278.0> Running boot step external_infrastructure defined by app rabbit
2020-04-20 16:38:15.141 [info] <0.278.0> Running boot step rabbit_registry defined by app rabbit
2020-04-20 16:38:15.141 [info] <0.278.0> Running boot step rabbit_auth_mechanism_cr_demo defined by app rabbit
2020-04-20 16:38:15.141 [info] <0.278.0> Running boot step rabbit_queue_location_random defined by app rabbit
2020-04-20 16:38:15.141 [info] <0.278.0> Running boot step rabbit_event defined by app rabbit
2020-04-20 16:38:15.142 [info] <0.278.0> Running boot step rabbit_auth_mechanism_amqplain defined by app rabbit
2020-04-20 16:38:15.142 [info] <0.278.0> Running boot step rabbit_auth_mechanism_plain defined by app rabbit
2020-04-20 16:38:15.143 [info] <0.278.0> Running boot step rabbit_exchange_type_direct defined by app rabbit
2020-04-20 16:38:15.143 [info] <0.278.0> Running boot step rabbit_exchange_type_fanout defined by app rabbit
2020-04-20 16:38:15.143 [info] <0.278.0> Running boot step rabbit_exchange_type_headers defined by app rabbit
2020-04-20 16:38:15.144 [info] <0.278.0> Running boot step rabbit_exchange_type_topic defined by app rabbit
2020-04-20 16:38:15.144 [info] <0.278.0> Running boot step rabbit_mirror_queue_mode_all defined by app rabbit
2020-04-20 16:38:15.144 [info] <0.278.0> Running boot step rabbit_mirror_queue_mode_exactly defined by app rabbit
2020-04-20 16:38:15.145 [info] <0.278.0> Running boot step rabbit_mirror_queue_mode_nodes defined by app rabbit
2020-04-20 16:38:15.145 [info] <0.278.0> Running boot step rabbit_priority_queue defined by app rabbit
2020-04-20 16:38:15.145 [info] <0.278.0> Priority queues enabled, real BQ is rabbit_variable_queue
2020-04-20 16:38:15.146 [info] <0.278.0> Running boot step rabbit_queue_location_client_local defined by app rabbit
2020-04-20 16:38:15.146 [info] <0.278.0> Running boot step rabbit_queue_location_min_masters defined by app rabbit
2020-04-20 16:38:15.146 [info] <0.278.0> Running boot step kernel_ready defined by app rabbit
2020-04-20 16:38:15.146 [info] <0.278.0> Running boot step rabbit_sysmon_minder defined by app rabbit
2020-04-20 16:38:15.147 [info] <0.278.0> Running boot step rabbit_epmd_monitor defined by app rabbit
2020-04-20 16:38:15.151 [info] <0.524.0> epmd monitor knows us, inter-node communication (distribution) port: 25672
2020-04-20 16:38:15.151 [info] <0.278.0> Running boot step guid_generator defined by app rabbit
2020-04-20 16:38:15.153 [info] <0.278.0> Running boot step rabbit_node_monitor defined by app rabbit
2020-04-20 16:38:15.153 [info] <0.530.0> Starting rabbit_node_monitor
2020-04-20 16:38:15.154 [info] <0.278.0> Running boot step delegate_sup defined by app rabbit
2020-04-20 16:38:15.155 [info] <0.278.0> Running boot step rabbit_memory_monitor defined by app rabbit
2020-04-20 16:38:15.155 [info] <0.278.0> Running boot step core_initialized defined by app rabbit
2020-04-20 16:38:15.155 [info] <0.278.0> Running boot step upgrade_queues defined by app rabbit
2020-04-20 16:38:15.199 [info] <0.278.0> message_store upgrades: 1 to apply
2020-04-20 16:38:15.199 [info] <0.278.0> message_store upgrades: Applying rabbit_variable_queue:move_messages_to_vhost_store
2020-04-20 16:38:15.199 [info] <0.278.0> message_store upgrades: No durable queues found. Skipping message store migration
2020-04-20 16:38:15.199 [info] <0.278.0> message_store upgrades: Removing the old message store data
2020-04-20 16:38:15.201 [info] <0.278.0> message_store upgrades: All upgrades applied successfully
2020-04-20 16:38:15.241 [info] <0.278.0> Running boot step rabbit_connection_tracking defined by app rabbit
2020-04-20 16:38:15.241 [info] <0.278.0> Running boot step rabbit_connection_tracking_handler defined by app rabbit
2020-04-20 16:38:15.241 [info] <0.278.0> Running boot step rabbit_exchange_parameters defined by app rabbit
2020-04-20 16:38:15.242 [info] <0.278.0> Running boot step rabbit_mirror_queue_misc defined by app rabbit
2020-04-20 16:38:15.243 [info] <0.278.0> Running boot step rabbit_policies defined by app rabbit
2020-04-20 16:38:15.245 [info] <0.278.0> Running boot step rabbit_policy defined by app rabbit
2020-04-20 16:38:15.245 [info] <0.278.0> Running boot step rabbit_queue_location_validator defined by app rabbit
2020-04-20 16:38:15.245 [info] <0.278.0> Running boot step rabbit_quorum_memory_manager defined by app rabbit
2020-04-20 16:38:15.245 [info] <0.278.0> Running boot step rabbit_vhost_limit defined by app rabbit
2020-04-20 16:38:15.245 [info] <0.278.0> Running boot step rabbit_mgmt_reset_handler defined by app rabbitmq_management
2020-04-20 16:38:15.246 [info] <0.278.0> Running boot step rabbit_mgmt_db_handler defined by app rabbitmq_management_agent
2020-04-20 16:38:15.246 [info] <0.278.0> Management plugin: using rates mode 'basic'
2020-04-20 16:38:15.247 [info] <0.278.0> Running boot step recovery defined by app rabbit
2020-04-20 16:38:15.248 [info] <0.278.0> Running boot step load_core_definitions defined by app rabbit
2020-04-20 16:38:15.248 [info] <0.278.0> Running boot step empty_db_check defined by app rabbit
2020-04-20 16:38:15.248 [info] <0.278.0> Adding vhost '/' (description: 'Default virtual host')
2020-04-20 16:38:15.260 [info] <0.571.0> Making sure data directory '/var/lib/rabbitmq/mnesia/rabbit@dfedfbae5ca7/msg_stores/vhosts/628WB79CIFDYO9LJI6DKMI09L' for vhost '/' exists
2020-04-20 16:38:15.279 [info] <0.571.0> Starting message stores for vhost '/'
2020-04-20 16:38:15.279 [info] <0.575.0> Message store "628WB79CIFDYO9LJI6DKMI09L/msg_store_transient": using rabbit_msg_store_ets_index to provide index
2020-04-20 16:38:15.282 [info] <0.571.0> Started message store of type transient for vhost '/'
2020-04-20 16:38:15.283 [info] <0.578.0> Message store "628WB79CIFDYO9LJI6DKMI09L/msg_store_persistent": using rabbit_msg_store_ets_index to provide index
2020-04-20 16:38:15.284 [warning] <0.578.0> Message store "628WB79CIFDYO9LJI6DKMI09L/msg_store_persistent": rebuilding indices from scratch
2020-04-20 16:38:15.285 [info] <0.571.0> Started message store of type persistent for vhost '/'
2020-04-20 16:38:15.289 [info] <0.278.0> Creating user 'guest'
2020-04-20 16:38:15.290 [info] <0.278.0> Setting user tags for user 'guest' to [administrator]
2020-04-20 16:38:15.292 [info] <0.278.0> Setting permissions for 'guest' in '/' to '.*', '.*', '.*'
2020-04-20 16:38:15.293 [info] <0.278.0> Running boot step rabbit_looking_glass defined by app rabbit
2020-04-20 16:38:15.293 [info] <0.278.0> Running boot step rabbit_core_metrics_gc defined by app rabbit
2020-04-20 16:38:15.294 [info] <0.278.0> Running boot step background_gc defined by app rabbit
2020-04-20 16:38:15.294 [info] <0.278.0> Running boot step connection_tracking defined by app rabbit
2020-04-20 16:38:15.297 [info] <0.278.0> Setting up a table for connection tracking on this node: tracked_connection_on_node_rabbit@dfedfbae5ca7
2020-04-20 16:38:15.302 [info] <0.278.0> Setting up a table for per-vhost connection counting on this node: tracked_connection_per_vhost_on_node_rabbit@dfedfbae5ca7
2020-04-20 16:38:15.302 [info] <0.278.0> Running boot step routing_ready defined by app rabbit
2020-04-20 16:38:15.303 [info] <0.278.0> Running boot step pre_flight defined by app rabbit
2020-04-20 16:38:15.303 [info] <0.278.0> Running boot step notify_cluster defined by app rabbit
2020-04-20 16:38:15.303 [info] <0.278.0> Running boot step networking defined by app rabbit
2020-04-20 16:38:15.307 [info] <0.624.0> started TCP listener on [::]:5672
2020-04-20 16:38:15.309 [info] <0.640.0> started TLS (SSL) listener on [::]:5671
2020-04-20 16:38:15.310 [info] <0.278.0> Running boot step cluster_name defined by app rabbit
2020-04-20 16:38:15.310 [info] <0.278.0> Initialising internal cluster ID to 'rabbitmq-cluster-id-1kHk4rtALrDzS9nMZlXMUw'
2020-04-20 16:38:15.311 [info] <0.278.0> Running boot step direct_client defined by app rabbit
2020-04-20 16:38:15.311 [info] <0.278.0> Running boot step os_signal_handler defined by app rabbit
2020-04-20 16:38:15.311 [info] <0.643.0> Swapping OS signal event handler (erl_signal_server) for our own
2020-04-20 16:38:15.371 [info] <0.693.0> Management plugin: HTTPS listener started on port 15671
2020-04-20 16:38:15.372 [info] <0.800.0> Statistics database started.
2020-04-20 16:38:15.372 [info] <0.799.0> Starting worker pool 'management_worker_pool' with 3 processes in it
2020-04-20 16:38:15.373 [info] <0.690.0> opening log file: "/var/log/rabbitmq/access.log.2020_04_20_16"
2020-04-20 16:38:15.614 [info] <0.9.0> Server startup complete; 3 plugins started.
 * rabbitmq_management
 * rabbitmq_web_dispatch
 * rabbitmq_management_agent
 completed with 3 plugins.
nick-george commented 4 years ago

Not sure if it helps, but I have two identically configured instances of RabbitMQ on two different servers. One is working, one isn't.

Working server: OS: Oracle Linux Server release 7.8 Docker Version: docker-engine-19.03.1.ol-1.0.0.el7.x86_64 Kernel Version: 4.14.35-1902.301.1.el7uek.x86_64 Docker image: 30e33de9be86

Failing server OS: Amazon Linux release 2 (Karoo) Docker Version: docker-19.03.6ce-1.amzn2.x86_64 Kernel Version: 4.14.173-137.229.amzn2.x86_64 Docker image: 30e33de9be86

Rabbitmq.conf is exactly the same as what I posted above (for both servers). However, the content of the server cert + key is different for each. The CAfiles are the same. I use Puppet to configure docker and the container on both servers. I'm wondering if there's maybe some side-effect of using the AWS Kernel that is causing the issue? Have you done your testing on AWS?

Thanks, Nick

lukebakken commented 4 years ago

Usually, this error is due to the rabbitmq_management plugin not being enabled:

22:02:37.583 [error] You've tried to set management.ssl.port, but there is no setting with that name.

I am assuming it should be enabled by default with this Docker image, but perhaps Puppet is changing the /etc/rabbitmq/enabled_plugins file behind your back @nick-george

nick-george commented 4 years ago

Hi Luke,

You are correct. The enabled_plugins file wasn't there. I don't know how/why this is the case. I would have thought that the docker image would make sure this file was there on startup.

I'll use puppet to ensure the file is there.

Cheers, Nick

lukebakken commented 4 years ago

I suspect that enabled_plugins is there and somehow Puppet is deleting it. I don't have access to docker to check the contents of this image, however.

nick-george commented 4 years ago

Maybe it has something to do with the fact that I am using /etc/rabbitmq as a docker volume in order to provide the certs and rabbitmq.conf. It looks like rabbitmq.conf gets generated by the docker image startup script based on environment variables (if it doesn't already exist), but the enabled_plugins file does not (no amount of restarting the image would bring the file back)

Cheers, Nick