OpenStack Neutron API Charm

charm readiness != API readiness

Bug #1854518 reported by Frode Nordahl
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
OpenStack Neutron API Charm
Triaged
Undecided
Unassigned

Bug Description

Reference: https://github.com/openstack-charmers/zaza-openstack-tests/issues/138

Test output:
```
2019-11-29 08:03:12 [INFO] Setting config to {'use-policyd-override': 'False'}
2019-11-29 08:03:13 [INFO] Waiting for at least one unit with agent status "executing"
2019-11-29 08:04:07 [INFO] Finally verify that operation works after removing the override.
2019-11-29 08:04:07 [INFO] Authentication for demo on keystone IP 10.5.0.67
2019-11-29 08:04:07 [INFO] keystone IP 10.5.0.67
2019-11-29 08:04:08 [INFO] ERROR
2019-11-29 08:04:08 [INFO] ======================================================================
2019-11-29 08:04:08 [INFO] ERROR: test_003_test_overide_is_observed (zaza.openstack.charm_tests.policyd.tests.NeutronApiTests)
2019-11-29 08:04:08 [INFO] Test that the override is observed by the underlying service.
2019-11-29 08:04:08 [INFO] ----------------------------------------------------------------------
2019-11-29 08:04:08 [INFO] Traceback (most recent call last):
2019-11-29 08:04:08 [INFO] File "/home/ubuntu/src/neutron-api/.tox/func-smoke/lib/python3.6/site-packages/zaza/openstack/charm_tests/policyd/tests.py", line 541, in get_client_and_attempt_operation
2019-11-29 08:04:08 [INFO] networks = neutron_client.list_networks()
2019-11-29 08:04:08 [INFO] File "/home/ubuntu/src/neutron-api/.tox/func-smoke/lib/python3.6/site-packages/neutronclient/v2_0/client.py", line 818, in list_networks
2019-11-29 08:04:08 [INFO] **_params)
2019-11-29 08:04:08 [INFO] File "/home/ubuntu/src/neutron-api/.tox/func-smoke/lib/python3.6/site-packages/neutronclient/v2_0/client.py", line 369, in list
2019-11-29 08:04:08 [INFO] for r in self._pagination(collection, path, **params):
2019-11-29 08:04:08 [INFO] File "/home/ubuntu/src/neutron-api/.tox/func-smoke/lib/python3.6/site-packages/neutronclient/v2_0/client.py", line 384, in _pagination
2019-11-29 08:04:08 [INFO] res = self.get(path, params=params)
2019-11-29 08:04:08 [INFO] File "/home/ubuntu/src/neutron-api/.tox/func-smoke/lib/python3.6/site-packages/neutronclient/v2_0/client.py", line 354, in get
2019-11-29 08:04:08 [INFO] headers=headers, params=params)
2019-11-29 08:04:08 [INFO] File "/home/ubuntu/src/neutron-api/.tox/func-smoke/lib/python3.6/site-packages/neutronclient/v2_0/client.py", line 331, in retry_request
2019-11-29 08:04:08 [INFO] headers=headers, params=params)
2019-11-29 08:04:08 [INFO] File "/home/ubuntu/src/neutron-api/.tox/func-smoke/lib/python3.6/site-packages/neutronclient/v2_0/client.py", line 294, in do_request
2019-11-29 08:04:08 [INFO] self._handle_fault_response(status_code, replybody, resp)
2019-11-29 08:04:08 [INFO] File "/home/ubuntu/src/neutron-api/.tox/func-smoke/lib/python3.6/site-packages/neutronclient/v2_0/client.py", line 269, in _handle_fault_response
2019-11-29 08:04:08 [INFO] exception_handler_v20(status_code, error_body)
2019-11-29 08:04:08 [INFO] File "/home/ubuntu/src/neutron-api/.tox/func-smoke/lib/python3.6/site-packages/neutronclient/v2_0/client.py", line 93, in exception_handler_v20
2019-11-29 08:04:08 [INFO] request_ids=request_ids)
2019-11-29 08:04:08 [INFO] neutronclient.common.exceptions.ServiceUnavailable: <!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">
2019-11-29 08:04:08 [INFO] <html><head>
2019-11-29 08:04:08 [INFO] <title>503 Service Unavailable</title>
2019-11-29 08:04:08 [INFO] </head><body>
2019-11-29 08:04:08 [INFO] <h1>Service Unavailable</h1>
2019-11-29 08:04:08 [INFO] <p>The server is temporarily unable to service your
2019-11-29 08:04:08 [INFO] request due to maintenance downtime or capacity
2019-11-29 08:04:08 [INFO] problems. Please try again later.</p>
2019-11-29 08:04:08 [INFO] <hr>
2019-11-29 08:04:08 [INFO] <address>Apache/2.4.29 (Ubuntu) Server at 10.5.0.52 Port 9696</address>
2019-11-29 08:04:08 [INFO] </body></html>
2019-11-29 08:04:08 [INFO] During handling of the above exception, another exception occurred:
2019-11-29 08:04:08 [INFO] Traceback (most recent call last):
2019-11-29 08:04:08 [INFO] File "/home/ubuntu/src/neutron-api/.tox/func-smoke/lib/python3.6/site-packages/zaza/openstack/charm_tests/policyd/tests.py", line 473, in test_003_test_overide_is_observed
2019-11-29 08:04:08 [INFO] self.get_client_and_attempt_operation(self.keystone_ips[0])
2019-11-29 08:04:08 [INFO] File "/home/ubuntu/src/neutron-api/.tox/func-smoke/lib/python3.6/site-packages/zaza/openstack/charm_tests/policyd/tests.py", line 546, in get_client_and_attempt_operation
2019-11-29 08:04:08 [INFO] raise PolicydOperationFailedException()
2019-11-29 08:04:08 [INFO] zaza.openstack.charm_tests.policyd.tests.PolicydOperationFailedException
2019-11-29 08:04:08 [INFO] During handling of the above exception, another exception occurred:
2019-11-29 08:04:08 [INFO] Traceback (most recent call last):
2019-11-29 08:04:08 [INFO] File "/home/ubuntu/src/neutron-api/.tox/func-smoke/lib/python3.6/site-packages/zaza/openstack/charm_tests/policyd/tests.py", line 478, in test_003_test_overide_is_observed
2019-11-29 08:04:08 [INFO] .format(str(e)))
2019-11-29 08:04:08 [INFO] zaza.openstack.utilities.exceptions.PolicydError: Service action failed and should have passed after removing policy override: ""
```

Neutron API charm log:
```
2019-11-29 08:04:05 INFO juju-log Unit is ready
2019-11-29 08:07:49 INFO juju-log ...
```

neutron-api syslog:
```
Nov 29 08:04:04 juju-c66fd6-zaza-7aa846afa0cd-6 systemd[1]: Stopped OpenStack Neutron Server.
Nov 29 08:04:04 juju-c66fd6-zaza-7aa846afa0cd-6 systemd[1]: Started OpenStack Neutron Server.
Nov 29 08:17:01 juju-c66fd6-zaza-7aa846afa0cd-6 CRON ...
```

Neutron API server daemon log:
```
2019-11-29 08:04:03.901 14066 INFO oslo_service.service [-] Child 14279 killed by signal 15
2019-11-29 08:04:07.039 20193 INFO neutron.common.config [-] Logging enabled!
...
2019-11-29 08:04:09.014 20193 INFO neutron.service [req-b336a6d0-daa1-426b-ae65-d6d395310269 - - - - -] Neutron service started, listening on 0.0.0.0:9676
```

Apache error log:
```
[Fri Nov 29 08:04:05.494436 2019] [proxy:error] [pid 18852:tid 140220213229312] (111)Connection refused: AH00957: HTTP: attempt to connect to 127.0.0.1:9676 (localhost) failed
[Fri Nov 29 08:04:05.494493 2019] [proxy_http:error] [pid 18852:tid 140220213229312] [client 10.5.0.52:40388] AH01114: HTTP: failed to make connection to backend: localhost
[Fri Nov 29 08:04:08.358579 2019] [proxy:error] [pid 18852:tid 140220204836608] (111)Connection refused: AH00957: HTTP: attempt to connect to 127.0.0.1:9676 (localhost) failed
[Fri Nov 29 08:04:08.358625 2019] [proxy_http:error] [pid 18852:tid 140220204836608] [client 10.5.0.52:40398] AH01114: HTTP: failed to make connection to backend: localhost
```

Apache access log:
```
10.5.0.52:443 10.5.0.52 - - [29/Nov/2019:08:03:20 +0000] "GET /v2.0/networks/b7c57241-8cf9-4b51-adc1-22f369f45803?fields=provider%3Aphysical_network&fields=provider%3Anetwork_type HTTP/1.1" 200 369 "-" "python-neutronclient"

10.5.0.52:443 10.5.0.52 - - [29/Nov/2019:08:04:05 +0000] "GET /v2.0/ports?device_id=52ad1fb7-c64b-4ec5-adb5-4f9a01825a37&fields=binding%3Ahost_id&fields=binding%3Avif_type HTTP/1.1" 503 3106 "-" "python-neutronclient"
10.5.0.52:443 10.5.0.52 - - [29/Nov/2019:08:04:08 +0000] "GET /v2.0/networks HTTP/1.1" 503 3106 "-" "python-neutronclient"

10.5.0.52:443 10.5.0.52 - - [29/Nov/2019:08:04:21 +0000] "GET /v2.0/ports?device_id=b1f990d7-b1de-457c-ad40-29f076ce3bbc&fields=binding%3Ahost_id&fields=binding%3Avif_type HTTP/1.1" 200 2914 "-" "python-neutronclient"
```

So, what's going on here is that the second the `neutron-api` charm signals it has done executing (which it has) the test attempts to use the service. And it appears to not actually ready to answer requests until a few seconds later at the earliest.

Andrew McLeod (admcleod)
Changed in charm-neutron-api:
status: New → Triaged
Revision history for this message
Alex Kavanagh (ajkavanagh) wrote :

Seen a variant of this on https://review.opendev.org/#/c/732657/ as well.

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.
Subscribing...

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.