shared-db-relation-changed fails to list keystone manager services

[Michael Skalka]

Openstack Queens deployed on Xenial with Keystone and mysql (percona) in HA. Keystone fails with

2018-08-28 11:29:42 DEBUG shared-db-relation-changed /usr/lib/python2.7/dist-packages/keystoneauth1/adapter.py:179: UserWarning: Using keystoneclient sessions has been deprecated. Please update your software to use keystoneauth1.
2018-08-28 11:29:42 DEBUG shared-db-relation-changed warnings.warn('Using keystoneclient sessions has been deprecated. '
2018-08-28 11:29:42 DEBUG shared-db-relation-changed Traceback (most recent call last):
2018-08-28 11:29:42 DEBUG shared-db-relation-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/shared-db-relation-changed", line 992, in <module>
2018-08-28 11:29:42 DEBUG shared-db-relation-changed main()
2018-08-28 11:29:42 DEBUG shared-db-relation-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/shared-db-relation-changed", line 985, in main
2018-08-28 11:29:42 DEBUG shared-db-relation-changed hooks.execute(sys.argv)
2018-08-28 11:29:42 DEBUG shared-db-relation-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/charmhelpers/core/hookenv.py", line 823, in execute
2018-08-28 11:29:42 DEBUG shared-db-relation-changed self._hooks[hook_name]()
2018-08-28 11:29:42 DEBUG shared-db-relation-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/charmhelpers/contrib/openstack/utils.py", line 1449, in wrapped_f
2018-08-28 11:29:42 DEBUG shared-db-relation-changed restart_functions)
2018-08-28 11:29:42 DEBUG shared-db-relation-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/charmhelpers/core/host.py", line 730, in restart_on_change_helper
2018-08-28 11:29:42 DEBUG shared-db-relation-changed r = lambda_f()
2018-08-28 11:29:42 DEBUG shared-db-relation-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/charmhelpers/contrib/openstack/utils.py", line 1448, in <lambda>
2018-08-28 11:29:42 DEBUG shared-db-relation-changed (lambda: f(*args, **kwargs)), restart_map, stopstart,
2018-08-28 11:29:42 DEBUG shared-db-relation-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/keystone_utils.py", line 1805, in inner_synchronize_ca_if_changed2
2018-08-28 11:29:42 DEBUG shared-db-relation-changed return f(*args, **kwargs)
2018-08-28 11:29:42 DEBUG shared-db-relation-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/shared-db-relation-changed", line 440, in db_changed
2018-08-28 11:29:42 DEBUG shared-db-relation-changed leader_init_db_if_ready(use_current_context=True)
2018-08-28 11:29:42 DEBUG shared-db-relation-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/shared-db-relation-changed", line 414, in leader_init_db_if_ready
2018-08-28 11:29:42 DEBUG shared-db-relation-changed update_all_identity_relation_units(check_db_ready=False)
2018-08-28 11:29:42 DEBUG shared-db-relation-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/shared-db-relation-changed", line 365, in update_all_identity_relation_units
2018-08-28 11:29:42 DEBUG shared-db-relation-changed ensure_initial_admin(config)
2018-08-28 11:29:42 DEBUG shared-db-relation-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/keystone_utils.py", line 1221, in ensure_initial_admin
2018-08-28 11:29:42 DEBUG shared-db-relation-changed return _ensure_initial_admin(config)
2018-08-28 11:29:42 DEBUG shared-db-relation-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/charmhelpers/core/decorators.py", line 40, in _retry_on_exception_inner_2
2018-08-28 11:29:42 DEBUG shared-db-relation-changed return f(*args, **kwargs)
2018-08-28 11:29:42 DEBUG shared-db-relation-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/keystone_utils.py", line 1164, in _ensure_initial_admin
2018-08-28 11:29:42 DEBUG shared-db-relation-changed manager = get_manager()
2018-08-28 11:29:42 DEBUG shared-db-relation-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/keystone_utils.py", line 993, in get_manager
2018-08-28 11:29:42 DEBUG shared-db-relation-changed api_version)
2018-08-28 11:29:42 DEBUG shared-db-relation-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/charmhelpers/core/decorators.py", line 40, in _retry_on_exception_inner_2
2018-08-28 11:29:42 DEBUG shared-db-relation-changed return f(*args, **kwargs)
2018-08-28 11:29:42 DEBUG shared-db-relation-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/manager.py", line 75, in get_keystone_manager
2018-08-28 11:29:42 DEBUG shared-db-relation-changed for svc in manager.api.services.list():
2018-08-28 11:29:42 DEBUG shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/keystoneclient/v3/services.py", line 93, in list
2018-08-28 11:29:42 DEBUG shared-db-relation-changed **kwargs)
2018-08-28 11:29:42 DEBUG shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/keystoneclient/base.py", line 75, in func
2018-08-28 11:29:42 DEBUG shared-db-relation-changed return f(*args, **new_kwargs)
2018-08-28 11:29:42 DEBUG shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/keystoneclient/base.py", line 397, in list
2018-08-28 11:29:42 DEBUG shared-db-relation-changed self.collection_key)
2018-08-28 11:29:42 DEBUG shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/keystoneclient/base.py", line 130, in _list
2018-08-28 11:29:42 DEBUG shared-db-relation-changed data = body[response_key]
2018-08-28 11:29:42 DEBUG shared-db-relation-changed TypeError: 'NoneType' object has no attribute '__getitem__'

Exploring the manager object the charm generates in the hook reveals that it's basically empty.

This environment is home to a fairly restrictive proxy, however the entire juju model has the no_proxy env variable set to the CIDR that encompasses the OpenStack cloud and at least from the command line each node has no issue seeing its peers and the two Keystone VIPs (internal and public).

Attached is a dump of the keystone and mysql unit logs along with the service logs from mysql and the only keystone unit which started logging (the leader).

[Ryan Beisner (1chb1n)]

The no_proxy env var is not cidr-friendly for many (most?) libraries and applications. AFAIK, the only safe way to use no_proxy in this case is to include each distinct address, for all unit addresses and VIPs. This will ensure that each unit can communicate directly with each of the other units.

It's not immediately clear from the attached logs what has happened. We would need a full juju crashdump, possibly with higher logging level configured on the affected juju applications, and a sanitized bundle from this deployment, as well as sanitized non-default model config and proxy no_proxy and other related proxy model configs in order to advise further.

See also https://docs.jujucharms.com/2.4/en/charms-offline-strategies which talks about the limitations on cidr usage, and foreshadows some upcoming changes to help work around this classic challenge.

[Ryan Beisner (1chb1n)]

Just for completeness, the attached logs tell me that:

Mysql (pxc) system service error logs look normal.

Mysql (pxc) juju application unit logs look normal and report the 3 expected db units are clustered:
2018-08-28 12:01:41 DEBUG juju-log All 3 percona units reporting clustered

Keystone/0 reaches a condition which I've also not seen before. Please address the proxy config as advised, and if this condition still exists, try to grab both juju and charm application logs at a more verbose level:
2018-08-28 11:44:19 DEBUG juju-log shared-db:62: Database is initialised
2018-08-28 11:58:31 ERROR juju.worker.uniter.operation runhook.go:114 hook "shared-db-relation-changed" failed: signal: killed

Keystone/1 looks ok, log indicates awareness of the VIPs:
2018-08-28 12:01:01 DEBUG juju-log VIP HA: VIP is set 10.22.6.28 10.22.4.28

Keystone/2 looks ok, log indicates awareness of the VIPs:
2018-08-28 12:00:25 DEBUG juju-log VIP HA: VIP is set 10.22.6.28 10.22.4.28

[Dmitrii Shcherbakov (dmitriis)]

There were changes in Juju itself to stop adding HTTP_PROXY, HTTPS_PROXY and NO_PROXY to environment variables during an execve(2) in charm processes forked from unit agents.

The old behavior is preserved if http-proxy, https-proxy and no-proxy legacy model-configs are used. New juju-http-proxy, juju-https-proxy, juju-no-proxy model-configs have to be used in order to stop adding proxies to the charm process environment which prevents http clients used during charm execution from being affected by model-configs. None of the node-global environment settings are affected by juju as well.

Juju processes (machine and unit agents) themselves are affected by juju-* settings and also support CIDR notation which is a desired behavior for bootstrapping and charm downloads.

Converting from legacy to new proxy settings can be done on a live model by changing model-configs for legacy settings to "" and adding new model configs instead. If any of the legacy configs are present, only legacy configs will be used. The change is propagated down to juju agents via a proxyupdater logic that changes in-process environment variables so no manual agent restarts are needed.

There was a bug in 2.4.0 and 2.4.1 https://bugs.launchpad.net/juju/+bug/1782236 that prevented new settings from being effective even if legacy proxy settings were not specified at all.

This was fixed for 2.4.2:
https://github.com/juju/juju/pull/8949
https://github.com/juju/juju/commit/5eb1b9275dc6ca039b9b32ff814b479e6ec497d1

(juju) git tag --contains=5eb1b9275dc6ca039b9b32ff814b479e6ec497d1
juju-2.4.2

Michael, could you confirm which model-config settings are used on the OpenStack model and if juju run --unit keystone/0 'env | grep HTTP' returns JUJU_* variables only? Also check the juju version and make sure it is 2.4.2 at least to rule out proxy settings from this issue.

[Launchpad Janitor (janitor)]

[Expired for OpenStack keystone charm because there has been no activity for 60 days.]