deploy fails at rabbitmq because epmd does not start

[Taisto Qvist]

This is related to #1855935, but I was asked to create a separate bugreport.

I am running kolla-ansible:train, in multinode centos-7.7 deployment, deploying to a varying number of hosts, but it always fails when rabbitmq should be started, but it always ends with:

+ exec /usr/sbin/rabbitmq-server
econnrefused
Protocol 'inet_tcp': register/listen error:

It turned out my hosts file had duplicate entries, since kolla-ansible simply appends to /etc/hosts, and I had already prepared it fully on all hosts.

But I have now tried with several versions of hosts files, and it never changes anything, even with a single "172.16.102.100 ctrl1.lab2.stack" entry.

--Original hosts file--
[root@compute1 ~(admin)]# cat /etc/hosts
127.0.0.1 localhost
::1 localhost localhost.localdomain localhost6 localhost6.localdomain6

172.16.102.100 ctrl1.lab2.stack controller1.lab2.stack ctrl1 controller1
172.16.102.109 ctrl2.lab2.stack controller2.lab2.stack ctrl2 controller2
172.16.102.101 compute1.lab2.stack compute1
172.16.102.102 compute2.lab2.stack compute2
172.16.102.103 compute3.lab2.stack compute3
172.16.102.104 neutron1.lab2.stack neutron1
172.16.102.105 neutron2.lab2.stack neutron2
172.16.102.106 storage1.lab2.stack storage1
172.16.102.107 storage2.lab2.stack storage2
172.16.102.108 storage3.lab2.stack storage3
# BEGIN ANSIBLE GENERATED HOSTS
172.16.102.100 ctrl1.lab2.stack ctrl1
172.16.102.104 neutron1.lab2.stack neutron1
172.16.102.101 compute1.lab2.stack compute1
172.16.102.106 storage1.lab2.stack storage1
# END ANSIBLE GENERATED HOSTS
--End

I also tried switching to the "kolla/centos-binary-rabbitmq:train" images instead of source, but the same result.

What I have noticed just now though, since the econnrefused doesnt sound like rev-lookup failure, is that starting a shell in kolla_toolbox container, and manually running epmd in that one, will then make easy to start the rabbitmq server in its own container.

What I cant figure out, is how epmd is supposed to be started "normally".

I've tried upping the log-level of rabbitmq with "log.default.level = debug", but it doesn't seem to kick in, and I'm quite a n00b on rabbitmq.

[Radosław Piliszek (yoctozepto)]

RabbitMQ spawns its own epmd for itself in the same container. Your issue is indeed different than the other's. Your /etc/hosts is just fine, same duplicates are fine. You can turn off kolla-ansible creating new by disabling hosts management but it is irrelevant in here.

Did you tweak anything related to networking in comparison to standard install?

[Radosław Piliszek (yoctozepto)]

... of CentOS 7 that is.

[Radosław Piliszek (yoctozepto)]

If you can spare some mind cycles, here is the script that is being run by RMQ: https://github.com/rabbitmq/rabbitmq-server/blob/v3.7.10/scripts/rabbitmq-server
It essentially launches epmd before rmq so we should, theoretically, at least see an error message from epmd itself here.

[Taisto Qvist (theque42)]

Its strange that I dont see anything from that start of epmd then, that seems to fail.
The full log output from docker logs rabbitmq, is:

+ sudo -E kolla_set_configs
INFO:__main__:Loading config file at /var/lib/kolla/config_files/config.json
INFO:__main__:Validating config file
INFO:__main__:Kolla config strategy set to: COPY_ALWAYS
INFO:__main__:Copying service configuration files
INFO:__main__:Copying /var/lib/kolla/config_files/rabbitmq-env.conf to /etc/rabbitmq/rabbitmq-env.conf
INFO:__main__:Setting permission for /etc/rabbitmq/rabbitmq-env.conf
INFO:__main__:Copying /var/lib/kolla/config_files/rabbitmq.conf to /etc/rabbitmq/rabbitmq.conf
INFO:__main__:Setting permission for /etc/rabbitmq/rabbitmq.conf
INFO:__main__:Copying /var/lib/kolla/config_files/erl_inetrc to /etc/rabbitmq/erl_inetrc
INFO:__main__:Setting permission for /etc/rabbitmq/erl_inetrc
INFO:__main__:Copying /var/lib/kolla/config_files/definitions.json to /etc/rabbitmq/definitions.json
INFO:__main__:Setting permission for /etc/rabbitmq/definitions.json
INFO:__main__:Writing out command to execute
INFO:__main__:Setting permission for /var/lib/rabbitmq
INFO:__main__:Setting permission for /var/lib/rabbitmq/.erlang.cookie
++ cat /run_command
+ CMD=/usr/sbin/rabbitmq-server
+ ARGS=
+ sudo kolla_copy_cacerts
+ [[ ! -n '' ]]
+ . kolla_extend_start
++ : /var/log/kolla/rabbitmq
++ [[ -n '' ]]
++ [[ ! -d /var/log/kolla/rabbitmq ]]
++ mkdir -p /var/log/kolla/rabbitmq
+++ stat -c %a /var/log/kolla/rabbitmq
++ [[ 2755 != \7\5\5 ]]
++ chmod 755 /var/log/kolla/rabbitmq
+ echo 'Running command: '\''/usr/sbin/rabbitmq-server'\'''
+ exec /usr/sbin/rabbitmq-server
Running command: '/usr/sbin/rabbitmq-server'
econnrefused
Protocol 'inet_tcp': register/listen error:

[Taisto Qvist (theque42)]

[root@ctrl1 ~(admin)]# ip link
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN mode DEFAULT group default qlen 1000
    link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
2: bond0: <BROADCAST,MULTICAST,MASTER> mtu 1500 qdisc noop state DOWN mode DEFAULT group default qlen 1000
    link/ether 9e:f2:d8:78:dd:0d brd ff:ff:ff:ff:ff:ff
3: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UP mode DEFAULT group default qlen 1000
    link/ether 52:54:de:a2:a1:00 brd ff:ff:ff:ff:ff:ff
4: eth1: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UP mode DEFAULT group default qlen 1000
    link/ether 52:54:de:a2:a1:11 brd ff:ff:ff:ff:ff:ff
5: eth2: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UP mode DEFAULT group default qlen 1000
    link/ether 52:54:de:a2:a1:22 brd ff:ff:ff:ff:ff:ff
6: eth3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UP mode DEFAULT group default qlen 1000
    link/ether 52:54:de:a2:a1:33 brd ff:ff:ff:ff:ff:ff
7: docker0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UP mode DEFAULT group default
    link/ether 02:42:54:39:f1:fb brd ff:ff:ff:ff:ff:ff
23: vethb2c1b6a@if22: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue master docker0 state UP mode DEFAULT group default
    link/ether 0e:dc:54:e2:ef:a1 brd ff:ff:ff:ff:ff:ff link-netnsid 0
27: vethd97f74d@if26: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue master docker0 state UP mode DEFAULT group default
    link/ether 1e:1f:f1:4c:36:a4 brd ff:ff:ff:ff:ff:ff link-netnsid 1
[lab2]:admin@admin
[root@ctrl1 ~(admin)]# ip addr
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN group default qlen 1000
    link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
    inet 127.0.0.1/8 scope host lo
       valid_lft forever preferred_lft forever
2: bond0: <BROADCAST,MULTICAST,MASTER> mtu 1500 qdisc noop state DOWN group default qlen 1000
    link/ether 9e:f2:d8:78:dd:0d brd ff:ff:ff:ff:ff:ff
3: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UP group default qlen 1000
    link/ether 52:54:de:a2:a1:00 brd ff:ff:ff:ff:ff:ff
    inet 10.10.102.100/16 brd 10.10.255.255 scope global eth0
       valid_lft forever preferred_lft forever
4: eth1: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UP group default qlen 1000
    link/ether 52:54:de:a2:a1:11 brd ff:ff:ff:ff:ff:ff
    inet 172.16.102.100/24 brd 172.16.102.255 scope global eth1
       valid_lft forever preferred_lft forever
5: eth2: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UP group default qlen 1000
    link/ether 52:54:de:a2:a1:22 brd ff:ff:ff:ff:ff:ff
    inet 172.20.102.100/24 brd 172.20.102.255 scope global eth2
       valid_lft forever preferred_lft forever
6: eth3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UP group default qlen 1000
    link/ether 52:54:de:a2:a1:33 brd ff:ff:ff:ff:ff:ff
    inet 172.24.102.100/24 brd 172.24.102.255 scope global eth3
       valid_lft forever preferred_lft forever
7: docker0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UP group default
    link/et...

[Taisto Qvist (theque42)]

[root@ctrl1 rabbitmq(admin)]# cat rabbitmq.conf
# NOTE(yoctozepto): rabbitmq uses the raw format (e.g. fd::) of IPv6 address;
# despite specifying port via colon, the url format (e.g. [fd::]) is not accepted
listeners.tcp.1 = 172.16.102.100:5672
cluster_partition_handling = pause_minority

management.listener.ip = 172.16.102.100
management.listener.port = 15672
management.load_definitions = /etc/rabbitmq/definitions.json

cluster_formation.peer_discovery_backend = rabbit_peer_discovery_classic_config
cluster_formation.classic_config.nodes.0 = rabbit@ctrl1
cluster_formation.classic_config.nodes.1 = rabbit@ctrl2
[lab2]:admin@admin
[root@ctrl1 rabbitmq(admin)]#

[Taisto Qvist (theque42)]

[root@ctrl1 rabbitmq(admin)]# cat rabbitmq-env.conf
RABBITMQ_NODENAME=rabbit@ctrl1
RABBITMQ_LOG_BASE=/var/log/kolla/rabbitmq
RABBITMQ_DIST_PORT=25672
RABBITMQ_PID_FILE=/var/lib/rabbitmq/mnesia/rabbitmq.pid
RABBITMQ_SERVER_ADDITIONAL_ERL_ARGS="-kernel inetrc '/etc/rabbitmq/erl_inetrc' "
RABBITMQ_CTL_ERL_ARGS=""

export ERL_EPMD_ADDRESS=172.16.102.100
export ERL_EPMD_PORT=4369

[Taisto Qvist (theque42)]

Let me know what more info you would require. I dont think I have made any unusual changes to the networking.
Each node has an interface for api, vxlan, storage, (and the "public" network 10.x, but not really used), and neutron has an additional interface for its routers.

[Taisto Qvist (theque42)]

[root@compute3 ~(admin)]# stripcom.sh /etc/kolla/globals.yml
---
kolla_base_distro: "centos"
kolla_install_type: "source"
openstack_release: "train"
kolla_enable_sanity_checks: "yes"
swift_devices_match_mode: "prefix"
swift_devices_name: "SwiftXfs"
node_custom_config: "/etc/kolla/config"
kolla_internal_vip_address: "172.16.102.111"
kolla_external_vip_address: "10.10.102.111"
docker_registry: "10.10.10.64:5000"
docker_registry_insecure: "yes"
network_interface: "eth1"
kolla_external_vip_interface: "eth0"
api_interface: "eth1"
storage_interface: "eth3"
tunnel_interface: "eth2"
neutron_external_interface: "eth4"
neutron_plugin_agent: "openvswitch"
keepalived_virtual_router_id: "52"
kolla_enable_tls_external: "no"
enable_aodh: "{{ enable_ceilometer | bool }}"
enable_barbican: "{{ enable_tacker | bool }}"
enable_ceilometer: "no"
enable_cells: "yes"
enable_cinder: "yes"
enable_cinder_backup: "yes"
enable_cinder_backend_lvm: "yes"
enable_gnocchi: "{{ enable_ceilometer | bool }}"
enable_kuryr: "{{ enable_zun | bool }}"
enable_magnum: "yes"
enable_mistral: "{{ enable_tacker | bool }}"
enable_neutron_vpnaas: "yes"
enable_neutron_fwaas: "no"
enable_neutron_provider_networks: "yes"
enable_neutron_sfc: "{{ enable_tacker | bool }}" ###TQ Needed for tacker?
enable_redis: "{{ enable_tacker | bool }}"
enable_swift: "yes"
enable_tacker: "no"
enable_trove: "yes"
enable_zun: "no"
glance_backend_file: "no"
glance_backend_swift: "yes"
panko_database_type: "mysql"
cinder_volume_group: "cinder-volumes"
cinder_backup_driver: "swift"
nova_compute_virt_type: "kvm"
[lab2]:admin@admin
[root@compute3 ~(admin)]#

[Radosław Piliszek (yoctozepto)]

It looks all right, not sure what else to check. Could you run the rmq container with strace attached to the rmq script? This way we could see some underlying failures.

[Taisto Qvist (theque42)]

I'd love to, if - since I am a bit of a noob on docker - if you tell me how I use strace on an process in a container :-)

[Taisto Qvist (theque42)]

Before I get an LMGTFY, I found https://medium.com/@rothgar/how-to-debug-a-running-docker-container-from-a-separate-container-983f11740dc6, and tried it.

The problem there is that my RMQ container starts and dies so quickly, that strace doesnt seem to have time catching it...at least on my first attempt.

[Radosław Piliszek (yoctozepto)]

Hmm, I just checked the container and it has no strace which complicates things a bit. You would have to rebuild this image to include strace. Then it's a matter of substituting in rabbitmq.json.j2:
  "command": "/usr/sbin/rabbitmq-server",
with:
  "command": "/usr/bin/strace -f /usr/sbin/rabbitmq-server",
in your local kolla-ansible installation and rerunning deploy.
Then the container logs would be richer in traces.

For rebuilding images you need kolla [0] and a docker local registry configured for kolla-ansible [1].

0: https://docs.openstack.org/kolla/latest/admin/image-building.html
1: https://docs.openstack.org/kolla-ansible/latest/user/multinode.html#deploy-a-registry

[Radosław Piliszek (yoctozepto)]

Seems we replied here almost parallelly - I was aware of that issue - that's the reason you need strace inside the container. Otherwise it is utmost pain to get it right (if someone knows a yet better way, please let me know).

[Taisto Qvist (theque42)]

Well, its done, but my hope that I would be able to find the fault myself, seems gone.

I first had to add the ptrace and sysadmin caps to the docker container, otherwise strace cant run properly, but thanks to the ooogling earlier, I had learned that.

The question is how long I should let the container run? It seems stuck, and I dont seem to get the same econnrefused error as without strace.
I did check that my new container gets the same problem as the official one.

[Taisto Qvist (theque42)]

Is this me, building the container image wrong... (I changed so that bash started in the container)

bash-4.2$ pwd
/var/lib/kolla
bash-4.2$ ls -la
total 20
drwxr-xr-x. 3 root root 4096 Dec 15 22:24 .
drwxr-xr-x. 1 root root 4096 Dec 15 22:24 ..
drwxrwx---. 3 root root 4096 Dec 15 22:22 config_files
bash-4.2$ cd config_files/
bash: cd: config_files/: Permission denied

[Taisto Qvist (theque42)]

I am also a bit confused about /etc/hosts, since this issue started with the discussion about that being broken, or at least that rmq/epmd was really picky with it being correct.
But the actual /etc/hosts doesnt seem to be mounted into the container?

[Taisto Qvist (theque42)]

I think my run command for starting the container, is a bit off. I reverse engineered it but have for instance missed --network host.

[Taisto Qvist (theque42)]

here is a better log with strace.

[Radosław Piliszek (yoctozepto)]

Hmm, that one at the end does not include econnrefused either. I thought about running it from kolla-ansible to ensure the same environment.

[Taisto Qvist (theque42)]

Does the inspect show any clear craziness?
---
[root@ctrl1 ~(admin)]# docker inspect rabbit
[
    {
        "Id": "4bc7665e9068b2a2d42a0d18f062c1605ed8105c93a448ac0c6dc6288f1c97ec",
        "Created": "2019-12-15T21:53:47.335659036Z",
        "Path": "dumb-init",
        "Args": [
            "--single-child",
            "--",
            "kolla_start"
        ],
        "State": {
            "Status": "exited",
            "Running": false,
            "Paused": false,
            "Restarting": false,
            "OOMKilled": false,
            "Dead": false,
            "Pid": 0,
            "ExitCode": 127,
            "Error": "",
            "StartedAt": "2019-12-15T21:53:47.812303135Z",
            "FinishedAt": "2019-12-15T21:57:25.973934641Z"
        },
        "Image": "sha256:d070b58099f047f9b427aab8d39ec7c877a55dd8cdd21d27dd143e37ca5cc723",
        "ResolvConfPath": "/var/lib/docker/containers/4bc7665e9068b2a2d42a0d18f062c1605ed8105c93a448ac0c6dc6288f1c97ec/resolv.conf",
        "HostnamePath": "/var/lib/docker/containers/4bc7665e9068b2a2d42a0d18f062c1605ed8105c93a448ac0c6dc6288f1c97ec/hostname",
        "HostsPath": "/var/lib/docker/containers/4bc7665e9068b2a2d42a0d18f062c1605ed8105c93a448ac0c6dc6288f1c97ec/hosts",
        "LogPath": "/var/lib/docker/containers/4bc7665e9068b2a2d42a0d18f062c1605ed8105c93a448ac0c6dc6288f1c97ec/4bc7665e9068b2a2d42a0d18f062c1605ed8105c93a448ac0c6dc6288f1c97ec-json.log",
        "Name": "/rabbit",
        "RestartCount": 0,
        "Driver": "overlay2",
        "Platform": "linux",
        "MountLabel": "",
        "ProcessLabel": "",
        "AppArmorProfile": "",
        "ExecIDs": null,
        "HostConfig": {
            "Binds": [
                "/etc/localtime:/etc/localtime:ro",
                "/etc/kolla/rabbitmq:/var/lib/kolla/config_files:ro",
                "rabbitmq:/var/lib/docker/volumes/rabbitmq/_data",
                "kolla_logs:/var/lib/docker/volumes/kolla_logs/_data"
            ],
            "ContainerIDFile": "",
            "LogConfig": {
                "Type": "json-file",
                "Config": {
                    "max-file": "5",
                    "max-size": "50m"
                }
            },
            "NetworkMode": "host",
            "PortBindings": {},
            "RestartPolicy": {
                "Name": "no",
                "MaximumRetryCount": 0
            },
            "AutoRemove": false,
            "VolumeDriver": "",
            "VolumesFrom": null,
            "CapAdd": [
                "sys_admin",
                "sys_ptrace"
            ],
            "CapDrop": null,
            "Capabilities": null,
            "Dns": [],
            "DnsOptions": [],
            "DnsSearch": [],
            "ExtraHosts": null,
            "GroupAdd": null,
            "IpcMode": "private",
            "Cgroup": "",
            "Links": null,
            "OomScoreAdj": 0,
            "PidMode": "",
            "Privileged": false,
            "PublishAllPorts": false,
            "ReadonlyRootfs": false,
            "SecurityOpt": null,
            "UTSMode": "",
            "UsernsMode": "",
            "ShmSize": 67108864,
            "Runtime": "r...

[Radosław Piliszek (yoctozepto)]

No clear craziness, sir. (Only unclear it seems! :-) )

[Taisto Qvist (theque42)]

I am running out of ideas. I am trying another install with less updated centos-Vms, and then I'll try my scripts on stein instead, and see if the deploy works there.

Any tips on what else I can troubleshoot, just give me a pointer. Unfortunately its closing into christmas, and I've got a sick oneyearold at home....

[Taisto Qvist (theque42)]

Hang on a second...I was fiddling a bit. Wheere did you say that epmd should be started? By Whoooom??

Since if I start my container with /bin/bash, and then, inside that I first do "epmd&", then /usr/sbin/rabbitmq-server will start fine...

[Radosław Piliszek (yoctozepto)]

/usr/sbin/rabbitmq-server starts epmd, it is even verified by the strace logs you provided. The issue is really puzzling as everything seems just right, yet not quite. :-)

[Radosław Piliszek (yoctozepto)]

What I noticed just now is that you have IPv6 disabled on all the interfaces. Did you do that? Which way? Maybe this is the culprit and can be reproduced...

[Eduardo Gonzalez (egonzalez90)]

Hi, can you share rabbitmq logs in /var/log/kolla/rabbitmq?

Also, could you check if ``getent ahostsv4 ctrl1`` resolves to the proper IP address 172.16.102.100, same for ctrl2 on both hosts and is important to be this command as is what rabbit sees.

Check what ``ansible_hostname`` fact is, probably ctrl1 by the logs.

State of selinux, firewall, etc.

[Taisto Qvist (theque42)]

Do you want the logs when I start it manually, with manual start of epmd first? Since on normal start, I never get any logs in the normal place. rabbitmq dies to quickly.

I was convinced that I actually had manually disabled IPv6, thinking(two years ago when I did my first attempt with...mitaka or something) that I didnt want an additional error-source, but now, when I removed the disabling from /etc/sysctl.d/99-disable-v6, it seems that after reboot, it STILL has v6 disabled.

I havent tried to see if that makes any change yet though.

[Taisto Qvist (theque42)]

I've waiting for the results of two different deploys, but the v6 stuff may have been part of the problem I think, just in case your doing any checks on your side.
IF that is required, maybe this should be checked in the prechecks that have always passed for me.
Will return with final result, once its done, and I've slept.
Cheers,
TQ

[Taisto Qvist (theque42)]

It seems the IPv6 issue solved it. I did however have to manually add a /etc/sysctl.d/99-enable-ipv6.conf, to enable ipv6, and I cant figure out why, since v6 should be enabled as default afaik.

Anyway, it of course doesnt explain why the lack of ipv6 causes epmd to fail during "auto-start" and not if I manually start it.

And as I said, if it really should be required with Ipv6 (or was that because I had left a ::1<=>localhost entry in my /etc/hosts?), then I suppose the prechecks should fail when it is disabled.

[Radosław Piliszek (yoctozepto)]

Could you then also please test if removing IPv6 localhost helps with IPv6 being disabled?

[Taisto Qvist (theque42)]

I've tried twice so far, but unfortunately with a 50% hit rate. Once, it succeeded without Ipv6(and no localhost6 in /etc/hosts), but just now, it failed with same problem as above.

[Launchpad Janitor (janitor)]

[Expired for kolla-ansible because there has been no activity for 60 days.]

[Magnus Lööf (magnus-loof)]

possibly related #1855935