Skip to content

"RabbitMQ probably didn't start properly." but it did !

Summary

Starting service rabbitmq:alpine ...
Pulling docker image rabbitmq:alpine ...
Using docker image sha256:84fca87b603ec051bbdb13d5f148aa37000fb26c600d7f387f3f15f1592be8f1 for rabbitmq:alpine ...
WARNING: Service rabbitmq:alpine is already created. Ignoring.
[...]
Waiting for services to be up and running...

*** WARNING: Service runner-311b35d2-project-5265984-concurrent-0-rabbitmq-1 probably didn't start properly.

service runner-311b35d2-project-5265984-concurrent-0-rabbitmq-1-wait-for-service did timeout

2018-03-15T12:32:02.952395196Z 2018-03-15 12:32:02.923 [info] <0.33.0> Application lager started on node rabbit@cc74f70c7be5
2018-03-15T12:32:03.983288125Z 2018-03-15 12:32:03.982 [info] <0.33.0> Application xmerl started on node rabbit@cc74f70c7be5
2018-03-15T12:32:03.984842243Z 2018-03-15 12:32:03.984 [info] <0.33.0> Application crypto started on node rabbit@cc74f70c7be5
2018-03-15T12:32:03.985126212Z 2018-03-15 12:32:03.984 [info] <0.33.0> Application recon started on node rabbit@cc74f70c7be5
2018-03-15T12:32:03.985337598Z 2018-03-15 12:32:03.985 [info] <0.33.0> Application jsx started on node rabbit@cc74f70c7be5
2018-03-15T12:32:04.283779235Z 2018-03-15 12:32:04.283 [info] <0.33.0> Application mnesia started on node rabbit@cc74f70c7be5
2018-03-15T12:32:04.291769127Z 2018-03-15 12:32:04.291 [info] <0.33.0> Application os_mon started on node rabbit@cc74f70c7be5
2018-03-15T12:32:04.294556981Z 2018-03-15 12:32:04.294 [info] <0.33.0> Application asn1 started on node rabbit@cc74f70c7be5
2018-03-15T12:32:04.294801476Z 2018-03-15 12:32:04.294 [info] <0.33.0> Application public_key started on node rabbit@cc74f70c7be5
2018-03-15T12:32:04.424697741Z 2018-03-15 12:32:04.424 [info] <0.33.0> Application ssl started on node rabbit@cc74f70c7be5
2018-03-15T12:32:04.430527209Z 2018-03-15 12:32:04.430 [info] <0.33.0> Application ranch started on node rabbit@cc74f70c7be5
2018-03-15T12:32:04.431612159Z 2018-03-15 12:32:04.431 [info] <0.33.0> Application ranch_proxy_protocol started on node rabbit@cc74f70c7be5
2018-03-15T12:32:04.431935481Z 2018-03-15 12:32:04.431 [info] <0.33.0> Application rabbit_common started on node rabbit@cc74f70c7be5
2018-03-15T12:32:04.555111049Z 2018-03-15 12:32:04.554 [info] <0.33.0> Application inets started on node rabbit@cc74f70c7be5
2018-03-15T12:32:04.571579409Z 2018-03-15 12:32:04.571 [info] <0.183.0> 
2018-03-15T12:32:04.571603329Z  Starting RabbitMQ 3.7.4 on Erlang 20.1.7
2018-03-15T12:32:04.571606584Z  Copyright (C) 2007-2018 Pivotal Software, Inc.
2018-03-15T12:32:04.571609119Z  Licensed under the MPL.  See http://www.rabbitmq.com/
2018-03-15T12:32:04.574421833Z 
2018-03-15T12:32:04.574442581Z   ##  ##
2018-03-15T12:32:04.574445865Z   ##  ##      RabbitMQ 3.7.4. Copyright (C) 2007-2018 Pivotal Software, Inc.
2018-03-15T12:32:04.574448772Z   ##########  Licensed under the MPL.  See http://www.rabbitmq.com/
2018-03-15T12:32:04.574451268Z   ######  ##
2018-03-15T12:32:04.574453533Z   ##########  Logs: <stdout>
2018-03-15T12:32:04.574456601Z 
2018-03-15T12:32:04.574458848Z               Starting broker...
2018-03-15T12:32:04.638061584Z 2018-03-15 12:32:04.637 [info] <0.183.0> 
2018-03-15T12:32:04.638085728Z  node           : rabbit@cc74f70c7be5
2018-03-15T12:32:04.638088948Z  home dir       : /var/lib/rabbitmq
2018-03-15T12:32:04.638091644Z  config file(s) : /etc/rabbitmq/rabbitmq.conf
2018-03-15T12:32:04.638105575Z  cookie hash    : ltoNd7Hrv26GgV71YBJcew==
2018-03-15T12:32:04.638108429Z  log(s)         : <stdout>
2018-03-15T12:32:04.638128552Z  database dir   : /var/lib/rabbitmq/mnesia/rabbit@cc74f70c7be5
2018-03-15T12:32:09.507151515Z 2018-03-15 12:32:09.506 [info] <0.191.0> Memory high watermark set to 1479 MiB (1550866841 bytes) of 3697 MiB (3877167104 bytes) total
2018-03-15T12:32:09.514774133Z 2018-03-15 12:32:09.514 [info] <0.193.0> Enabling free disk space monitoring
2018-03-15T12:32:09.514804830Z 2018-03-15 12:32:09.514 [info] <0.193.0> Disk free limit set to 50MB
2018-03-15T12:32:09.520747487Z 2018-03-15 12:32:09.520 [info] <0.195.0> Limiting to approx 1048476 file handles (943626 sockets)
2018-03-15T12:32:09.520768875Z 2018-03-15 12:32:09.520 [info] <0.196.0> FHC read buffering:  OFF
2018-03-15T12:32:09.520772711Z 2018-03-15 12:32:09.520 [info] <0.196.0> FHC write buffering: ON
2018-03-15T12:32:09.522393122Z 2018-03-15 12:32:09.522 [info] <0.183.0> Node database directory at /var/lib/rabbitmq/mnesia/rabbit@cc74f70c7be5 is empty. Assuming we need to join an existing cluster or initialise from scratch...
2018-03-15T12:32:09.523464339Z 2018-03-15 12:32:09.522 [info] <0.183.0> Configured peer discovery backend: rabbit_peer_discovery_classic_config
2018-03-15T12:32:09.523701925Z 2018-03-15 12:32:09.523 [info] <0.183.0> Will try to lock with peer discovery backend rabbit_peer_discovery_classic_config
2018-03-15T12:32:09.523710478Z 2018-03-15 12:32:09.523 [info] <0.183.0> Peer discovery backend does not support locking, falling back to randomized delay
2018-03-15T12:32:09.523976342Z 2018-03-15 12:32:09.523 [info] <0.183.0> Peer discovery backend rabbit_peer_discovery_classic_config does not support registration, skipping randomized startup delay.
2018-03-15T12:32:09.523985292Z 2018-03-15 12:32:09.523 [info] <0.183.0> All discovered existing cluster peers: 
2018-03-15T12:32:09.524165745Z 2018-03-15 12:32:09.523 [info] <0.183.0> Discovered no peer nodes to cluster with
2018-03-15T12:32:09.530394088Z 2018-03-15 12:32:09.527 [info] <0.33.0> Application mnesia exited with reason: stopped
2018-03-15T12:32:09.557234044Z 2018-03-15 12:32:09.557 [info] <0.33.0> Application mnesia started on node rabbit@cc74f70c7be5
2018-03-15T12:32:09.751684295Z 2018-03-15 12:32:09.751 [info] <0.183.0> Waiting for Mnesia tables for 30000 ms, 9 retries left
2018-03-15T12:32:09.776575125Z 2018-03-15 12:32:09.776 [info] <0.183.0> Waiting for Mnesia tables for 30000 ms, 9 retries left
2018-03-15T12:32:09.818434452Z 2018-03-15 12:32:09.816 [info] <0.183.0> Waiting for Mnesia tables for 30000 ms, 9 retries left
2018-03-15T12:32:09.818751264Z 2018-03-15 12:32:09.818 [info] <0.183.0> Peer discovery backend rabbit_peer_discovery_classic_config does not support registration, skipping registration.
2018-03-15T12:32:09.819701250Z 2018-03-15 12:32:09.819 [info] <0.183.0> Priority queues enabled, real BQ is rabbit_variable_queue
2018-03-15T12:32:09.826564829Z 2018-03-15 12:32:09.826 [info] <0.363.0> Starting rabbit_node_monitor
2018-03-15T12:32:09.853696115Z 2018-03-15 12:32:09.853 [info] <0.183.0> message_store upgrades: 1 to apply
2018-03-15T12:32:09.854013857Z 2018-03-15 12:32:09.853 [info] <0.183.0> message_store upgrades: Applying rabbit_variable_queue:move_messages_to_vhost_store
2018-03-15T12:32:09.854216991Z 2018-03-15 12:32:09.854 [info] <0.183.0> message_store upgrades: No durable queues found. Skipping message store migration
2018-03-15T12:32:09.854378468Z 2018-03-15 12:32:09.854 [info] <0.183.0> message_store upgrades: Removing the old message store data
2018-03-15T12:32:09.855201464Z 2018-03-15 12:32:09.854 [info] <0.183.0> message_store upgrades: All upgrades applied successfully
2018-03-15T12:32:09.885951958Z 2018-03-15 12:32:09.885 [info] <0.183.0> Adding vhost '/'
2018-03-15T12:32:09.956152779Z 2018-03-15 12:32:09.955 [info] <0.397.0> Making sure data directory '/var/lib/rabbitmq/mnesia/rabbit@cc74f70c7be5/msg_stores/vhosts/628WB79CIFDYO9LJI6DKMI09L' for vhost '/' exists
2018-03-15T12:32:09.965307857Z 2018-03-15 12:32:09.964 [info] <0.397.0> Starting message stores for vhost '/'
2018-03-15T12:32:09.965671686Z 2018-03-15 12:32:09.965 [info] <0.401.0> Message store "628WB79CIFDYO9LJI6DKMI09L/msg_store_transient": using rabbit_msg_store_ets_index to provide index
2018-03-15T12:32:09.966930491Z 2018-03-15 12:32:09.966 [info] <0.397.0> Started message store of type transient for vhost '/'
2018-03-15T12:32:09.967218451Z 2018-03-15 12:32:09.967 [info] <0.404.0> Message store "628WB79CIFDYO9LJI6DKMI09L/msg_store_persistent": using rabbit_msg_store_ets_index to provide index
2018-03-15T12:32:09.967884758Z 2018-03-15 12:32:09.967 [warning] <0.404.0> Message store "628WB79CIFDYO9LJI6DKMI09L/msg_store_persistent": rebuilding indices from scratch
2018-03-15T12:32:09.968718907Z 2018-03-15 12:32:09.968 [info] <0.397.0> Started message store of type persistent for vhost '/'
2018-03-15T12:32:09.971727750Z 2018-03-15 12:32:09.971 [info] <0.183.0> Creating user 'guest'
2018-03-15T12:32:09.980844092Z 2018-03-15 12:32:09.980 [info] <0.183.0> Setting user tags for user 'guest' to [administrator]
2018-03-15T12:32:09.985554728Z 2018-03-15 12:32:09.985 [info] <0.183.0> Setting permissions for 'guest' in '/' to '.*', '.*', '.*'
2018-03-15T12:32:09.996350274Z 2018-03-15 12:32:09.996 [info] <0.442.0> started TCP Listener on [::]:5672
2018-03-15T12:32:10.009068978Z 2018-03-15 12:32:10.008 [info] <0.183.0> Setting up a table for connection tracking on this node: tracked_connection_on_node_rabbit@cc74f70c7be5
2018-03-15T12:32:10.013612016Z 2018-03-15 12:32:10.013 [info] <0.183.0> Setting up a table for per-vhost connection counting on this node: tracked_connection_per_vhost_on_node_rabbit@cc74f70c7be5
2018-03-15T12:32:10.014498060Z 2018-03-15 12:32:10.014 [info] <0.33.0> Application rabbit started on node rabbit@cc74f70c7be5
2018-03-15T12:32:10.263552976Z 2018-03-15 12:32:10.263 [info] <0.5.0> Server startup complete; 0 plugins started.
2018-03-15T12:32:10.263731043Z  completed with 0 plugins.

*********

Steps to reproduce

I try to load service rabbitmq : https://hub.docker.com/_/rabbitmq/ I try latest, alpine, management, alpine-managment.

I try too this image to https://hub.docker.com/r/healthcheck/rabbitmq/

Example Project

Bug reproduce on Gitlab.com private project, with docker+machine on Google Cloud I add: i have this problem only for rabbitmq, no problem with mysq, redis or elasticsearch

What is the current bug behavior?

*** WARNING: Service runner-311b35d2-project-5265984-concurrent-0-rabbitmq-1 probably didn't start properly. service runner-311b35d2-project-5265984-concurrent-0-rabbitmq-1-wait-for-service did timeout

What is the expected correct behavior?

Not say the previous quote, because the service was up in less than 8sec

Relevant logs and/or screenshots

(Paste any relevant logs - please use code blocks (```) to format console output, logs, and code as it's very hard to read otherwise.)

Output of checks

This bug happens on GitLab.com but on Gitlab-runner on Gcloud (docker+machine)