tripleo

Bug #1792296
Comment #6

Comment 6 for bug 1792296

Revision history for this message

Michele Baldessari (michele) wrote on 2018-09-14:

1. pacemaker failed to start the haproxy bundle container
Sep 13 08:45:51 [30345] upstream-centos-7-rdo-cloud-tripleo-0000174334 pengine: info: common_print: ip-192.168.24.11 (ocf::heartbeat:IPaddr2): Stopped
Sep 13 08:45:51 [30345] upstream-centos-7-rdo-cloud-tripleo-0000174334 pengine: info: common_print: ip-192.168.24.12 (ocf::heartbeat:IPaddr2): Stopped
Sep 13 08:45:51 [30345] upstream-centos-7-rdo-cloud-tripleo-0000174334 pengine: info: container_print: Docker container: haproxy-bundle [192.168.24.1:8787/tripleomaster/centos-binary-haproxy:pcmklatest]
Sep 13 08:45:51 [30345] upstream-centos-7-rdo-cloud-tripleo-0000174334 pengine: info: common_print: haproxy-bundle-docker-0 (ocf::heartbeat:docker): Stopped

Sep 13 08:00:26 [30341] upstream-centos-7-rdo-cloud-tripleo-0000174334 cib: info: cib_perform_op:▸ + /cib: @num_updates=1↲
Sep 13 08:00:26 [30341] upstream-centos-7-rdo-cloud-tripleo-0000174334 cib: info: cib_perform_op:▸ + /cib/status/node_state[@id='1']/lrm[@id='1']/lrm_resources/lrm_resource[@id='haproxy-bundle-docker-0']/lrm_rsc_op[@id='haproxy-bundle-docker-0_last_0']: @operation_key=haproxy-bundle-docker-0_start_0, @operation=start, @transition-key=60:27:0:df70d12c-f2cc-45fb-a677-64838b575c74, @transition-magic=-1:193;60:27:0:df70d12c-f2cc-45fb-a677-64838b575c74, @call-id=-1, @rc-code=193, @op-status=-1, @las↲
Sep 13 08:00:26 [30341] upstream-centos-7-rdo-cloud-tripleo-0000174334 cib: info: cib_process_request:▸ Completed cib_modify operation for section status: OK (rc=0, origin=upstream-centos-7-rdo-cloud-tripleo-0000174334/crmd/226, version=0.28.1)↲
Sep 13 08:00:26 docker(haproxy-bundle-docker-0)[73283]: INFO: checking for nsenter, which is required when 'monitor_cmd' is specified↲
Sep 13 08:00:26 docker(haproxy-bundle-docker-0)[73283]: INFO: running container haproxy-bundle-docker-0 for the first time↲
Sep 13 08:00:27 docker(haproxy-bundle-docker-0)[73283]: INFO: monitor cmd exit code = 137↲
Sep 13 08:00:27 docker(haproxy-bundle-docker-0)[73283]: INFO: stdout/stderr:↲
Sep 13 08:00:27 docker(haproxy-bundle-docker-0)[73283]: ERROR: waiting on monitor_cmd to pass after start↲
Sep 13 08:00:28 docker(haproxy-bundle-docker-0)[73283]: ERROR: Newly created docker container exited after start↲
Sep 13 08:00:28 [30343] upstream-centos-7-rdo-cloud-tripleo-0000174334 lrmd: notice: operation_finished:▸ haproxy-bundle-docker-0_start_0:73283:stderr [ ocf-exit-reason:waiting on monitor_cmd to pass after start ]↲
Sep 13 08:00:28 [30343] upstream-centos-7-rdo-cloud-tripleo-0000174334 lrmd: notice: operation_finished:▸ haproxy-bundle-docker-0_start_0:73283:stderr [ ocf-exit-reason:Newly created docker container exited after start ]↲
Sep 13 08:00:28 [30343] upstream-centos-7-rdo-cloud-tripleo-0000174334 lrmd: info: log_finished:▸ finished - rsc:haproxy-bundle-docker-0 action:start call_id:40 pid:73283 exit-code:1 exec-time:1541ms queue-time:0ms↲
Sep 13 08:00:28 [30346] upstream-centos-7-rdo-cloud-tripleo-0000174334 crmd: notice: process_lrm_event:▸Result of start operation for haproxy-bundle-docker-0 on upstream-centos-7-rdo-cloud-tripleo-0000174334: 1 (unknown error) | call=40 key=haproxy-bundle-docker-0_start_0 confirmed=true cib-update=227↲

The bundle name is:
Sep 13 08:00:16 [30341] upstream-centos-7-rdo-cloud-tripleo-0000174334 cib: info: cib_perform_op:▸ ++ <docker run-command="/bin/bash /usr/local/bin/kolla_start" network="host" image="192.168.24.1:8787/tripleomaster/centos-binary-haproxy:pcmklatest" options="--user=root --log-driver=journald -e KOLLA_CONFIG_STRATEGY=COPY_ALWAYS" replicas="1"/>↲

From docker info https://logs.rdoproject.org/openstack-periodic/git.openstack.org/openstack-infra/tripleo-ci/master/legacy-periodic-tripleo-ci-centos-7-multinode-1ctlr-featureset019-master/36edbf9/logs/subnode-2/var/log/extra/docker/docker_allinfo.log.txt.gz we see that the container exists:
192.168.24.1:8787/tripleomaster/centos-binary-haproxy pcmklatest fdb82a29ee72 About an hour ago 826 MB
192.168.24.1:8787/tripleomaster/centos-binary-haproxy tripleo-ci-testing-updated-20180913065338 fdb82a29ee72 About an hour ago 826 MB

So the problem is haproxy's ceph stanza is binding on something that is already taken:
Sep 13 08:00:26 upstream-centos-7-rdo-cloud-tripleo-0000174334 dockerd-current[23590]: + echo 'Running command: '\''/usr/sbin/haproxy-systemd-wrapper -f /etc/haproxy/haproxy.cfg'\'''
Sep 13 08:00:26 upstream-centos-7-rdo-cloud-tripleo-0000174334 dockerd-current[23590]: Running command: '/usr/sbin/haproxy-systemd-wrapper -f /etc/haproxy/haproxy.cfg'
Sep 13 08:00:26 upstream-centos-7-rdo-cloud-tripleo-0000174334 dockerd-current[23590]: + exec /usr/sbin/haproxy-systemd-wrapper -f /etc/haproxy/haproxy.cfg
Sep 13 08:00:26 upstream-centos-7-rdo-cloud-tripleo-0000174334 dockerd-current[23590]: <7>haproxy-systemd-wrapper: executing /usr/sbin/haproxy -f /etc/haproxy/haproxy.cfg -Ds
Sep 13 08:00:26 upstream-centos-7-rdo-cloud-tripleo-0000174334 dockerd-current[23590]: [ALERT] 255/080026 (11) : Starting proxy ceph_rgw: cannot bind socket [192.168.24.11:8080]
Sep 13 08:00:26 upstream-centos-7-rdo-cloud-tripleo-0000174334 haproxy[73442]: Proxy glance_api started.

https://logs.rdoproject.org/openstack-periodic/git.openstack.org/openstack-infra/tripleo-ci/master/legacy-periodic-tripleo-ci-centos-7-multinode-1ctlr-featureset019-master/36edbf9/logs/subnode-2/var/log/cluster/corosync.log.txt.gz
                                
1. pacemaker failed to start the haproxy bundle container                                                         
Sep 13 08:45:51 [30345] upstream-centos-7-rdo-cloud-tripleo-0000174334    pengine:     info: common_print:      ip-192.168.24.11        (ocf::heartbeat:IPaddr2):       Stopped
Sep 13 08:45:51 [30345] upstream-centos-7-rdo-cloud-tripleo-0000174334    pengine:     info: common_print:      ip-192.168.24.12        (ocf::heartbeat:IPaddr2):       Stopped
Sep 13 08:45:51 [30345] upstream-centos-7-rdo-cloud-tripleo-0000174334    pengine:     info: container_print:    Docker container: haproxy-bundle [192.168.24.1:8787/tripleomaster/centos-binary-haproxy:pcmklatest]
Sep 13 08:45:51 [30345] upstream-centos-7-rdo-cloud-tripleo-0000174334    pengine:     info: common_print:         haproxy-bundle-docker-0      (ocf::heartbeat:docker):        Stopped
                                                                                         
Sep 13 08:00:26 [30341] upstream-centos-7-rdo-cloud-tripleo-0000174334        cib:     info: cib_perform_op:▸   +  /cib:  @num_updates=1↲
Sep 13 08:00:26 [30341] upstream-centos-7-rdo-cloud-tripleo-0000174334        cib:     info: cib_perform_op:▸   +  /cib/status/node_state[@id='1']/lrm[@id='1']/lrm_resources/lrm_resource[@id='haproxy-bundle-docker-0']/lrm_rsc_op[@id='haproxy-bundle-docker-0_last_0']:  @operation_key=haproxy-bundle-docker-0_start_0, @operation=start, @transition-key=60:27:0:df70d12c-f2cc-45fb-a677-64838b575c74, @transition-magic=-1:193;60:27:0:df70d12c-f2cc-45fb-a677-64838b575c74, @call-id=-1, @rc-code=193, @op-status=-1, @las↲
Sep 13 08:00:26 [30341] upstream-centos-7-rdo-cloud-tripleo-0000174334        cib:     info: cib_process_request:▸      Completed cib_modify operation for section status: OK (rc=0, origin=upstream-centos-7-rdo-cloud-tripleo-0000174334/crmd/226, version=0.28.1)↲
Sep 13 08:00:26  docker(haproxy-bundle-docker-0)[73283]:    INFO: checking for nsenter, which is required when 'monitor_cmd' is specified↲
Sep 13 08:00:26  docker(haproxy-bundle-docker-0)[73283]:    INFO: running container haproxy-bundle-docker-0 for the first time↲
Sep 13 08:00:27  docker(haproxy-bundle-docker-0)[73283]:    INFO: monitor cmd exit code = 137↲ 
Sep 13 08:00:27  docker(haproxy-bundle-docker-0)[73283]:    INFO: stdout/stderr:↲        
Sep 13 08:00:27  docker(haproxy-bundle-docker-0)[73283]:    ERROR: waiting on monitor_cmd to pass after start↲
Sep 13 08:00:28  docker(haproxy-bundle-docker-0)[73283]:    ERROR: Newly created docker container exited after start↲
Sep 13 08:00:28 [30343] upstream-centos-7-rdo-cloud-tripleo-0000174334       lrmd:   notice: operation_finished:▸       haproxy-bundle-docker-0_start_0:73283:stderr [ ocf-exit-reason:waiting on monitor_cmd to pass after start ]↲
Sep 13 08:00:28 [30343] upstream-centos-7-rdo-cloud-tripleo-0000174334       lrmd:   notice: operation_finished:▸       haproxy-bundle-docker-0_start_0:73283:stderr [ ocf-exit-reason:Newly created docker container exited after start ]↲
Sep 13 08:00:28 [30343] upstream-centos-7-rdo-cloud-tripleo-0000174334       lrmd:     info: log_finished:▸     finished - rsc:haproxy-bundle-docker-0 action:start call_id:40 pid:73283 exit-code:1 exec-time:1541ms queue-time:0ms↲
Sep 13 08:00:28 [30346] upstream-centos-7-rdo-cloud-tripleo-0000174334       crmd:   notice: process_lrm_event:▸Result of start operation for haproxy-bundle-docker-0 on upstream-centos-7-rdo-cloud-tripleo-0000174334: 1 (unknown error) | call=40 key=haproxy-bundle-docker-0_start_0 confirmed=true cib-update=227↲
                                                                                         
The bundle name is:                                                                      
Sep 13 08:00:16 [30341] upstream-centos-7-rdo-cloud-tripleo-0000174334        cib:     info: cib_perform_op:▸   ++                                  <docker run-command="/bin/bash /usr/local/bin/kolla_start" network="host" image="192.168.24.1:8787/tripleomaster/centos-binary-haproxy:pcmklatest" options="--user=root --log-driver=journald -e KOLLA_CONFIG_STRATEGY=COPY_ALWAYS" replicas="1"/>↲
                                                                                         
From docker info https://logs.rdoproject.org/openstack-periodic/git.openstack.org/openstack-infra/tripleo-ci/master/legacy-periodic-tripleo-ci-centos-7-multinode-1ctlr-featureset019-master/36edbf9/logs/subnode-2/var/log/extra/docker/docker_allinfo.log.txt.gz we see that the container exists:
192.168.24.1:8787/tripleomaster/centos-binary-haproxy              pcmklatest                                   fdb82a29ee72        About an hour ago   826 MB
192.168.24.1:8787/tripleomaster/centos-binary-haproxy              tripleo-ci-testing-updated-20180913065338    fdb82a29ee72        About an hour ago   826 MB
                                                                                         
So the problem is haproxy's ceph stanza is binding on something that is already taken:                                                                                                                                                                                         
Sep 13 08:00:26 upstream-centos-7-rdo-cloud-tripleo-0000174334 dockerd-current[23590]: + echo 'Running command: '\''/usr/sbin/haproxy-systemd-wrapper -f /etc/haproxy/haproxy.cfg'\'''
Sep 13 08:00:26 upstream-centos-7-rdo-cloud-tripleo-0000174334 dockerd-current[23590]: Running command: '/usr/sbin/haproxy-systemd-wrapper -f /etc/haproxy/haproxy.cfg'
Sep 13 08:00:26 upstream-centos-7-rdo-cloud-tripleo-0000174334 dockerd-current[23590]: + exec /usr/sbin/haproxy-systemd-wrapper -f /etc/haproxy/haproxy.cfg
Sep 13 08:00:26 upstream-centos-7-rdo-cloud-tripleo-0000174334 dockerd-current[23590]: <7>haproxy-systemd-wrapper: executing /usr/sbin/haproxy -f /etc/haproxy/haproxy.cfg -Ds 
Sep 13 08:00:26 upstream-centos-7-rdo-cloud-tripleo-0000174334 dockerd-current[23590]: [ALERT] 255/080026 (11) : Starting proxy ceph_rgw: cannot bind socket [192.168.24.11:8080]
Sep 13 08:00:26 upstream-centos-7-rdo-cloud-tripleo-0000174334 haproxy[73442]: Proxy glance_api started.