Incomplete relation occasionally leading to KeyError in keystone_wait_for_propagation()

[Frode Nordahl]

DEBUG:runner:juju-log: INFO: Retrying 'keystone_wait_for_propagation' 1 more times (delay=50)
DEBUG:runner:2017-03-01 11:35:51,532 keystone_wait_for_propagation DEBUG: keystone relation data: {u'service_protocol': u'http', u'service_tenant': u'services', u'admin_token': u'ubuntutesting', u'service_password': u'XZ4d43ZtLHhrVGKcqSPLb5h6HHJBcxbSBKLZBsJwW5FfY99Wb32s8Hmw9w2ydzdN', u'service_port': u'5000', u'auth_port': u'35357', u'auth_protocol': u'http', u'private-address': u'10.5.27.149', u'service_host': u'10.5.27.148', u'auth_host': u'10.5.27.148', u'service_username': u'cinder_cinderv2', u'service_tenant_id': u'38ff00c7a3f14e4183610f7f099b945d', u'api_version': u'2'}
DEBUG:runner:2017-03-01 11:35:55,495 keystone_wait_for_propagation DEBUG: keystone relation data: {u'service_protocol': u'http', u'service_tenant': u'services', u'admin_token': u'ubuntutesting', u'service_password': u'XZ4d43ZtLHhrVGKcqSPLb5h6HHJBcxbSBKLZBsJwW5FfY99Wb32s8Hmw9w2ydzdN', u'service_port': u'5000', u'auth_port': u'35357', u'auth_protocol': u'http', u'private-address': u'10.5.27.148', u'service_host': u'10.5.27.148', u'auth_host': u'10.5.27.148', u'service_username': u'cinder_cinderv2', u'service_tenant_id': u'38ff00c7a3f14e4183610f7f099b945d', u'api_version': u'2'}
DEBUG:runner:2017-03-01 11:35:59,542 keystone_wait_for_propagation DEBUG: keystone relation data: {u'private-address': u'10.5.27.150'}
DEBUG:runner:Traceback (most recent call last):
DEBUG:runner: File "/tmp/bundletester-oi3GTH/keystone/tests/gate-basic-trusty-kilo", line 24, in <module>
DEBUG:runner: source='cloud:trusty-updates/kilo')
DEBUG:runner: File "/tmp/bundletester-oi3GTH/keystone/tests/basic_deployment.py", line 65, in __init__
DEBUG:runner: self._initialize_tests()
DEBUG:runner: File "/tmp/bundletester-oi3GTH/keystone/tests/basic_deployment.py", line 289, in _initialize_tests
DEBUG:runner: self.set_api_version(2)
DEBUG:runner: File "/tmp/bundletester-oi3GTH/keystone/tests/basic_deployment.py", line 160, in set_api_version
DEBUG:runner: u.keystone_configure_api_version(se_rels, self, api_version)
DEBUG:runner: File "/tmp/bundletester-oi3GTH/keystone/tests/charmhelpers/contrib/openstack/amulet/utils.py", line 346, in keystone_configure_api_version
DEBUG:runner: self.keystone_wait_for_propagation(sentry_relation_pairs, api_version)
DEBUG:runner: File "/tmp/bundletester-oi3GTH/keystone/tests/charmhelpers/core/decorators.py", line 40, in _retry_on_exception_inner_2
DEBUG:runner: return f(*args, **kwargs)
DEBUG:runner: File "/tmp/bundletester-oi3GTH/keystone/tests/charmhelpers/contrib/openstack/amulet/utils.py", line 324, in keystone_wait_for_propagation
DEBUG:runner: if rel['api_version'] != str(api_version):
DEBUG:runner:KeyError: 'api_version'
DEBUG:runner:Exit Code: 1
==
keystone/746 active idle 1.25.10 2253 5000/tcp 10.5.27.150 Unit is ready
==
$ juju run --unit cinder/291 'relation-ids identity-service'
identity-service:3742
$ juju run --unit cinder/291 'relation-get -r 3742 -- - keystone/744'
admin_token: ubuntutesting
api_version: "2"
auth_host: 10.5.27.148
auth_port: "35357"
auth_protocol: http
private-address: 10.5.27.149
service_host: 10.5.27.148
service_password: XZ4d43ZtLHhrVGKcqSPLb5h6HHJBcxbSBKLZBsJwW5FfY99Wb32s8Hmw9w2ydzdN
service_port: "5000"
service_protocol: http
service_tenant: services
service_tenant_id: 38ff00c7a3f14e4183610f7f099b945d
service_username: cinder_cinderv2
$ juju run --unit cinder/291 'relation-get -r 3742 -- - keystone/745'
admin_token: ubuntutesting
api_version: "2"
auth_host: 10.5.27.148
auth_port: "35357"
auth_protocol: http
private-address: 10.5.27.148
service_host: 10.5.27.148
service_password: XZ4d43ZtLHhrVGKcqSPLb5h6HHJBcxbSBKLZBsJwW5FfY99Wb32s8Hmw9w2ydzdN
service_port: "5000"
service_protocol: http
service_tenant: services
service_tenant_id: 38ff00c7a3f14e4183610f7f099b945d
service_username: cinder_cinderv2
$ juju run --unit cinder/291 'relation-get -r 3742 -- - keystone/746'
private-address: 10.5.27.150

[Felipe Reyes (freyes)]

Another occurrence of this bug: https://review.openstack.org/#/c/566763/1

[Felipe Reyes (freyes)]

The attached MP was attempting to address the error while the message is being formatted which it's already fixed by https://github.com/freyes/charm-helpers/commit/1117ba6d00c3ae1d54835f17e42cef106a416f4c

But the underlying problem of raising the Exception prematurely needs to be solved, the absence of api_version attribute in the relation may simply mean that keystone is not ready and polling for N seconds is needed before raising the error.

[Felipe Reyes (freyes)]

wrapped keystone_wait_for_propagation() with @retry_on_exception()

https://github.com/juju/charm-helpers/commit/edd813b734f230658ed9c06b8be86316ed8bbb45

[Felipe Reyes (freyes)]

Syncing the fix into charm-keystone -> https://review.openstack.org/#/c/567658/

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/567658
Committed: https://git.openstack.org/cgit/openstack/charm-keystone/commit/?id=0e9020bd2a90ec301d9666195faeb7e2cbe4d089
Submitter: Zuul
Branch: master

commit 0e9020bd2a90ec301d9666195faeb7e2cbe4d089
Author: Felipe Reyes <email address hidden>
Date: Thu May 10 14:50:59 2018 -0300

    Sync charm-helpers

    Retry keystone_wait_for_propagation() on exception.

    Closes-Bug: #1668954
    Change-Id: I5e5689dbd5cd974b11e017b6d0f06575cabcceb2

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/18.02
Review: https://review.openstack.org/567968

[OpenStack Infra (hudson-openstack)]

Change abandoned by Felipe Reyes (<email address hidden>) on branch: stable/18.02
Review: https://review.openstack.org/567968
Reason: backport not needed since https://review.openstack.org/568299 was merged into stable/18.02