[artful] apachectl: Address already in use: AH00072: make_sock: could not bind to address 0.0.0.0:8776

[Ryan Beisner]

The Cinder charm on Artful tries to start apache2 on tcp 8776, but haproxy is already bound to that port/socket. This is observable via the charm's workload status message, as it stays in a blocked state.

ubuntu@juju-4947e0-auto-osci-sv10-0:/var/log$ sudo netstat -taupn
Active Internet connections (servers and established)
Proto Recv-Q Send-Q Local Address Foreign Address State PID/Program name
tcp 0 0 0.0.0.0:8776 0.0.0.0:* LISTEN 29128/haproxy
tcp 0 0 0.0.0.0:5355 0.0.0.0:* LISTEN 772/systemd-resolve
tcp 0 0 0.0.0.0:22 0.0.0.0:* LISTEN 908/sshd
tcp 0 0 127.0.0.1:8888 0.0.0.0:* LISTEN 29128/haproxy
tcp 0 0 0.0.0.0:3260 0.0.0.0:* LISTEN 12174/tgtd
tcp 0 0 172.17.110.9:44034 172.17.110.16:5672 ESTABLISHED 29198/python
tcp 0 0 172.17.110.9:44018 172.17.110.16:5672 ESTABLISHED 29114/python
tcp 0 0 172.17.110.9:47026 172.17.110.3:17070 ESTABLISHED 1979/jujud
tcp 0 0 172.17.110.9:22 10.5.0.6:46140 ESTABLISHED 30024/sshd: ubuntu
tcp 0 0 172.17.110.9:47018 172.17.110.3:17070 ESTABLISHED 1852/jujud
tcp 0 0 172.17.110.9:44030 172.17.110.16:5672 ESTABLISHED 29114/python
tcp 0 0 172.17.110.9:44016 172.17.110.16:5672 ESTABLISHED 29114/python
tcp 0 0 172.17.110.9:36970 172.17.110.8:3306 ESTABLISHED 29114/python
tcp 0 0 172.17.110.9:47020 172.17.110.3:17070 ESTABLISHED 1852/jujud
tcp 0 0 172.17.110.9:47024 172.17.110.3:17070 ESTABLISHED 1979/jujud
tcp 0 0 172.17.110.9:36986 172.17.110.8:3306 ESTABLISHED 29198/python
tcp 0 0 172.17.110.9:44032 172.17.110.16:5672 ESTABLISHED 29198/python
tcp 0 0 172.17.110.9:44028 172.17.110.16:5672 ESTABLISHED 29198/python
tcp6 0 0 :::8776 :::* LISTEN 29128/haproxy
tcp6 0 0 ::1:11211 :::* LISTEN 26285/memcached
tcp6 0 0 :::5355 :::* LISTEN 772/systemd-resolve
tcp6 0 0 :::22 :::* LISTEN 908/sshd
tcp6 0 0 :::3260 :::* LISTEN 12174/tgtd
udp 0 0 0.0.0.0:5355 0.0.0.0:* 772/systemd-resolve
udp 0 0 127.0.0.53:53 0.0.0.0:* 772/systemd-resolve
udp 0 0 172.17.110.9:68 0.0.0.0:* 588/systemd-network
udp6 0 0 :::5355 :::* 772/systemd-resolve
udp6 0 0 ::1:11211 :::* 26285/memcached

.

ubuntu@juju-4947e0-auto-osci-sv10-0:/var/log$ ps aux | grep apache
ubuntu 30210 0.0 0.0 14796 1068 pts/0 S+ 18:51 0:00 grep --color=auto apache

.

Sep 28 18:49:07 juju-4947e0-auto-osci-sv10-0 systemd[1]: apache2.service: Control process exited, code=exited status=1
Sep 28 18:49:07 juju-4947e0-auto-osci-sv10-0 systemd[1]: Failed to start The Apache HTTP Server.
Sep 28 18:49:07 juju-4947e0-auto-osci-sv10-0 systemd[1]: apache2.service: Unit entered failed state.
Sep 28 18:49:07 juju-4947e0-auto-osci-sv10-0 systemd[1]: apache2.service: Failed with result 'exit-code'.
Sep 28 18:49:07 juju-4947e0-auto-osci-sv10-0 systemd[1]: Stopping OpenStack Cinder Volume...
Sep 28 18:49:07 juju-4947e0-auto-osci-sv10-0 systemd[1]: Stopped OpenStack Cinder Volume.
Sep 28 18:49:07 juju-4947e0-auto-osci-sv10-0 systemd[1]: Starting OpenStack Cinder Volume...
Sep 28 18:49:07 juju-4947e0-auto-osci-sv10-0 systemd[1]: Started OpenStack Cinder Volume.
Sep 28 18:49:07 juju-4947e0-auto-osci-sv10-0 systemd[1]: Stopping OpenStack Cinder Scheduler...
Sep 28 18:49:07 juju-4947e0-auto-osci-sv10-0 systemd[1]: Stopped OpenStack Cinder Scheduler.
Sep 28 18:49:07 juju-4947e0-auto-osci-sv10-0 systemd[1]: Starting OpenStack Cinder Scheduler...
Sep 28 18:49:07 juju-4947e0-auto-osci-sv10-0 systemd[1]: Started OpenStack Cinder Scheduler.
Sep 28 18:49:07 juju-4947e0-auto-osci-sv10-0 systemd[1]: Stopping HAProxy Load Balancer...
Sep 28 18:49:07 juju-4947e0-auto-osci-sv10-0 systemd[1]: Stopped HAProxy Load Balancer.
Sep 28 18:49:07 juju-4947e0-auto-osci-sv10-0 systemd[1]: Starting HAProxy Load Balancer...
Sep 28 18:49:07 juju-4947e0-auto-osci-sv10-0 systemd[1]: Started HAProxy Load Balancer.
Sep 28 18:49:07 juju-4947e0-auto-osci-sv10-0 systemd[1]: Starting The Apache HTTP Server...
Sep 28 18:49:07 juju-4947e0-auto-osci-sv10-0 apachectl[29120]: AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 172.17.110.9. Set the 'ServerName' directive globally to suppress this message
Sep 28 18:49:07 juju-4947e0-auto-osci-sv10-0 apachectl[29120]: (98)Address already in use: AH00072: make_sock: could not bind to address [::]:8776
Sep 28 18:49:07 juju-4947e0-auto-osci-sv10-0 apachectl[29120]: (98)Address already in use: AH00072: make_sock: could not bind to address 0.0.0.0:8776
Sep 28 18:49:07 juju-4947e0-auto-osci-sv10-0 apachectl[29120]: no listening sockets available, shutting down
Sep 28 18:49:07 juju-4947e0-auto-osci-sv10-0 apachectl[29120]: AH00015: Unable to open logs
Sep 28 18:49:07 juju-4947e0-auto-osci-sv10-0 apachectl[29120]: Action 'start' failed.
Sep 28 18:49:07 juju-4947e0-auto-osci-sv10-0 apachectl[29120]: The Apache error log may have more information.
Sep 28 18:49:07 juju-4947e0-auto-osci-sv10-0 systemd[1]: apache2.service: Control process exited, code=exited status=1
Sep 28 18:49:07 juju-4947e0-auto-osci-sv10-0 systemd[1]: Failed to start The Apache HTTP Server.
Sep 28 18:49:07 juju-4947e0-auto-osci-sv10-0 systemd[1]: apache2.service: Unit entered failed state.
Sep 28 18:49:07 juju-4947e0-auto-osci-sv10-0 systemd[1]: apache2.service: Failed with result 'exit-code'.

.

jenkins@juju-0d10ff-osci-9:~$ juju status
Model Controller Cloud/Region Version SLA
auto-osci-sv10 auto-osci-sv10 serverstack/serverstack 2.2.4 unsupported

App Version Status Scale Charm Store Rev OS Notes
cinder 11.0.0 blocked 1 cinder local 136 ubuntu
glance 15.0.0 active 1 glance jujucharms 291 ubuntu
keystone 12.0.0 active 1 keystone jujucharms 312 ubuntu
percona-cluster 5.6.34-26.19 active 1 percona-cluster jujucharms 272 ubuntu
rabbitmq-server 3.6.10 active 1 rabbitmq-server jujucharms 276 ubuntu

Unit Workload Agent Machine Public address Ports Message
cinder/0* blocked idle 0 172.17.110.9 8776/tcp Services not running that should be: apache2
glance/0* active idle 1 172.17.110.11 9292/tcp Unit is ready
keystone/0* active idle 2 172.17.110.5 5000/tcp Unit is ready
percona-cluster/0* active idle 3 172.17.110.8 3306/tcp Unit is ready
rabbitmq-server/0* active idle 4 172.17.110.16 5672/tcp Unit is ready

Machine State DNS Inst id Series AZ Message
0 started 172.17.110.9 b87806e5-2ace-4fde-b56a-33844cfe3825 artful nova ACTIVE
1 started 172.17.110.11 88cfab0e-3f61-4ce7-aa4c-e939c3c11e9e artful nova ACTIVE
2 started 172.17.110.5 51edcf6e-e2e5-48e1-9295-09bb5fef273c artful nova ACTIVE
3 started 172.17.110.8 153a964e-074c-4bbe-afa8-c8e0bfdc0d85 artful nova ACTIVE
4 started 172.17.110.16 909c9064-70ad-48e8-afb3-f7ef7006fd92 artful nova ACTIVE

Relation provider Requirer Interface Type
cinder:cluster cinder:cluster cinder-ha peer
glance:cluster glance:cluster glance-ha peer
glance:image-service cinder:image-service glance regular
keystone:cluster keystone:cluster keystone-ha peer
keystone:identity-service cinder:identity-service keystone regular
keystone:identity-service glance:identity-service keystone regular
percona-cluster:cluster percona-cluster:cluster percona-cluster peer
percona-cluster:shared-db cinder:shared-db mysql-shared regular
percona-cluster:shared-db glance:shared-db mysql-shared regular
percona-cluster:shared-db keystone:shared-db mysql-shared regular
rabbitmq-server:amqp cinder:amqp rabbitmq regular
rabbitmq-server:amqp glance:amqp rabbitmq regular
rabbitmq-server:cluster rabbitmq-server:cluster rabbitmq-ha peer

[Ryan Beisner (1chb1n)]

Test updates are here: https://review.openstack.org/#/c/508200/

[Ryan Beisner (1chb1n)]

Logs and artifacts here:
https://openstack-ci-reports.ubuntu.com/artifacts/test_charm_pipeline_amulet_full/openstack/charm-cinder/508200/1/600/index.html

[Liam Young (gnuoy)]

Ok, so this has been broken in the charm for a while. The package shipped vhost should be disabled by the charm but due to a bug that is not happening.

However xenial and zesty both seem to allow apache to start when it has a conflicting port with haproxy. If haproxy is running and bound to 8776 on both ipv4 and ipv6 then apache starts and creates a duplicate bind to 8776 on the ipv6 address. Bug #1720378

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/508812

[Ryan Beisner (1chb1n)]

Bumping to High, as Artful is in freeze and set to ship on Oct 19.

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/508812
Committed: https://git.openstack.org/cgit/openstack/charm-cinder/commit/?id=6dd1af6059338a99e82d4a94ac743af7643c9db3
Submitter: Jenkins
Branch: master

commit 6dd1af6059338a99e82d4a94ac743af7643c9db3
Author: Liam Young <email address hidden>
Date: Fri Sep 29 17:42:27 2017 +0000

    Fix disabling cinder wsgi vhost from package

    The package shipped vhost should be disabled by the charm but due to a bug
    this was not happening. This means that apache (on artful) fails to start.
    On xenial and zesty both seem to allow apache to start when it has a
    conflicting port with haproxy which is why this has not caused a problem
    previousy releases (Bug #1720378).

    Change-Id: Ic83452d232838e6ffcc2b8dc5f33dae347f7cb3d
    Closes-Bug: #1720215
    Depends-On: I08c3963eb21bbc9f1035a5f565a9b4d993222887

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/514740