[disco-stein] FAIL: test_create_loadbalancer (load balancer resource has not reached expected provisioning status)

[Ryan Beisner]

Octavia charm gate tests are failing on disco-stein. Charm application state is good. The functional test fails to create a load balancer.

2019-10-04 01:13:52 [INFO] ======================================================================
2019-10-04 01:13:52 [INFO] FAIL: test_create_loadbalancer (zaza.openstack.charm_tests.octavia.tests.LBAASv2Test)
2019-10-04 01:13:52 [INFO] Create load balancer.
2019-10-04 01:13:52 [INFO] ----------------------------------------------------------------------
2019-10-04 01:13:52 [INFO] Traceback (most recent call last):
2019-10-04 01:13:52 [INFO] File "/tmp/tmp.mYUkaYMskk/func/lib/python3.5/site-packages/zaza/openstack/charm_tests/octavia/tests.py", line 100, in test_create_loadbalancer
2019-10-04 01:13:52 [INFO] resp = wait_for_lb_resource(octavia_client.load_balancer_show, lb_id)
2019-10-04 01:13:52 [INFO] File "/tmp/tmp.mYUkaYMskk/func/lib/python3.5/site-packages/tenacity/__init__.py", line 292, in wrapped_f
2019-10-04 01:13:52 [INFO] return self.call(f, *args, **kw)
2019-10-04 01:13:52 [INFO] File "/tmp/tmp.mYUkaYMskk/func/lib/python3.5/site-packages/tenacity/__init__.py", line 358, in call
2019-10-04 01:13:52 [INFO] do = self.iter(retry_state=retry_state)
2019-10-04 01:13:52 [INFO] File "/tmp/tmp.mYUkaYMskk/func/lib/python3.5/site-packages/tenacity/__init__.py", line 331, in iter
2019-10-04 01:13:52 [INFO] raise retry_exc.reraise()
2019-10-04 01:13:52 [INFO] File "/tmp/tmp.mYUkaYMskk/func/lib/python3.5/site-packages/tenacity/__init__.py", line 167, in reraise
2019-10-04 01:13:52 [INFO] raise self.last_attempt.result()
2019-10-04 01:13:52 [INFO] File "/usr/lib/python3.5/concurrent/futures/_base.py", line 398, in result
2019-10-04 01:13:52 [INFO] return self.__get_result()
2019-10-04 01:13:52 [INFO] File "/usr/lib/python3.5/concurrent/futures/_base.py", line 357, in __get_result
2019-10-04 01:13:52 [INFO] raise self._exception
2019-10-04 01:13:52 [INFO] File "/tmp/tmp.mYUkaYMskk/func/lib/python3.5/site-packages/tenacity/__init__.py", line 361, in call
2019-10-04 01:13:52 [INFO] result = fn(*args, **kwargs)
2019-10-04 01:13:52 [INFO] File "/tmp/tmp.mYUkaYMskk/func/lib/python3.5/site-packages/zaza/openstack/charm_tests/octavia/tests.py", line 90, in wait_for_lb_resource
2019-10-04 01:13:52 [INFO] .format(resp))
2019-10-04 01:13:52 [INFO] AssertionError: load balancer resource has not reached expected provisioning status: {'vip_subnet_id': '00afd76e-7d5d-4121-8ed5-dd75dc474b77', 'name': 'zaza-lb-0', 'provider': 'amphora', 'description': 'Created by Zaza', 'created_at': '2019-10-04T00:58:51', 'project_id': '739642e52ffd401c8582c0b33b25b3de', 'admin_state_up': True, 'operating_status': 'OFFLINE', 'pools': [], 'tags': [], 'provisioning_status': 'PENDING_CREATE', 'id': '3bfec020-5c73-4206-abba-d1a01e6241f1', 'vip_qos_policy_id': None, 'flavor_id': None, 'tenant_id': '739642e52ffd401c8582c0b33b25b3de', 'vip_address': '10.42.0.15', 'updated_at': None, 'vip_port_id': 'aed1b162-e389-493a-a91e-9c34939c98df', 'vip_network_id': '6885ebd1-5225-4b87-8d74-a9bd2ac8ba96', 'listeners': []}
2019-10-04 01:13:52 [INFO] ----------------------------------------------------------------------
2019-10-04 01:13:52 [INFO] Ran 1 test in 916.257s
2019-10-04 01:13:52 [INFO] FAILED

https://openstack-ci-reports.ubuntu.com/artifacts/test_charm_pipeline_func_full/openstack/charm-octavia/685845/2/3963/index.html

https://openstack-ci-reports.ubuntu.com/artifacts/test_charm_pipeline_func_full/openstack/charm-octavia/685845/2/3963/consoleText.test_charm_func_full_7218.txt

Affects rebuild: https://review.opendev.org/#/c/685845/

[Frode Nordahl (fnordahl)]

The Octavia gate is broken at master at the moment, there is a in-flight
series pending merge here:

https://review.opendev.org/#/q/status:open+project:openstack/charm-octavia+branch:master+topic:bug/1845303

The two patches are interdependent and stacked so we need to land the first
in the series despite failing functional tests.

As can be viewed at tip of the series the gate is unblocked as soon as they
both are merged.

[Ryan Beisner (1chb1n)]

FYI With that batch of changes merged, the charm gate test is still consistently failing on disco-stein.

Observed @ https://review.opendev.org/#/c/685845

[Ryan Beisner (1chb1n)]

Copying Frode's comment from gerrit, which seems to validate the bug and provide additional info to triage:

Frode Nordahl
4:31 AM
↩
Patch Set 4:

Analysis of crashdump:
Most of the work is successfully handled by unit ``octavia_2``, but at some point ``octavia_0`` takes over the processing and it bombs out with:

    2019-10-17 06:46:32.660 11876 WARNING octavia.amphorae.drivers.haproxy.rest_api_driver [req-1cdfa818-b062-4712-b27e-c69d27770620 - ea305ecf2c0145eb8e9b2c0962cb06fb - - -] Could not connect to instance. Retrying.: requests.exceptions.ConnectTimeout: HTTPSConnectionPool(host='fc00:c166:533d:e15c:f816:3eff:fe35:50ee', port=9443): Max retries exceeded with url: /0.5/info (Caused by ConnectTimeoutError(<urllib3.connection.VerifiedHTTPSConnection object at 0x7f5af0e0b6d8>, 'Connection to fc00:c166:533d:e15c:f816:3eff:fe35:50ee timed out. (connect timeout=10.0)'))

So this appears to be a real intermittent issue where one of the units fail to acquire an IP address in the management network.

[Ryan Beisner (1chb1n)]

Triaged high, as failures in interim releases leading into the next LTS are indicative of what is to come.

[Aurelien Lourot (aurelien-lourot)]

Hit us here again: https://openstack-ci-reports.ubuntu.com/artifacts/test_charm_pipeline_func_full/openstack/charm-octavia/741616/5/6445/consoleText.test_charm_func_full_9564.txt

[Aurelien Lourot (aurelien-lourot)]

Another variation of this:

https://review.opendev.org/c/openstack/charm-octavia/+/770417
https://openstack-ci-reports.ubuntu.com/artifacts/test_charm_pipeline_func_smoke/openstack/charm-octavia/770417/1/21111/index.html