Gracefully shutdown on docker stop #7253

serut · 2023-02-10T10:01:48Z

serut
Feb 10, 2023

Hello there,

Our RabbitMQ container does not seem to correctly shutdown as the next boot rebuilds indices from scratch.

I've tryed to configure the stop_grace_period docker property to let RabbitMQ properly write its indices but it's not working.
Our Swarm deployment looks like this :

services:
  rs-rabbitmq:
    image: rabbitmq:3.11
    user: "3050:1050"
    hostname: rs-rabbitmq
    read_only: true
    stop_grace_period: 30m
    healthcheck:
      test: ["CMD-SHELL", "rabbitmqctl status || exit 1"]
      interval: 30s
      timeout: 10s
      retries: 3
      start_period: 2h
    volumes:
      - type: volume
        source: data-rabbitmq-datavolume
        target: /var/lib/rabbitmq/mnesia/
      - type: tmpfs
        target: /var/log/rabbitmq/
    configs:
      - source: rs-rabbitmq_definitions.json
        target: /etc/rabbitmq/definitions.json
      - source: rs-rabbitmq_rabbitmq.conf
        target: /etc/rabbitmq/rabbitmq.conf
      - source: rs-rabbitmq_ssl.ca
        target: "/etc/ca-certificates/ca_certificate.pem"
      - source: rs-rabbitmq_ssl.cert
        target: "/etc/ca-certificates/server_certificate.pem"    
    secrets:
      - source: rs-rabbitmq_ssl.key
        target: "/etc/ca-certificates/server_key.pem" 
    ports:
      - "5672:5672"
      - "15672:15672"
      - "5671:5671"
    deploy:
      resources:
        limits:
          cpus: '4'
          memory: 2500m
        reservations:
          cpus: '1'
          memory: 2000m

When the container stops, we can see it does not fully save its index correctly :

2023-02-10 08:22:36.526313+00:00 [notice] <0.61.0> SIGTERM received - shutting down
2023-02-10 08:22:36.526313+00:00 [notice] <0.61.0> 
2023-02-10 08:22:36.556293+00:00 [warning] <0.23341.0> HTTP listener registry could not find context rabbitmq_prometheus_tls
2023-02-10 08:22:36.571545+00:00 [warning] <0.23341.0> HTTP listener registry could not find context rabbitmq_management_tls
2023-02-10 08:22:36.593575+00:00 [info] <0.230.0> Peer discovery backend rabbit_peer_discovery_classic_config does not support registration, skipping unregistration.
2023-02-10 08:22:36.593860+00:00 [info] <0.23469.0> stopped TLS (SSL) listener on [::]:5671
2023-02-10 08:22:36.595406+00:00 [info] <0.23449.0> stopped TCP listener on [::]:5672
2023-02-10 08:22:36.596703+00:00 [error] <0.2731.6> Error on AMQP connection <0.2731.6> (10.11.3.113:55740 -> 10.11.3.2:5672 - SpringAMQP#558575fe:0, vhost: 'regards.instance.manager', user: 'guest', state: running), channel 0:
2023-02-10 08:22:36.596703+00:00 [error] <0.2731.6>  operation none caused a connection exception connection_forced: "broker forced connection closure with reason 'shutdown'"
2023-02-10 08:22:36.596702+00:00 [error] <0.18776.7> Error on AMQP connection <0.18776.7> (10.11.3.245:38762 -> 10.11.3.2:5672 - SpringAMQP#1734b1a:0, vhost: 'regards.multitenant.manager', user: 'guest', state: running), channel 0:
2023-02-10 08:22:36.596702+00:00 [error] <0.18776.7>  operation none caused a connection exception connection_forced: "broker forced connection closure with reason 'shutdown'"
[...]
2023-02-10 08:22:36.598389+00:00 [error] <0.30504.7>  operation none caused a connection exception connection_forced: "broker forced connection closure with reason 'shutdown'"
2023-02-10 08:22:41.601128+00:00 [info] <0.32725.11> Closing all connections in vhost 'regards.multitenant.manager' on node 'rabbit@rs-rabbitmq' because the vhost is stopping
2023-02-10 08:22:41.601359+00:00 [info] <0.32726.11> Closing all connections in vhost '/' on node 'rabbit@rs-rabbitmq' because the vhost is stopping
2023-02-10 08:22:41.601427+00:00 [info] <0.32727.11> Closing all connections in vhost 'regards.instance.manager' on node 'rabbit@rs-rabbitmq' because the vhost is stopping
2023-02-10 08:22:41.765613+00:00 [info] <0.22188.0> Stopping message store for directory '/var/lib/rabbitmq/mnesia/rabbit@rs-rabbitmq/msg_stores/vhosts/628WB79CIFDYO9LJI6DKMI09L/msg_store_persistent'
2023-02-10 08:22:41.907677+00:00 [info] <0.22188.0> Message store for directory '/var/lib/rabbitmq/mnesia/rabbit@rs-rabbitmq/msg_stores/vhosts/628WB79CIFDYO9LJI6DKMI09L/msg_store_persistent' is stopped
2023-02-10 08:22:41.908832+00:00 [info] <0.22184.0> Stopping message store for directory '/var/lib/rabbitmq/mnesia/rabbit@rs-rabbitmq/msg_stores/vhosts/628WB79CIFDYO9LJI6DKMI09L/msg_store_transient'
2023-02-10 08:22:42.063850+00:00 [info] <0.22184.0> Message store for directory '/var/lib/rabbitmq/mnesia/rabbit@rs-rabbitmq/msg_stores/vhosts/628WB79CIFDYO9LJI6DKMI09L/msg_store_transient' is stopped
2023-02-10 08:22:45.484255+00:00 [error] <0.18776.7> Error on AMQP connection <0.18776.7> (10.11.3.245:38762 -> 10.11.3.2:5672 - SpringAMQP#1734b1a:0, vhost: 'regards.multitenant.manager', user: 'guest', state: running), channel 9:error while terminating:
2023-02-10 08:22:45.484255+00:00 [error] <0.18776.7> shutdown

This is the log when the server boots :

2023-02-10 08:22:57.589068+00:00 [notice] <0.44.0> Application syslog exited with reason: stopped
2023-02-10 08:22:57.597896+00:00 [notice] <0.230.0> Logging: switching to configured handler(s); following messages may not be visible in this log output
2023-02-10 08:22:57.618841+00:00 [notice] <0.230.0> Logging: configured log handlers are now ACTIVE
2023-02-10 08:23:03.135338+00:00 [info] <0.230.0> ra: starting system quorum_queues
2023-02-10 08:23:03.135436+00:00 [info] <0.230.0> starting Ra system: quorum_queues in directory: /var/lib/rabbitmq/mnesia/rabbit@rs-rabbitmq/quorum/rabbit@rs-rabbitmq
2023-02-10 08:23:03.140770+00:00 [info] <0.296.0> ra system 'quorum_queues' running pre init for 0 registered servers
2023-02-10 08:23:03.143132+00:00 [info] <0.297.0> ra: meta data store initialised for system quorum_queues. 0 record(s) recovered
2023-02-10 08:23:03.143649+00:00 [notice] <0.302.0> WAL: ra_log_wal init, open tbls: ra_log_open_mem_tables, closed tbls: ra_log_closed_mem_tables
2023-02-10 08:23:03.160551+00:00 [info] <0.230.0> ra: starting system coordination
2023-02-10 08:23:03.160640+00:00 [info] <0.230.0> starting Ra system: coordination in directory: /var/lib/rabbitmq/mnesia/rabbit@rs-rabbitmq/coordination/rabbit@rs-rabbitmq
2023-02-10 08:23:03.189434+00:00 [info] <0.316.0> ra system 'coordination' running pre init for 0 registered servers
2023-02-10 08:23:03.194484+00:00 [info] <0.317.0> ra: meta data store initialised for system coordination. 0 record(s) recovered
2023-02-10 08:23:03.194830+00:00 [notice] <0.324.0> WAL: ra_coordination_log_wal init, open tbls: ra_coordination_log_open_mem_tables, closed tbls: ra_coordination_log_closed_mem_tables
2023-02-10 08:23:03.209953+00:00 [info] <0.230.0> 
2023-02-10 08:23:03.209953+00:00 [info] <0.230.0>  Starting RabbitMQ 3.11.8 on Erlang 25.2.2 [jit]
2023-02-10 08:23:03.209953+00:00 [info] <0.230.0>  Copyright (c) 2007-2023 VMware, Inc. or its affiliates.
2023-02-10 08:23:03.209953+00:00 [info] <0.230.0>  Licensed under the MPL 2.0. Website: https://rabbitmq.com

  ##  ##      RabbitMQ 3.11.8
  ##  ##
  ##########  Copyright (c) 2007-2023 VMware, Inc. or its affiliates.
  ######  ##
  ##########  Licensed under the MPL 2.0. Website: https://rabbitmq.com

  Erlang:      25.2.2 [jit]
  TLS Library: OpenSSL - OpenSSL 3.0.7 1 Nov 2022
  Release series support status: supported

  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: /var/log/rabbitmq/rabbit@rs-rabbitmq_upgrade.log
        <stdout>

  Config file(s): /etc/rabbitmq/rabbitmq.conf
                  /etc/rabbitmq/conf.d/10-defaults.conf

  Starting broker...2023-02-10 08:23:03.211353+00:00 [info] <0.230.0> 
2023-02-10 08:23:03.211353+00:00 [info] <0.230.0>  node           : rabbit@rs-rabbitmq
2023-02-10 08:23:03.211353+00:00 [info] <0.230.0>  home dir       : /var/lib/rabbitmq
2023-02-10 08:23:03.211353+00:00 [info] <0.230.0>  config file(s) : /etc/rabbitmq/rabbitmq.conf
2023-02-10 08:23:03.211353+00:00 [info] <0.230.0>                 : /etc/rabbitmq/conf.d/10-defaults.conf
2023-02-10 08:23:03.211353+00:00 [info] <0.230.0>  cookie hash    : NhhUKF+MrJfEnCH+Cq7BGQ==
2023-02-10 08:23:03.211353+00:00 [info] <0.230.0>  log(s)         : /var/log/rabbitmq/rabbit@rs-rabbitmq_upgrade.log
2023-02-10 08:23:03.211353+00:00 [info] <0.230.0>                 : <stdout>
2023-02-10 08:23:03.211353+00:00 [info] <0.230.0>  database dir   : /var/lib/rabbitmq/mnesia/rabbit@rs-rabbitmq
2023-02-10 08:23:04.404951+00:00 [info] <0.230.0> Running boot step pre_boot defined by app rabbit
2023-02-10 08:23:04.405076+00:00 [info] <0.230.0> Running boot step rabbit_global_counters defined by app rabbit
2023-02-10 08:23:04.405574+00:00 [info] <0.230.0> Running boot step rabbit_osiris_metrics defined by app rabbit
2023-02-10 08:23:04.405768+00:00 [info] <0.230.0> Running boot step rabbit_core_metrics defined by app rabbit
2023-02-10 08:23:04.407009+00:00 [info] <0.230.0> Running boot step rabbit_alarm defined by app rabbit
2023-02-10 08:23:04.466691+00:00 [info] <0.384.0> Memory high watermark set to 8031 MiB (8421249843 bytes) of 20077 MiB (21053124608 bytes) total
2023-02-10 08:23:04.480460+00:00 [info] <0.386.0> Enabling free disk space monitoring (disk free space: 415185698816, total memory: 21053124608)
2023-02-10 08:23:04.480716+00:00 [info] <0.386.0> Disk free limit set to 5000MB
2023-02-10 08:23:04.484440+00:00 [info] <0.230.0> Running boot step code_server_cache defined by app rabbit
2023-02-10 08:23:04.484667+00:00 [info] <0.230.0> Running boot step file_handle_cache defined by app rabbit
2023-02-10 08:23:04.485215+00:00 [info] <0.389.0> Limiting to approx 1048479 file handles (943629 sockets)
2023-02-10 08:23:04.485409+00:00 [info] <0.390.0> FHC read buffering: OFF
2023-02-10 08:23:04.485481+00:00 [info] <0.390.0> FHC write buffering: ON
2023-02-10 08:23:04.486145+00:00 [info] <0.230.0> Running boot step worker_pool defined by app rabbit
2023-02-10 08:23:04.486385+00:00 [info] <0.331.0> Will use 8 processes for default worker pool
2023-02-10 08:23:04.486488+00:00 [info] <0.331.0> Starting worker pool 'worker_pool' with 8 processes in it
2023-02-10 08:23:04.487186+00:00 [info] <0.230.0> Running boot step database defined by app rabbit
2023-02-10 08:23:04.491881+00:00 [info] <0.230.0> Waiting for Mnesia tables for 30000 ms, 9 retries left
2023-02-10 08:23:04.492530+00:00 [info] <0.230.0> Successfully synced tables from a peer
2023-02-10 08:23:04.514244+00:00 [info] <0.230.0> Waiting for Mnesia tables for 30000 ms, 9 retries left
2023-02-10 08:23:04.514490+00:00 [info] <0.230.0> Successfully synced tables from a peer
2023-02-10 08:23:04.514525+00:00 [info] <0.230.0> Peer discovery backend rabbit_peer_discovery_classic_config does not support registration, skipping registration.
2023-02-10 08:23:04.514618+00:00 [info] <0.230.0> Running boot step tracking_metadata_store defined by app rabbit
2023-02-10 08:23:04.514752+00:00 [info] <0.407.0> Setting up a table for connection tracking on this node: tracked_connection
2023-02-10 08:23:04.514804+00:00 [info] <0.407.0> Setting up a table for per-vhost connection counting on this node: tracked_connection_per_vhost
2023-02-10 08:23:04.514848+00:00 [info] <0.407.0> Setting up a table for per-user connection counting on this node: tracked_connection_per_user
2023-02-10 08:23:04.514925+00:00 [info] <0.407.0> Setting up a table for channel tracking on this node: tracked_channel
2023-02-10 08:23:04.514997+00:00 [info] <0.407.0> Setting up a table for channel tracking on this node: tracked_channel_per_user
2023-02-10 08:23:04.515175+00:00 [info] <0.230.0> Running boot step networking_metadata_store defined by app rabbit
2023-02-10 08:23:04.515379+00:00 [info] <0.230.0> Running boot step database_sync defined by app rabbit
2023-02-10 08:23:04.515477+00:00 [info] <0.230.0> Running boot step feature_flags defined by app rabbit
2023-02-10 08:23:04.516026+00:00 [info] <0.230.0> Running boot step codec_correctness_check defined by app rabbit
2023-02-10 08:23:04.516112+00:00 [info] <0.230.0> Running boot step external_infrastructure defined by app rabbit
2023-02-10 08:23:04.516157+00:00 [info] <0.230.0> Running boot step rabbit_event defined by app rabbit
2023-02-10 08:23:04.516331+00:00 [info] <0.230.0> Running boot step rabbit_registry defined by app rabbit
2023-02-10 08:23:04.516426+00:00 [info] <0.230.0> Running boot step rabbit_auth_mechanism_amqplain defined by app rabbit
2023-02-10 08:23:04.516535+00:00 [info] <0.230.0> Running boot step rabbit_auth_mechanism_cr_demo defined by app rabbit
2023-02-10 08:23:04.516636+00:00 [info] <0.230.0> Running boot step rabbit_auth_mechanism_plain defined by app rabbit
2023-02-10 08:23:04.516711+00:00 [info] <0.230.0> Running boot step rabbit_exchange_type_direct defined by app rabbit
2023-02-10 08:23:04.516835+00:00 [info] <0.230.0> Running boot step rabbit_exchange_type_fanout defined by app rabbit
2023-02-10 08:23:04.516971+00:00 [info] <0.230.0> Running boot step rabbit_exchange_type_headers defined by app rabbit
2023-02-10 08:23:04.517049+00:00 [info] <0.230.0> Running boot step rabbit_exchange_type_topic defined by app rabbit
2023-02-10 08:23:04.517136+00:00 [info] <0.230.0> Running boot step rabbit_mirror_queue_mode_all defined by app rabbit
2023-02-10 08:23:04.517195+00:00 [info] <0.230.0> Running boot step rabbit_mirror_queue_mode_exactly defined by app rabbit
2023-02-10 08:23:04.517304+00:00 [info] <0.230.0> Running boot step rabbit_mirror_queue_mode_nodes defined by app rabbit
2023-02-10 08:23:04.517426+00:00 [info] <0.230.0> Running boot step rabbit_priority_queue defined by app rabbit
2023-02-10 08:23:04.517473+00:00 [info] <0.230.0> Priority queues enabled, real BQ is rabbit_variable_queue
2023-02-10 08:23:04.517524+00:00 [info] <0.230.0> Running boot step rabbit_queue_location_client_local defined by app rabbit
2023-02-10 08:23:04.517595+00:00 [info] <0.230.0> Running boot step rabbit_queue_location_min_masters defined by app rabbit
2023-02-10 08:23:04.517634+00:00 [info] <0.230.0> Running boot step rabbit_queue_location_random defined by app rabbit
2023-02-10 08:23:04.517676+00:00 [info] <0.230.0> Running boot step kernel_ready defined by app rabbit
2023-02-10 08:23:04.517709+00:00 [info] <0.230.0> Running boot step rabbit_sysmon_minder defined by app rabbit
2023-02-10 08:23:04.517874+00:00 [info] <0.230.0> Running boot step rabbit_epmd_monitor defined by app rabbit
2023-02-10 08:23:04.519131+00:00 [info] <0.416.0> epmd monitor knows us, inter-node communication (distribution) port: 25672
2023-02-10 08:23:04.519252+00:00 [info] <0.230.0> Running boot step guid_generator defined by app rabbit
2023-02-10 08:23:04.525559+00:00 [info] <0.230.0> Running boot step rabbit_node_monitor defined by app rabbit
2023-02-10 08:23:04.525897+00:00 [info] <0.420.0> Starting rabbit_node_monitor
2023-02-10 08:23:04.526168+00:00 [info] <0.230.0> Running boot step delegate_sup defined by app rabbit
2023-02-10 08:23:04.526998+00:00 [info] <0.230.0> Running boot step rabbit_memory_monitor defined by app rabbit
2023-02-10 08:23:04.527296+00:00 [info] <0.230.0> Running boot step rabbit_fifo_dlx_sup defined by app rabbit
2023-02-10 08:23:04.527438+00:00 [info] <0.230.0> Running boot step core_initialized defined by app rabbit
2023-02-10 08:23:04.527505+00:00 [info] <0.230.0> Running boot step upgrade_queues defined by app rabbit
2023-02-10 08:23:04.539863+00:00 [info] <0.230.0> Running boot step channel_tracking defined by app rabbit
2023-02-10 08:23:04.539955+00:00 [info] <0.230.0> Running boot step rabbit_channel_tracking_handler defined by app rabbit
2023-02-10 08:23:04.540043+00:00 [info] <0.230.0> Running boot step connection_tracking defined by app rabbit
2023-02-10 08:23:04.540068+00:00 [info] <0.230.0> Running boot step rabbit_connection_tracking_handler defined by app rabbit
2023-02-10 08:23:04.540127+00:00 [info] <0.230.0> Running boot step rabbit_definitions_hashing defined by app rabbit
2023-02-10 08:23:04.540244+00:00 [info] <0.230.0> Running boot step rabbit_exchange_parameters defined by app rabbit
2023-02-10 08:23:04.540470+00:00 [info] <0.230.0> Running boot step rabbit_mirror_queue_misc defined by app rabbit
2023-02-10 08:23:04.540722+00:00 [info] <0.230.0> Running boot step rabbit_policies defined by app rabbit
2023-02-10 08:23:04.541185+00:00 [info] <0.230.0> Running boot step rabbit_policy defined by app rabbit
2023-02-10 08:23:04.541324+00:00 [info] <0.230.0> Running boot step rabbit_queue_location_validator defined by app rabbit
2023-02-10 08:23:04.541435+00:00 [info] <0.230.0> Running boot step rabbit_quorum_memory_manager defined by app rabbit
2023-02-10 08:23:04.541535+00:00 [info] <0.230.0> Running boot step rabbit_stream_coordinator defined by app rabbit
2023-02-10 08:23:04.541736+00:00 [info] <0.230.0> Running boot step rabbit_vhost_limit defined by app rabbit
2023-02-10 08:23:04.541865+00:00 [info] <0.230.0> Running boot step rabbit_mgmt_reset_handler defined by app rabbitmq_management
2023-02-10 08:23:04.541949+00:00 [info] <0.230.0> Running boot step rabbit_mgmt_db_handler defined by app rabbitmq_management_agent
2023-02-10 08:23:04.541987+00:00 [info] <0.230.0> Management plugin: using rates mode 'basic'
2023-02-10 08:23:04.547398+00:00 [info] <0.230.0> Running boot step rabbit_shovel_parameters defined by app rabbitmq_shovel
2023-02-10 08:23:04.547585+00:00 [info] <0.230.0> Running boot step recovery defined by app rabbit
2023-02-10 08:23:04.551731+00:00 [info] <0.454.0> Making sure data directory '/var/lib/rabbitmq/mnesia/rabbit@rs-rabbitmq/msg_stores/vhosts/APYN3HZ2FWB83GLCFGRY2DOX4' for vhost 'regards.multitenant.manager' exists
2023-02-10 08:23:07.398738+00:00 [info] <0.454.0> Starting message stores for vhost 'regards.multitenant.manager'
2023-02-10 08:23:07.399179+00:00 [info] <0.459.0> Message store "APYN3HZ2FWB83GLCFGRY2DOX4/msg_store_transient": using rabbit_msg_store_ets_index to provide index
2023-02-10 08:23:07.432145+00:00 [info] <0.454.0> Started message store of type transient for vhost 'regards.multitenant.manager'
2023-02-10 08:23:07.492075+00:00 [info] <0.463.0> Message store "APYN3HZ2FWB83GLCFGRY2DOX4/msg_store_persistent": using rabbit_msg_store_ets_index to provide index
2023-02-10 08:23:07.500633+00:00 [warning] <0.463.0> Message store "APYN3HZ2FWB83GLCFGRY2DOX4/msg_store_persistent": rebuilding indices from scratch
2023-02-10 08:23:32.025822+00:00 [info] <0.454.0> Started message store of type persistent for vhost 'regards.multitenant.manager'
2023-02-10 08:36:51.942303+00:00 [info] <0.454.0> Recovering 179 queues of type rabbit_classic_queue took 827382ms
2023-02-10 08:36:51.942445+00:00 [info] <0.454.0> Recovering 0 queues of type rabbit_quorum_queue took 0ms
2023-02-10 08:36:51.942478+00:00 [info] <0.454.0> Recovering 0 queues of type rabbit_stream_queue took 0ms
2023-02-10 08:36:52.015121+00:00 [info] <0.14539.1> Making sure data directory '/var/lib/rabbitmq/mnesia/rabbit@rs-rabbitmq/msg_stores/vhosts/628WB79CIFDYO9LJI6DKMI09L' for vhost '/' exists
2023-02-10 08:36:52.077943+00:00 [info] <0.14539.1> Starting message stores for vhost '/'
2023-02-10 08:36:52.082434+00:00 [info] <0.14543.1> Message store "628WB79CIFDYO9LJI6DKMI09L/msg_store_transient": using rabbit_msg_store_ets_index to provide index
2023-02-10 08:36:52.117960+00:00 [info] <0.14539.1> Started message store of type transient for vhost '/'
2023-02-10 08:36:52.118345+00:00 [info] <0.14547.1> Message store "628WB79CIFDYO9LJI6DKMI09L/msg_store_persistent": using rabbit_msg_store_ets_index to provide index
2023-02-10 08:36:52.161644+00:00 [info] <0.14539.1> Started message store of type persistent for vhost '/'
2023-02-10 08:36:52.170945+00:00 [info] <0.14539.1> Recovering 1 queues of type rabbit_classic_queue took 148ms
2023-02-10 08:36:52.171171+00:00 [info] <0.14539.1> Recovering 0 queues of type rabbit_quorum_queue took 0ms
2023-02-10 08:36:52.171230+00:00 [info] <0.14539.1> Recovering 0 queues of type rabbit_stream_queue took 0ms
2023-02-10 08:36:52.187078+00:00 [info] <0.14689.1> Making sure data directory '/var/lib/rabbitmq/mnesia/rabbit@rs-rabbitmq/msg_stores/vhosts/CBFRXS0HLQ1RLA9P3Q8UAU5CC' for vhost 'regards.instance.manager' exists
2023-02-10 08:36:53.851474+00:00 [info] <0.14689.1> Starting message stores for vhost 'regards.instance.manager'
2023-02-10 08:36:53.852175+00:00 [info] <0.14694.1> Message store "CBFRXS0HLQ1RLA9P3Q8UAU5CC/msg_store_transient": using rabbit_msg_store_ets_index to provide index
2023-02-10 08:36:53.872128+00:00 [info] <0.14689.1> Started message store of type transient for vhost 'regards.instance.manager'
2023-02-10 08:36:53.894158+00:00 [info] <0.14698.1> Message store "CBFRXS0HLQ1RLA9P3Q8UAU5CC/msg_store_persistent": using rabbit_msg_store_ets_index to provide index
2023-02-10 08:36:53.898406+00:00 [warning] <0.14698.1> Message store "CBFRXS0HLQ1RLA9P3Q8UAU5CC/msg_store_persistent": rebuilding indices from scratch
2023-02-10 08:36:54.843329+00:00 [info] <0.14689.1> Started message store of type persistent for vhost 'regards.instance.manager'
2023-02-10 08:43:07.264648+00:00 [info] <0.14689.1> Recovering 87 queues of type rabbit_classic_queue took 375072ms
2023-02-10 08:43:07.264776+00:00 [info] <0.14689.1> Recovering 0 queues of type rabbit_quorum_queue took 0ms
2023-02-10 08:43:07.264823+00:00 [info] <0.14689.1> Recovering 0 queues of type rabbit_stream_queue took 0ms
2023-02-10 08:43:07.304895+00:00 [info] <0.230.0> Running boot step empty_db_check defined by app rabbit
2023-02-10 08:43:07.305016+00:00 [info] <0.230.0> Will not seed default virtual host and user: have definitions to load...
2023-02-10 08:43:07.305051+00:00 [info] <0.230.0> Running boot step rabbit_observer_cli defined by app rabbit
2023-02-10 08:43:07.308421+00:00 [info] <0.230.0> Running boot step rabbit_looking_glass defined by app rabbit
2023-02-10 08:43:07.308517+00:00 [info] <0.230.0> Running boot step rabbit_core_metrics_gc defined by app rabbit
2023-02-10 08:43:07.308659+00:00 [info] <0.230.0> Running boot step background_gc defined by app rabbit
2023-02-10 08:43:07.311778+00:00 [info] <0.230.0> Running boot step routing_ready defined by app rabbit
2023-02-10 08:43:07.311863+00:00 [info] <0.230.0> Running boot step pre_flight defined by app rabbit
2023-02-10 08:43:07.311886+00:00 [info] <0.230.0> Running boot step notify_cluster defined by app rabbit
2023-02-10 08:43:07.311911+00:00 [info] <0.230.0> Running boot step networking defined by app rabbit
2023-02-10 08:43:07.312000+00:00 [info] <0.230.0> Running boot step definition_import_worker_pool defined by app rabbit
2023-02-10 08:43:07.312125+00:00 [info] <0.331.0> Starting worker pool 'definition_import_pool' with 8 processes in it
2023-02-10 08:43:07.319351+00:00 [info] <0.230.0> Running boot step cluster_name defined by app rabbit
2023-02-10 08:43:07.319444+00:00 [info] <0.230.0> Running boot step direct_client defined by app rabbit
2023-02-10 08:43:07.319532+00:00 [info] <0.230.0> Running boot step rabbit_maintenance_mode_state defined by app rabbit
2023-02-10 08:43:07.319561+00:00 [info] <0.230.0> Creating table rabbit_node_maintenance_states for maintenance mode status
2023-02-10 08:43:07.373257+00:00 [info] <0.230.0> Running boot step rabbit_management_load_definitions defined by app rabbitmq_management
2023-02-10 08:43:07.396797+00:00 [info] <0.230.0> Applying definitions from file at '/etc/rabbitmq/definitions.json'
2023-02-10 08:43:07.396876+00:00 [info] <0.230.0> Asked to import definitions. Acting user: rmq-internal
2023-02-10 08:43:07.396982+00:00 [info] <0.230.0> Importing concurrently 1 users...
2023-02-10 08:43:07.410403+00:00 [info] <0.230.0> Importing concurrently 3 vhosts...
2023-02-10 08:43:07.418851+00:00 [info] <0.230.0> Importing concurrently 3 permissions...
2023-02-10 08:43:07.424675+00:00 [info] <0.4753.2> Successfully set permissions for 'guest' in virtual host 'regards.instance.manager' to '.*', '.*', '.*'
2023-02-10 08:43:07.424846+00:00 [info] <0.4752.2> Successfully set permissions for 'guest' in virtual host 'regards.multitenant.manager' to '.*', '.*', '.*'
2023-02-10 08:43:07.428599+00:00 [info] <0.4751.2> Successfully set permissions for 'guest' in virtual host '/' to '.*', '.*', '.*'
2023-02-10 08:43:22.057555+00:00 [info] <0.4778.2> Resetting node maintenance status
2023-02-10 08:43:24.932120+00:00 [info] <0.4837.2> Management plugin: HTTP (non-TLS) listener started on port 15672
2023-02-10 08:43:24.958478+00:00 [info] <0.4865.2> Statistics database started.
2023-02-10 08:43:24.958679+00:00 [info] <0.4864.2> Starting worker pool 'management_worker_pool' with 3 processes in it
2023-02-10 08:43:25.639693+00:00 [info] <0.4893.2> Prometheus metrics: HTTP (non-TLS) listener started on port 15692
2023-02-10 08:43:25.658519+00:00 [info] <0.4778.2> Ready to start client connection listeners
2023-02-10 08:43:25.728200+00:00 [info] <0.4937.2> started TCP listener on [::]:5672
2023-02-10 08:43:25.742861+00:00 [info] <0.4957.2> started TLS (SSL) listener on [::]:5671
 completed with 6 plugins.
2023-02-10 08:43:25.909554+00:00 [info] <0.4778.2> Server startup complete; 6 plugins started.
2023-02-10 08:43:25.909554+00:00 [info] <0.4778.2>  * rabbitmq_prometheus
2023-02-10 08:43:25.909554+00:00 [info] <0.4778.2>  * rabbitmq_shovel_management
2023-02-10 08:43:25.909554+00:00 [info] <0.4778.2>  * rabbitmq_shovel
2023-02-10 08:43:25.909554+00:00 [info] <0.4778.2>  * rabbitmq_management
2023-02-10 08:43:25.909554+00:00 [info] <0.4778.2>  * rabbitmq_web_dispatch
2023-02-10 08:43:25.909554+00:00 [info] <0.4778.2>  * rabbitmq_management_agent

The configuration file rabbitmq.conf

# Logging
log.console = true
log.console.level = info
#log.console.formatter = json
log.file = false
log.dir = /var/log/rabbitmq/

loopback_users.guest = false
listeners.tcp.default = 5672
management.tcp.port = 15672
management.load_definitions = /etc/rabbitmq/definitions.json
disk_free_limit.absolute = 5GB

# TLS configuration
listeners.ssl.default = 5671
ssl_options.cacertfile = /etc/ca-certificates/ca_certificate.pem
ssl_options.certfile   = /etc/ca-certificates/server_certificate.pem
ssl_options.keyfile    = /etc/ca-certificates/server_key.pem
ssl_options.verify     = verify_peer
ssl_options.fail_if_no_peer_cert = true
ssl_options.password = ....

Moreover, this is a very small instance we use since a couple of days to validate our software, as you can see here :

Do you know how to configure the property worker_shutdown_timeout or to see its current value ?

Duplicates of docker-library/rabbitmq#610

michaelklishin · 2023-02-10T14:50:45Z

michaelklishin
Feb 10, 2023
Maintainer

rabbitmqctl shutdown is how nodes are told to shut down. It’s a good question for/to the Docker image maintainers if or how they call that command.

There are worker shutdown timeout in many places. With quorum queues, streams and CQ v2 it should not be necessary to increase them because very little data is kept in memory.

Connection shutdown log messages are irrelevant for CQ index rebuilding.

0 replies

lukebakken · 2023-02-10T22:22:00Z

lukebakken
Feb 10, 2023
Maintainer

EDIT: I actually don't always see the "rebuilding" message, even if I stop RabbitMQ with a TERM signal. I'm investigating.

@serut it's safe to ignore that message. The SIGTERM handling in the rabbitmq-server script shuts down RabbitMQ correctly. This script is what the docker image uses to start RabbitMQ.

@michaelklishin I think we should investigate why that message appears on occasion.

2 replies

michaelklishin Feb 11, 2023
Maintainer

@lukebakken does this happen even if you use CQv2? If it does, then yes, it would be interesting to put some time in. @lhoguin would likely know best.

lukebakken Feb 14, 2023
Maintainer

I'll check that as well, thanks. I'm currently busy with customer support but I'll return to this when I can (cc @serut)

serut · 2023-02-13T10:40:52Z

serut
Feb 13, 2023
Author

Thank you for your reply !!

If I run rabbitmqctl shutdown inside the container, this is the log produced by RabbitMQ :

rs-rabbitmq:/$ rabbitmqctl shutdown

2023-02-13 10:11:42.988797+00:00 [info] <0.6225.37> RabbitMQ is asked to stop...
2023-02-13 10:11:43.129077+00:00 [info] <0.6225.37> Stopping RabbitMQ applications and their dependencies in the following order:
2023-02-13 10:11:43.129077+00:00 [info] <0.6225.37>     rabbitmq_shovel_management
2023-02-13 10:11:43.129077+00:00 [info] <0.6225.37>     rabbitmq_management
2023-02-13 10:11:43.129077+00:00 [info] <0.6225.37>     rabbitmq_prometheus
2023-02-13 10:11:43.129077+00:00 [info] <0.6225.37>     rabbitmq_web_dispatch
2023-02-13 10:11:43.129077+00:00 [info] <0.6225.37>     cowboy
2023-02-13 10:11:43.129077+00:00 [info] <0.6225.37>     cowlib
2023-02-13 10:11:43.129077+00:00 [info] <0.6225.37>     rabbitmq_management_agent
2023-02-13 10:11:43.129077+00:00 [info] <0.6225.37>     rabbitmq_shovel
2023-02-13 10:11:43.129077+00:00 [info] <0.6225.37>     rabbit
2023-02-13 10:11:43.129077+00:00 [info] <0.6225.37>     rabbitmq_prelaunch
2023-02-13 10:11:43.129077+00:00 [info] <0.6225.37>     amqp_client
2023-02-13 10:11:43.129077+00:00 [info] <0.6225.37>     rabbit_common
2023-02-13 10:11:43.129077+00:00 [info] <0.6225.37>     prometheus
2023-02-13 10:11:43.129077+00:00 [info] <0.6225.37>     ra
2023-02-13 10:11:43.129077+00:00 [info] <0.6225.37>     accept
2023-02-13 10:11:43.129077+00:00 [info] <0.6225.37>     os_mon
2023-02-13 10:11:43.129077+00:00 [info] <0.6225.37>     sysmon_handler
2023-02-13 10:11:43.129077+00:00 [info] <0.6225.37>     amqp10_client
2023-02-13 10:11:43.129077+00:00 [info] <0.6225.37>     osiris
2023-02-13 10:11:43.129077+00:00 [info] <0.6225.37>     mnesia
2023-02-13 10:11:43.129077+00:00 [info] <0.6225.37> 
2023-02-13 10:11:43.129295+00:00 [info] <0.6225.37> Stopping application 'rabbitmq_shovel_management'
2023-02-13 10:11:43.129392+00:00 [notice] <0.44.0> Application rabbitmq_shovel_management exited with reason: stopped
2023-02-13 10:11:43.129455+00:00 [info] <0.6225.37> Stopping application 'rabbitmq_management'
2023-02-13 10:11:43.132312+00:00 [warning] <0.1238.6> HTTP listener registry could not find context rabbitmq_management_tls
2023-02-13 10:11:43.137380+00:00 [notice] <0.44.0> Application rabbitmq_management exited with reason: stopped
2023-02-13 10:11:43.137539+00:00 [info] <0.6225.37> Stopping application 'rabbitmq_prometheus'
2023-02-13 10:11:43.139861+00:00 [warning] <0.1238.6> HTTP listener registry could not find context rabbitmq_prometheus_tls
2023-02-13 10:11:43.143521+00:00 [notice] <0.44.0> Application rabbitmq_prometheus exited with reason: stopped
2023-02-13 10:11:43.143657+00:00 [info] <0.6225.37> Stopping application 'rabbitmq_web_dispatch'
2023-02-13 10:11:43.147383+00:00 [notice] <0.44.0> Application rabbitmq_web_dispatch exited with reason: stopped
2023-02-13 10:11:43.147548+00:00 [info] <0.6225.37> Stopping application 'cowboy'
2023-02-13 10:11:43.150786+00:00 [notice] <0.44.0> Application cowboy exited with reason: stopped
2023-02-13 10:11:43.150907+00:00 [info] <0.6225.37> Stopping application 'cowlib'
2023-02-13 10:11:43.150977+00:00 [notice] <0.44.0> Application cowlib exited with reason: stopped
2023-02-13 10:11:43.151038+00:00 [info] <0.6225.37> Stopping application 'rabbitmq_management_agent'
2023-02-13 10:11:43.159940+00:00 [notice] <0.44.0> Application rabbitmq_management_agent exited with reason: stopped
2023-02-13 10:11:43.160097+00:00 [info] <0.6225.37> Stopping application 'rabbitmq_shovel'
2023-02-13 10:11:43.164618+00:00 [notice] <0.44.0> Application rabbitmq_shovel exited with reason: stopped
2023-02-13 10:11:43.164784+00:00 [info] <0.6225.37> Stopping application 'rabbit'
2023-02-13 10:11:43.165063+00:00 [info] <0.230.0> Peer discovery backend rabbit_peer_discovery_classic_config does not support registration, skipping unregistration.
2023-02-13 10:11:43.165197+00:00 [info] <0.1346.6> stopped TCP listener on [::]:5672
2023-02-13 10:11:43.168096+00:00 [error] <0.9627.6>  operation none caused a connection exception connection_forced: "broker forced connection closure with reason 'shutdown'"
2023-02-13 10:11:48.168795+00:00 [info] <0.6811.37> Closing all connections in vhost '/' on node 'rabbit@rs-rabbitmq' because the vhost is stopping
2023-02-13 10:11:48.168791+00:00 [info] <0.6810.37> Closing all connections in vhost 'regards.instance.manager' on node 'rabbit@rs-rabbitmq' because the vhost is stopping
2023-02-13 10:11:48.169103+00:00 [info] <0.6812.37> Closing all connections in vhost 'regards.multitenant.manager' on node 'rabbit@rs-rabbitmq' because the vhost is stopping
2023-02-13 10:11:48.295405+00:00 [info] <0.2558.4> Stopping message store for directory '/var/lib/rabbitmq/mnesia/rabbit@rs-rabbitmq/msg_stores/vhosts/628WB79CIFDYO9LJI6DKMI09L/msg_store_persistent'
2023-02-13 10:11:49.421275+00:00 [info] <0.2558.4> Message store for directory '/var/lib/rabbitmq/mnesia/rabbit@rs-rabbitmq/msg_stores/vhosts/628WB79CIFDYO9LJI6DKMI09L/msg_store_persistent' is stopped
2023-02-13 10:11:49.421466+00:00 [info] <0.2554.4> Stopping message store for directory '/var/lib/rabbitmq/mnesia/rabbit@rs-rabbitmq/msg_stores/vhosts/628WB79CIFDYO9LJI6DKMI09L/msg_store_transient'
2023-02-13 10:11:50.810126+00:00 [info] <0.2554.4> Message store for directory '/var/lib/rabbitmq/mnesia/rabbit@rs-rabbitmq/msg_stores/vhosts/628WB79CIFDYO9LJI6DKMI09L/msg_store_transient' is stopped
2023-02-13 10:11:58.757351+00:00 [error] <0.9626.6> ** Generic server <0.9626.6> terminating
2023-02-13 10:14:25.797340+00:00 [info] <0.464.0> Stopping message store for directory '/var/lib/rabbitmq/mnesia/rabbit@rs-rabbitmq/msg_stores/vhosts/APYN3HZ2FWB83GLCFGRY2DOX4/msg_store_persistent'
2023-02-13 10:14:26.538811+00:00 [info] <0.2744.4> Stopping message store for directory '/var/lib/rabbitmq/mnesia/rabbit@rs-rabbitmq/msg_stores/vhosts/CBFRXS0HLQ1RLA9P3Q8UAU5CC/msg_store_persistent'
2023-02-13 10:14:26.628854+00:00 [info] <0.2744.4> Message store for directory '/var/lib/rabbitmq/mnesia/rabbit@rs-rabbitmq/msg_stores/vhosts/CBFRXS0HLQ1RLA9P3Q8UAU5CC/msg_store_persistent' is stopped
2023-02-13 10:14:26.629216+00:00 [info] <0.2740.4> Stopping message store for directory '/var/lib/rabbitmq/mnesia/rabbit@rs-rabbitmq/msg_stores/vhosts/CBFRXS0HLQ1RLA9P3Q8UAU5CC/msg_store_transient'
2023-02-13 10:14:26.751303+00:00 [info] <0.2740.4> Message store for directory '/var/lib/rabbitmq/mnesia/rabbit@rs-rabbitmq/msg_stores/vhosts/CBFRXS0HLQ1RLA9P3Q8UAU5CC/msg_store_transient' is stopped
2023-02-13 10:14:27.152169+00:00 [info] <0.464.0> Message store for directory '/var/lib/rabbitmq/mnesia/rabbit@rs-rabbitmq/msg_stores/vhosts/APYN3HZ2FWB83GLCFGRY2DOX4/msg_store_persistent' is stopped
2023-02-13 10:14:27.152565+00:00 [info] <0.460.0> Stopping message store for directory '/var/lib/rabbitmq/mnesia/rabbit@rs-rabbitmq/msg_stores/vhosts/APYN3HZ2FWB83GLCFGRY2DOX4/msg_store_transient'
2023-02-13 10:14:27.184922+00:00 [info] <0.460.0> Message store for directory '/var/lib/rabbitmq/mnesia/rabbit@rs-rabbitmq/msg_stores/vhosts/APYN3HZ2FWB83GLCFGRY2DOX4/msg_store_transient' is stopped
2023-02-13 10:14:27.264943+00:00 [info] <0.407.0> Management plugin: to stop collect_statistics.
2023-02-13 10:14:32.274436+00:00 [notice] <0.44.0> Application rabbit exited with reason: stopped
2023-02-13 10:14:32.274594+00:00 [info] <0.6225.37> Stopping application 'rabbitmq_prelaunch'
2023-02-13 10:14:32.277512+00:00 [notice] <0.44.0> Application rabbitmq_prelaunch exited with reason: stopped
2023-02-13 10:14:32.277705+00:00 [info] <0.6225.37> Stopping application 'amqp_client'
2023-02-13 10:14:32.280621+00:00 [notice] <0.44.0> Application amqp_client exited with reason: stopped
2023-02-13 10:14:32.280756+00:00 [info] <0.6225.37> Stopping application 'rabbit_common'
2023-02-13 10:14:32.280807+00:00 [notice] <0.44.0> Application rabbit_common exited with reason: stopped
2023-02-13 10:14:32.280840+00:00 [info] <0.6225.37> Stopping application 'prometheus'
2023-02-13 10:14:32.283376+00:00 [notice] <0.44.0> Application prometheus exited with reason: stopped
2023-02-13 10:14:32.283494+00:00 [info] <0.6225.37> Stopping application 'ra'
2023-02-13 10:14:32.287974+00:00 [notice] <0.44.0> Application ra exited with reason: stopped
2023-02-13 10:14:32.288087+00:00 [info] <0.6225.37> Stopping application 'accept'
2023-02-13 10:14:32.288136+00:00 [notice] <0.44.0> Application accept exited with reason: stopped
2023-02-13 10:14:32.288172+00:00 [info] <0.6225.37> Stopping application 'os_mon'
2023-02-13 10:14:32.290546+00:00 [notice] <0.44.0> Application os_mon exited with reason: stopped
2023-02-13 10:14:32.290676+00:00 [info] <0.6225.37> Stopping application 'sysmon_handler'
2023-02-13 10:14:32.293215+00:00 [notice] <0.44.0> Application sysmon_handler exited with reason: stopped
2023-02-13 10:14:32.293356+00:00 [info] <0.6225.37> Stopping application 'amqp10_client'
2023-02-13 10:14:32.295694+00:00 [notice] <0.44.0> Application amqp10_client exited with reason: stopped
2023-02-13 10:14:32.295817+00:00 [info] <0.6225.37> Stopping application 'osiris'
2023-02-13 10:14:32.298699+00:00 [notice] <0.44.0> Application osiris exited with reason: stopped
2023-02-13 10:14:32.298819+00:00 [info] <0.6225.37> Stopping application 'mnesia'
vm-perf_rs-rabbitmq.1.safqpdhr6fcz@vm-perf.cloud-espace.si.c-s.fr    | Gracefully halting Erlang VM
2023-02-13 10:14:32.309095+00:00 [notice] <0.44.0> Application mnesia exited with reason: stopped
2023-02-13 10:14:32.309305+00:00 [info] <0.6225.37> Successfully stopped RabbitMQ and its dependencies
2023-02-13 10:14:32.309454+00:00 [info] <0.6225.37> Halting Erlang VM with the following applications:
2023-02-13 10:14:32.309454+00:00 [info] <0.6225.37>     amqp10_common
2023-02-13 10:14:32.309454+00:00 [info] <0.6225.37>     observer_cli
2023-02-13 10:14:32.309454+00:00 [info] <0.6225.37>     redbug
2023-02-13 10:14:32.309454+00:00 [info] <0.6225.37>     runtime_tools
2023-02-13 10:14:32.309454+00:00 [info] <0.6225.37>     stdout_formatter
2023-02-13 10:14:32.309454+00:00 [info] <0.6225.37>     seshat
2023-02-13 10:14:32.309454+00:00 [info] <0.6225.37>     gen_batch_server
2023-02-13 10:14:32.309454+00:00 [info] <0.6225.37>     aten
2023-02-13 10:14:32.309454+00:00 [info] <0.6225.37>     ranch
2023-02-13 10:14:32.309454+00:00 [info] <0.6225.37>     inets
2023-02-13 10:14:32.309454+00:00 [info] <0.6225.37>     systemd
2023-02-13 10:14:32.309454+00:00 [info] <0.6225.37>     enough
2023-02-13 10:14:32.309454+00:00 [info] <0.6225.37>     cuttlefish
2023-02-13 10:14:32.309454+00:00 [info] <0.6225.37>     credentials_obfuscation
2023-02-13 10:14:32.309454+00:00 [info] <0.6225.37>     recon
2023-02-13 10:14:32.309454+00:00 [info] <0.6225.37>     thoas
2023-02-13 10:14:32.309454+00:00 [info] <0.6225.37>     xmerl
2023-02-13 10:14:32.309454+00:00 [info] <0.6225.37>     tools
2023-02-13 10:14:32.309454+00:00 [info] <0.6225.37>     syntax_tools
2023-02-13 10:14:32.309454+00:00 [info] <0.6225.37>     ssl
2023-02-13 10:14:32.309454+00:00 [info] <0.6225.37>     public_key
2023-02-13 10:14:32.309454+00:00 [info] <0.6225.37>     asn1
2023-02-13 10:14:32.309454+00:00 [info] <0.6225.37>     crypto
2023-02-13 10:14:32.309454+00:00 [info] <0.6225.37>     compiler
2023-02-13 10:14:32.309454+00:00 [info] <0.6225.37>     sasl
2023-02-13 10:14:32.309454+00:00 [info] <0.6225.37>     stdlib
2023-02-13 10:14:32.309454+00:00 [info] <0.6225.37>     kernel
2023-02-13 10:14:32.309454+00:00 [info] <0.6225.37>

You can notice this log is much longer than the log produced by a SIGTERM. For example, there is no Successfully stopped RabbitMQ and its dependencies with SIGTERM...

Here is the log produced by the next boot after a rabbitmqctl shutdown :

  ##  ##      RabbitMQ 3.11.8
  ##  ##
  ##########  Copyright (c) 2007-2023 VMware, Inc. or its affiliates.
  ######  ##
  ##########  Licensed under the MPL 2.0. Website: https://rabbitmq.com

  Erlang:      25.2.2 [jit]
  TLS Library: OpenSSL - OpenSSL 3.0.7 1 Nov 2022
  Release series support status: supported

  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: /var/log/rabbitmq/rabbit@rs-rabbitmq_upgrade.log
        <stdout>

  Config file(s): /etc/rabbitmq/rabbitmq.conf
                  /etc/rabbitmq/conf.d/10-defaults.conf

  Starting broker...2023-02-13 10:14:51.217384+00:00 [info] <0.230.0> 
2023-02-13 10:14:51.217384+00:00 [info] <0.230.0>  node           : rabbit@rs-rabbitmq
2023-02-13 10:14:51.217384+00:00 [info] <0.230.0>  home dir       : /var/lib/rabbitmq
2023-02-13 10:14:51.217384+00:00 [info] <0.230.0>  config file(s) : /etc/rabbitmq/rabbitmq.conf
2023-02-13 10:14:51.217384+00:00 [info] <0.230.0>                 : /etc/rabbitmq/conf.d/10-defaults.conf
2023-02-13 10:14:51.217384+00:00 [info] <0.230.0>  cookie hash    : uiD01N6Lf82UJxo+8ZNlvg==
2023-02-13 10:14:51.217384+00:00 [info] <0.230.0>  log(s)         : /var/log/rabbitmq/rabbit@rs-rabbitmq_upgrade.log
2023-02-13 10:14:51.217384+00:00 [info] <0.230.0>                 : <stdout>
2023-02-13 10:14:51.217384+00:00 [info] <0.230.0>  database dir   : /var/lib/rabbitmq/mnesia/rabbit@rs-rabbitmq
2023-02-13 10:14:52.577875+00:00 [info] <0.230.0> Running boot step pre_boot defined by app rabbit
2023-02-13 10:14:52.578022+00:00 [info] <0.230.0> Running boot step rabbit_global_counters defined by app rabbit
2023-02-13 10:14:52.579417+00:00 [info] <0.230.0> Running boot step rabbit_osiris_metrics defined by app rabbit
2023-02-13 10:14:52.579863+00:00 [info] <0.230.0> Running boot step rabbit_core_metrics defined by app rabbit
2023-02-13 10:14:52.583045+00:00 [info] <0.230.0> Running boot step rabbit_alarm defined by app rabbit
2023-02-13 10:14:52.593647+00:00 [info] <0.386.0> Memory high watermark set to 9579 MiB (10044358656 bytes) of 23947 MiB (25110896640 bytes) total
2023-02-13 10:14:52.599354+00:00 [info] <0.388.0> Enabling free disk space monitoring (disk free space: 413164699648, total memory: 25110896640)
2023-02-13 10:14:52.599495+00:00 [info] <0.388.0> Disk free limit set to 5000MB
2023-02-13 10:14:52.602932+00:00 [info] <0.230.0> Running boot step code_server_cache defined by app rabbit
2023-02-13 10:14:52.603082+00:00 [info] <0.230.0> Running boot step file_handle_cache defined by app rabbit
2023-02-13 10:14:52.603390+00:00 [info] <0.391.0> Limiting to approx 1048479 file handles (943629 sockets)
2023-02-13 10:14:52.603572+00:00 [info] <0.392.0> FHC read buffering: OFF
2023-02-13 10:14:52.603633+00:00 [info] <0.392.0> FHC write buffering: ON
2023-02-13 10:14:52.604893+00:00 [info] <0.230.0> Running boot step worker_pool defined by app rabbit
2023-02-13 10:14:52.604987+00:00 [info] <0.343.0> Will use 8 processes for default worker pool
2023-02-13 10:14:52.605032+00:00 [info] <0.343.0> Starting worker pool 'worker_pool' with 8 processes in it
2023-02-13 10:14:52.605590+00:00 [info] <0.230.0> Running boot step database defined by app rabbit
2023-02-13 10:14:52.609385+00:00 [info] <0.230.0> Waiting for Mnesia tables for 30000 ms, 9 retries left
2023-02-13 10:14:52.610145+00:00 [info] <0.230.0> Successfully synced tables from a peer
2023-02-13 10:14:52.626980+00:00 [info] <0.230.0> Waiting for Mnesia tables for 30000 ms, 9 retries left
2023-02-13 10:14:52.627371+00:00 [info] <0.230.0> Successfully synced tables from a peer
2023-02-13 10:14:52.627413+00:00 [info] <0.230.0> Peer discovery backend rabbit_peer_discovery_classic_config does not support registration, skipping registration.
2023-02-13 10:14:52.627516+00:00 [info] <0.230.0> Running boot step tracking_metadata_store defined by app rabbit
2023-02-13 10:14:52.627658+00:00 [info] <0.409.0> Setting up a table for connection tracking on this node: tracked_connection
2023-02-13 10:14:52.627752+00:00 [info] <0.409.0> Setting up a table for per-vhost connection counting on this node: tracked_connection_per_vhost
2023-02-13 10:14:52.627829+00:00 [info] <0.409.0> Setting up a table for per-user connection counting on this node: tracked_connection_per_user
2023-02-13 10:14:52.627908+00:00 [info] <0.409.0> Setting up a table for channel tracking on this node: tracked_channel
2023-02-13 10:14:52.627966+00:00 [info] <0.409.0> Setting up a table for channel tracking on this node: tracked_channel_per_user
2023-02-13 10:14:52.628067+00:00 [info] <0.230.0> Running boot step networking_metadata_store defined by app rabbit
2023-02-13 10:14:52.628192+00:00 [info] <0.230.0> Running boot step database_sync defined by app rabbit
2023-02-13 10:14:52.628291+00:00 [info] <0.230.0> Running boot step feature_flags defined by app rabbit
2023-02-13 10:14:52.628436+00:00 [info] <0.230.0> Running boot step codec_correctness_check defined by app rabbit
2023-02-13 10:14:52.628467+00:00 [info] <0.230.0> Running boot step external_infrastructure defined by app rabbit
2023-02-13 10:14:52.628492+00:00 [info] <0.230.0> Running boot step rabbit_event defined by app rabbit
2023-02-13 10:14:52.628653+00:00 [info] <0.230.0> Running boot step rabbit_registry defined by app rabbit
2023-02-13 10:14:52.628751+00:00 [info] <0.230.0> Running boot step rabbit_auth_mechanism_amqplain defined by app rabbit
2023-02-13 10:14:52.628861+00:00 [info] <0.230.0> Running boot step rabbit_auth_mechanism_cr_demo defined by app rabbit
2023-02-13 10:14:52.628939+00:00 [info] <0.230.0> Running boot step rabbit_auth_mechanism_plain defined by app rabbit
2023-02-13 10:14:52.629016+00:00 [info] <0.230.0> Running boot step rabbit_exchange_type_direct defined by app rabbit
2023-02-13 10:14:52.629125+00:00 [info] <0.230.0> Running boot step rabbit_exchange_type_fanout defined by app rabbit
2023-02-13 10:14:52.629199+00:00 [info] <0.230.0> Running boot step rabbit_exchange_type_headers defined by app rabbit
2023-02-13 10:14:52.629259+00:00 [info] <0.230.0> Running boot step rabbit_exchange_type_topic defined by app rabbit
2023-02-13 10:14:52.629323+00:00 [info] <0.230.0> Running boot step rabbit_mirror_queue_mode_all defined by app rabbit
2023-02-13 10:14:52.629387+00:00 [info] <0.230.0> Running boot step rabbit_mirror_queue_mode_exactly defined by app rabbit
2023-02-13 10:14:52.629432+00:00 [info] <0.230.0> Running boot step rabbit_mirror_queue_mode_nodes defined by app rabbit
2023-02-13 10:14:52.629501+00:00 [info] <0.230.0> Running boot step rabbit_priority_queue defined by app rabbit
2023-02-13 10:14:52.629538+00:00 [info] <0.230.0> Priority queues enabled, real BQ is rabbit_variable_queue
2023-02-13 10:14:52.629599+00:00 [info] <0.230.0> Running boot step rabbit_queue_location_client_local defined by app rabbit
2023-02-13 10:14:52.629684+00:00 [info] <0.230.0> Running boot step rabbit_queue_location_min_masters defined by app rabbit
2023-02-13 10:14:52.629731+00:00 [info] <0.230.0> Running boot step rabbit_queue_location_random defined by app rabbit
2023-02-13 10:14:52.629778+00:00 [info] <0.230.0> Running boot step kernel_ready defined by app rabbit
2023-02-13 10:14:52.629819+00:00 [info] <0.230.0> Running boot step rabbit_sysmon_minder defined by app rabbit
2023-02-13 10:14:52.630019+00:00 [info] <0.230.0> Running boot step rabbit_epmd_monitor defined by app rabbit
2023-02-13 10:14:52.630996+00:00 [info] <0.418.0> epmd monitor knows us, inter-node communication (distribution) port: 25672
2023-02-13 10:14:52.631112+00:00 [info] <0.230.0> Running boot step guid_generator defined by app rabbit
2023-02-13 10:14:52.636713+00:00 [info] <0.230.0> Running boot step rabbit_node_monitor defined by app rabbit
2023-02-13 10:14:52.636967+00:00 [info] <0.422.0> Starting rabbit_node_monitor
2023-02-13 10:14:52.637141+00:00 [info] <0.230.0> Running boot step delegate_sup defined by app rabbit
2023-02-13 10:14:52.637757+00:00 [info] <0.230.0> Running boot step rabbit_memory_monitor defined by app rabbit
2023-02-13 10:14:52.637983+00:00 [info] <0.230.0> Running boot step rabbit_fifo_dlx_sup defined by app rabbit
2023-02-13 10:14:52.638066+00:00 [info] <0.230.0> Running boot step core_initialized defined by app rabbit
2023-02-13 10:14:52.638099+00:00 [info] <0.230.0> Running boot step upgrade_queues defined by app rabbit
2023-02-13 10:14:52.647977+00:00 [info] <0.230.0> Running boot step channel_tracking defined by app rabbit
2023-02-13 10:14:52.648238+00:00 [info] <0.230.0> Setting up a table for channel tracking on this node: 'tracked_channel_on_node_rabbit@rs-rabbitmq'
2023-02-13 10:14:52.648440+00:00 [info] <0.230.0> Setting up a table for channel tracking on this node: 'tracked_channel_table_per_user_on_node_rabbit@rs-rabbitmq'
2023-02-13 10:14:52.648669+00:00 [info] <0.230.0> Running boot step rabbit_channel_tracking_handler defined by app rabbit
2023-02-13 10:14:52.648767+00:00 [info] <0.230.0> Running boot step connection_tracking defined by app rabbit
2023-02-13 10:14:52.648942+00:00 [info] <0.230.0> Setting up a table for connection tracking on this node: 'tracked_connection_on_node_rabbit@rs-rabbitmq'
2023-02-13 10:14:52.649098+00:00 [info] <0.230.0> Setting up a table for per-vhost connection counting on this node: 'tracked_connection_per_vhost_on_node_rabbit@rs-rabbitmq'
2023-02-13 10:14:52.649240+00:00 [info] <0.230.0> Setting up a table for per-user connection counting on this node: 'tracked_connection_table_per_user_on_node_rabbit@rs-rabbitmq'
2023-02-13 10:14:52.649470+00:00 [info] <0.230.0> Running boot step rabbit_connection_tracking_handler defined by app rabbit
2023-02-13 10:14:52.649539+00:00 [info] <0.230.0> Running boot step rabbit_definitions_hashing defined by app rabbit
2023-02-13 10:14:52.649665+00:00 [info] <0.230.0> Running boot step rabbit_exchange_parameters defined by app rabbit
2023-02-13 10:14:52.649818+00:00 [info] <0.230.0> Running boot step rabbit_mirror_queue_misc defined by app rabbit
2023-02-13 10:14:52.650030+00:00 [info] <0.230.0> Running boot step rabbit_policies defined by app rabbit
2023-02-13 10:14:52.650498+00:00 [info] <0.230.0> Running boot step rabbit_policy defined by app rabbit
2023-02-13 10:14:52.650589+00:00 [info] <0.230.0> Running boot step rabbit_queue_location_validator defined by app rabbit
2023-02-13 10:14:52.650674+00:00 [info] <0.230.0> Running boot step rabbit_quorum_memory_manager defined by app rabbit
2023-02-13 10:14:52.650745+00:00 [info] <0.230.0> Running boot step rabbit_stream_coordinator defined by app rabbit
2023-02-13 10:14:52.650972+00:00 [info] <0.230.0> Running boot step rabbit_vhost_limit defined by app rabbit
2023-02-13 10:14:52.651055+00:00 [info] <0.230.0> Running boot step rabbit_mgmt_reset_handler defined by app rabbitmq_management
2023-02-13 10:14:52.651132+00:00 [info] <0.230.0> Running boot step rabbit_mgmt_db_handler defined by app rabbitmq_management_agent
2023-02-13 10:14:52.651173+00:00 [info] <0.230.0> Management plugin: using rates mode 'basic'
2023-02-13 10:14:52.654769+00:00 [info] <0.230.0> Running boot step rabbit_shovel_parameters defined by app rabbitmq_shovel
2023-02-13 10:14:52.655034+00:00 [info] <0.230.0> Running boot step recovery defined by app rabbit
2023-02-13 10:14:52.658001+00:00 [info] <0.461.0> Making sure data directory '/var/lib/rabbitmq/mnesia/rabbit@rs-rabbitmq/msg_stores/vhosts/APYN3HZ2FWB83GLCFGRY2DOX4' for vhost 'regards.multitenant.manager' exists
2023-02-13 10:14:59.428418+00:00 [info] <0.461.0> Starting message stores for vhost 'regards.multitenant.manager'
2023-02-13 10:14:59.428864+00:00 [info] <0.466.0> Message store "APYN3HZ2FWB83GLCFGRY2DOX4/msg_store_transient": using rabbit_msg_store_ets_index to provide index
2023-02-13 10:14:59.454687+00:00 [info] <0.461.0> Started message store of type transient for vhost 'regards.multitenant.manager'
2023-02-13 10:14:59.510889+00:00 [info] <0.470.0> Message store "APYN3HZ2FWB83GLCFGRY2DOX4/msg_store_persistent": using rabbit_msg_store_ets_index to provide index
2023-02-13 10:15:04.484452+00:00 [info] <0.461.0> Started message store of type persistent for vhost 'regards.multitenant.manager'
2023-02-13 10:17:39.020799+00:00 [info] <0.461.0> Recovering 141 queues of type rabbit_classic_queue took 166355ms
2023-02-13 10:17:39.020939+00:00 [info] <0.461.0> Recovering 0 queues of type rabbit_quorum_queue took 0ms
2023-02-13 10:17:39.021000+00:00 [info] <0.461.0> Recovering 0 queues of type rabbit_stream_queue took 0ms
2023-02-13 10:17:39.166585+00:00 [info] <0.1977.1> Making sure data directory '/var/lib/rabbitmq/mnesia/rabbit@rs-rabbitmq/msg_stores/vhosts/628WB79CIFDYO9LJI6DKMI09L' for vhost '/' exists
2023-02-13 10:17:39.344372+00:00 [info] <0.1977.1> Starting message stores for vhost '/'
2023-02-13 10:17:39.344748+00:00 [info] <0.1981.1> Message store "628WB79CIFDYO9LJI6DKMI09L/msg_store_transient": using rabbit_msg_store_ets_index to provide index
2023-02-13 10:17:39.378390+00:00 [info] <0.1977.1> Started message store of type transient for vhost '/'
2023-02-13 10:17:39.379057+00:00 [info] <0.1985.1> Message store "628WB79CIFDYO9LJI6DKMI09L/msg_store_persistent": using rabbit_msg_store_ets_index to provide index
2023-02-13 10:17:39.402555+00:00 [info] <0.1977.1> Started message store of type persistent for vhost '/'
2023-02-13 10:17:39.411813+00:00 [info] <0.1977.1> Recovering 1 queues of type rabbit_classic_queue took 201ms
2023-02-13 10:17:39.411925+00:00 [info] <0.1977.1> Recovering 0 queues of type rabbit_quorum_queue took 0ms
2023-02-13 10:17:39.412025+00:00 [info] <0.1977.1> Recovering 0 queues of type rabbit_stream_queue took 0ms
2023-02-13 10:17:39.448687+00:00 [info] <0.2154.1> Making sure data directory '/var/lib/rabbitmq/mnesia/rabbit@rs-rabbitmq/msg_stores/vhosts/CBFRXS0HLQ1RLA9P3Q8UAU5CC' for vhost 'regards.instance.manager' exists
2023-02-13 10:17:39.637135+00:00 [info] <0.2154.1> Starting message stores for vhost 'regards.instance.manager'
2023-02-13 10:17:39.637878+00:00 [info] <0.2158.1> Message store "CBFRXS0HLQ1RLA9P3Q8UAU5CC/msg_store_transient": using rabbit_msg_store_ets_index to provide index
2023-02-13 10:17:39.737745+00:00 [info] <0.2154.1> Started message store of type transient for vhost 'regards.instance.manager'
2023-02-13 10:17:39.739599+00:00 [info] <0.2162.1> Message store "CBFRXS0HLQ1RLA9P3Q8UAU5CC/msg_store_persistent": using rabbit_msg_store_ets_index to provide index
2023-02-13 10:17:39.864375+00:00 [info] <0.2154.1> Started message store of type persistent for vhost 'regards.instance.manager'
2023-02-13 10:17:44.558721+00:00 [info] <0.2154.1> Recovering 3 queues of type rabbit_classic_queue took 5103ms
2023-02-13 10:17:44.558817+00:00 [info] <0.2154.1> Recovering 0 queues of type rabbit_quorum_queue took 0ms
2023-02-13 10:17:44.558849+00:00 [info] <0.2154.1> Recovering 0 queues of type rabbit_stream_queue took 0ms
2023-02-13 10:17:44.586724+00:00 [info] <0.230.0> Running boot step empty_db_check defined by app rabbit
2023-02-13 10:17:44.586821+00:00 [info] <0.230.0> Will not seed default virtual host and user: have definitions to load...
2023-02-13 10:17:44.586845+00:00 [info] <0.230.0> Running boot step rabbit_observer_cli defined by app rabbit
2023-02-13 10:17:44.586940+00:00 [info] <0.230.0> Running boot step rabbit_looking_glass defined by app rabbit
2023-02-13 10:17:44.587013+00:00 [info] <0.230.0> Running boot step rabbit_core_metrics_gc defined by app rabbit
2023-02-13 10:17:44.587143+00:00 [info] <0.230.0> Running boot step background_gc defined by app rabbit
2023-02-13 10:17:44.587371+00:00 [info] <0.230.0> Running boot step routing_ready defined by app rabbit
2023-02-13 10:17:44.587533+00:00 [info] <0.230.0> Running boot step pre_flight defined by app rabbit
2023-02-13 10:17:44.587646+00:00 [info] <0.230.0> Running boot step notify_cluster defined by app rabbit
2023-02-13 10:17:44.587799+00:00 [info] <0.230.0> Running boot step networking defined by app rabbit
2023-02-13 10:17:44.587945+00:00 [info] <0.230.0> Running boot step definition_import_worker_pool defined by app rabbit
2023-02-13 10:17:44.588067+00:00 [info] <0.343.0> Starting worker pool 'definition_import_pool' with 8 processes in it
2023-02-13 10:17:44.588586+00:00 [info] <0.230.0> Running boot step cluster_name defined by app rabbit
2023-02-13 10:17:44.588807+00:00 [info] <0.230.0> Running boot step direct_client defined by app rabbit
2023-02-13 10:17:44.588907+00:00 [info] <0.230.0> Running boot step rabbit_maintenance_mode_state defined by app rabbit
2023-02-13 10:17:44.588938+00:00 [info] <0.230.0> Creating table rabbit_node_maintenance_states for maintenance mode status
2023-02-13 10:17:44.589088+00:00 [info] <0.230.0> Running boot step rabbit_management_load_definitions defined by app rabbitmq_management
2023-02-13 10:17:44.589775+00:00 [info] <0.230.0> Applying definitions from file at '/etc/rabbitmq/definitions.json'
2023-02-13 10:17:44.589837+00:00 [info] <0.230.0> Asked to import definitions. Acting user: rmq-internal
2023-02-13 10:17:44.589938+00:00 [info] <0.230.0> Importing concurrently 1 users...
2023-02-13 10:17:44.592667+00:00 [info] <0.230.0> Importing concurrently 3 vhosts...
2023-02-13 10:17:44.596844+00:00 [info] <0.230.0> Importing concurrently 3 permissions...
2023-02-13 10:17:44.599955+00:00 [info] <0.3112.1> Successfully set permissions for 'guest' in virtual host 'regards.instance.manager' to '.*', '.*', '.*'
2023-02-13 10:17:44.599981+00:00 [info] <0.3111.1> Successfully set permissions for 'guest' in virtual host 'regards.multitenant.manager' to '.*', '.*', '.*'
2023-02-13 10:17:44.600103+00:00 [info] <0.3110.1> Successfully set permissions for 'guest' in virtual host '/' to '.*', '.*', '.*'
2023-02-13 10:17:44.634826+00:00 [info] <0.3137.1> Resetting node maintenance status
2023-02-13 10:17:44.753552+00:00 [info] <0.3202.1> Management plugin: HTTP (non-TLS) listener started on port 15672
2023-02-13 10:17:44.753808+00:00 [info] <0.3230.1> Statistics database started.
2023-02-13 10:17:44.753982+00:00 [info] <0.3229.1> Starting worker pool 'management_worker_pool' with 3 processes in it
2023-02-13 10:17:44.769262+00:00 [info] <0.3258.1> Prometheus metrics: HTTP (non-TLS) listener started on port 15692
2023-02-13 10:17:44.769533+00:00 [info] <0.3137.1> Ready to start client connection listeners
2023-02-13 10:17:44.772089+00:00 [info] <0.3302.1> started TCP listener on [::]:5672

The server boots under 3 mins, which is much better. The main difference so far is this log :

# after a rabbitmqctl shutdown 
2023-02-13 10:14:59.428418+00:00 [info] <0.461.0> Starting message stores for vhost 'regards.multitenant.manager'
2023-02-13 10:14:59.428864+00:00 [info] <0.466.0> Message store "APYN3HZ2FWB83GLCFGRY2DOX4/msg_store_transient": using rabbit_msg_store_ets_index to provide index

# after a SIGTERM shutdown 
2023-02-10 08:36:53.894158+00:00 [info] <0.14698.1> Message store "CBFRXS0HLQ1RLA9P3Q8UAU5CC/msg_store_persistent": using rabbit_msg_store_ets_index to provide index
2023-02-10 08:36:53.898406+00:00 [warning] <0.14698.1> Message store "CBFRXS0HLQ1RLA9P3Q8UAU5CC/msg_store_persistent": rebuilding indices from scratch

There is no indices to rebuild from scratch after a rabbitmqctl shutdown but there is after after a SIGTERM.

May I ask you why you move this as a discussion ?

0 replies

lukebakken · 2023-02-22T21:04:59Z

lukebakken
Feb 22, 2023
Maintainer

cc @michaelklishin @dumbbell the code that is executed when SIGTERM is caught is not identical to the code when rabbitmqctl shutdown is run.

In the case of SIGTERM, init:stop() is immediately called.
In the case of rabbitmqctl shutdown, the following functions are called:
https://github.com/rabbitmq/rabbitmq-server/blob/main/deps/rabbit/src/rabbit.erl#L462-L490
https://github.com/rabbitmq/rabbitmq-server/blob/main/deps/rabbit/src/rabbit.erl#L430-L449
https://github.com/rabbitmq/rabbitmq-server/blob/main/deps/rabbit/src/rabbit.erl#L451-L458

The biggest difference I see is that rabbit:do_stop/0 modifies the order in which applications are stopped.

I still have yet to reliably duplicate the "rebuilding" message.

4 replies

michaelklishin Feb 23, 2023
Maintainer

I would say SIGTERM should be handled the same way ctl shutdown is.

dumbbell Feb 23, 2023
Maintainer

That applications ordering would be the same as what the application master does. We are just re-inventing the wheel here.

If there is a difference in behavior (beside logged messages), then something is wrong in either our supervision trees or the declared dependencies (or both).

If our supervision trees are correct, then every standard Erlang methods and tools will work out-of-the-box: explicit init:stop/0, SIGTERM, erl_call -q, Erlang heartbeat monitor, Erlang releases, etc.

lukebakken Feb 23, 2023
Maintainer

Thanks! Yeah I'll know more if/when I can reliably reproduce this.

dumbbell Feb 24, 2023
Maintainer

Note that there is a known issue with Ra and Osiris supervision trees: we start processes under Ra and Osiris supervision trees which depend on processes started under the rabbit supervision tree. rabbit is stopped first because it depends on both Ra and Osiris, so there is a time window between that and the time Osiris ans Ra are stopped where these processes can't work properly. See #6960.

But this issue remains, regardless of the way we stop RabbitMQ. It is just that we can't stop rabbit without stopping osiris and ra.

lukebakken · 2023-04-10T15:49:14Z

lukebakken
Apr 10, 2023
Maintainer

Here's a test I did with main.

Start RabbitMQ (make FULL=1 RABBITMQ_CONFIG_FILE="/home/lbakken/development/lukebakken/rabbitmq/conf/rabbitmq.conf" PLUGINS='rabbitmq_management rabbitmq_top' run-broker)
Publish 6000+ persistent messages to durable queues (in rabbitmq/rabbitmq-perf-test: make ARGS="--auto-delete false --flag persistent --flag mandatory --producers 6 --consumers 0 --pmessages 1024 --confirm 128 --queue-pattern rabbitmq-server-7253-%d --queue-pattern-from 0 --queue-pattern-to 5 --size 8192" run)
Stop via TERM and restart a few times

$ rg --no-ignore --hidden --glob '*.log' --fixed-strings rebuild /tmp/rabbitmq-test-instances/
/tmp/rabbitmq-test-instances/rabbit@shostakovich/log/[email protected]
893:2023-04-10 08:21:56.870210-07:00 [debug] <0.560.0> Done rebuilding message refcount
895:2023-04-10 08:21:56.870643-07:00 [debug] <0.560.0> Finished rebuilding index
898:2023-04-10 08:21:56.871664-07:00 [warning] <0.564.0> Message store "628WB79CIFDYO9LJI6DKMI09L/msg_store_persistent": rebuilding indices from scratch
901:2023-04-10 08:21:56.872106-07:00 [debug] <0.564.0> Done rebuilding message refcount
903:2023-04-10 08:21:56.872515-07:00 [debug] <0.564.0> Finished rebuilding index
1834:2023-04-10 08:26:01.335317-07:00 [debug] <0.469.0> Done rebuilding message refcount
1836:2023-04-10 08:26:01.336248-07:00 [debug] <0.469.0> Finished rebuilding index
1840:2023-04-10 08:26:01.347234-07:00 [debug] <0.473.0> Finished rebuilding index
2704:2023-04-10 08:27:24.811736-07:00 [debug] <0.449.0> Done rebuilding message refcount
2706:2023-04-10 08:27:24.812179-07:00 [debug] <0.449.0> Finished rebuilding index
2710:2023-04-10 08:27:24.818538-07:00 [debug] <0.453.0> Finished rebuilding index
3667:2023-04-10 08:41:08.821552-07:00 [debug] <0.449.0> Done rebuilding message refcount
3669:2023-04-10 08:41:08.821862-07:00 [debug] <0.449.0> Finished rebuilding index
3673:2023-04-10 08:41:08.828097-07:00 [debug] <0.453.0> Finished rebuilding index
4618:2023-04-10 08:45:44.707994-07:00 [debug] <0.449.0> Done rebuilding message refcount
4620:2023-04-10 08:45:44.708304-07:00 [debug] <0.449.0> Finished rebuilding index
4624:2023-04-10 08:45:44.712921-07:00 [debug] <0.453.0> Finished rebuilding index
5458:2023-04-10 08:46:19.769953-07:00 [debug] <0.449.0> Done rebuilding message refcount
5460:2023-04-10 08:46:19.770409-07:00 [debug] <0.449.0> Finished rebuilding index
5464:2023-04-10 08:46:19.775900-07:00 [debug] <0.453.0> Finished rebuilding index

Note that indices were only rebuilt from scratch on the first start of RabbitMQ, as I would expect.

Going to try out the same tests using Docker next.

0 replies

lukebakken · 2023-04-10T17:45:49Z

lukebakken
Apr 10, 2023
Maintainer

Here is the repo with GNU make targets to start, stop and restart RabbitMQ via docker - https://github.com/lukebakken/rabbitmq-server-7253

In the log file, you can see that the only time indices are rebuilt from scratch is when the container is terminated via docker kill.

So, at this point, I don't see an issue to fix.

$ rg --no-ignore --hidden --fixed-strings rebuild ./var-log-rabbitmq
./var-log-rabbitmq/[email protected]
1670:2023-04-10 16:06:41.685905+00:00 [debug] <0.689.0> Done rebuilding message refcount
1672:2023-04-10 16:06:41.686318+00:00 [debug] <0.689.0> Finished rebuilding index
1675:2023-04-10 16:06:41.687209+00:00 [warning] <0.693.0> Message store "628WB79CIFDYO9LJI6DKMI09L/msg_store_persistent": rebuilding indices from scratch
1678:2023-04-10 16:06:41.687572+00:00 [debug] <0.693.0> Done rebuilding message refcount
1680:2023-04-10 16:06:41.687928+00:00 [debug] <0.693.0> Finished rebuilding index
2475:2023-04-10 16:07:25.166074+00:00 [debug] <0.470.0> Done rebuilding message refcount
2477:2023-04-10 16:07:25.166477+00:00 [debug] <0.470.0> Finished rebuilding index
2481:2023-04-10 16:07:25.168146+00:00 [debug] <0.474.0> Finished rebuilding index
3263:2023-04-10 17:35:11.479678+00:00 [debug] <0.437.0> Done rebuilding message refcount
3265:2023-04-10 17:35:11.479982+00:00 [debug] <0.437.0> Finished rebuilding index
3269:2023-04-10 17:35:11.481309+00:00 [debug] <0.441.0> Finished rebuilding index
4051:2023-04-10 17:36:14.270340+00:00 [debug] <0.437.0> Done rebuilding message refcount
4053:2023-04-10 17:36:14.270698+00:00 [debug] <0.437.0> Finished rebuilding index
4057:2023-04-10 17:36:14.272120+00:00 [debug] <0.441.0> Finished rebuilding index

I ran make kill at this point...

4818:2023-04-10 17:37:01.393217+00:00 [debug] <0.437.0> Done rebuilding message refcount
4820:2023-04-10 17:37:01.393563+00:00 [debug] <0.437.0> Finished rebuilding index
4823:2023-04-10 17:37:01.394254+00:00 [warning] <0.441.0> Message store "628WB79CIFDYO9LJI6DKMI09L/msg_store_persistent": rebuilding indices from scratch
4826:2023-04-10 17:37:01.394534+00:00 [debug] <0.441.0> Done rebuilding message refcount
4828:2023-04-10 17:37:01.394947+00:00 [debug] <0.441.0> Finished rebuilding index

0 replies

Gracefully shutdown on docker stop #7253

Uh oh!

Uh oh!

serut Feb 10, 2023

Replies: 6 comments · 6 replies

Uh oh!

michaelklishin Feb 10, 2023 Maintainer

Uh oh!

Uh oh!

lukebakken Feb 10, 2023 Maintainer

Uh oh!

michaelklishin Feb 11, 2023 Maintainer

Uh oh!

lukebakken Feb 14, 2023 Maintainer

Uh oh!

Uh oh!

serut Feb 13, 2023 Author

Uh oh!

lukebakken Feb 22, 2023 Maintainer

Uh oh!

michaelklishin Feb 23, 2023 Maintainer

Uh oh!

dumbbell Feb 23, 2023 Maintainer

Uh oh!

lukebakken Feb 23, 2023 Maintainer

Uh oh!

dumbbell Feb 24, 2023 Maintainer

Uh oh!

Uh oh!

lukebakken Apr 10, 2023 Maintainer

Uh oh!

lukebakken Apr 10, 2023 Maintainer

serut
Feb 10, 2023

Replies: 6 comments 6 replies

michaelklishin
Feb 10, 2023
Maintainer

lukebakken
Feb 10, 2023
Maintainer

michaelklishin Feb 11, 2023
Maintainer

lukebakken Feb 14, 2023
Maintainer

serut
Feb 13, 2023
Author

lukebakken
Feb 22, 2023
Maintainer

michaelklishin Feb 23, 2023
Maintainer

dumbbell Feb 23, 2023
Maintainer

lukebakken Feb 23, 2023
Maintainer

dumbbell Feb 24, 2023
Maintainer

lukebakken
Apr 10, 2023
Maintainer

lukebakken
Apr 10, 2023
Maintainer