get_keystone_manager exhausts retries on: Unable to establish connection to http://localhost:35347/v2.0/OS-KSADM/services

[Ryan Beisner]

get_keystone_manager exhausts retries on Unable to establish connection to http://localhost:35347/v2.0/OS-KSADM/services

Following the landing of the mod_wsgi keystone bits in next, I've observed a handful of these fails within 1 day. A retry generally makes the hook not fail.

This happens to be Wily-Liberty. I've not tracked or collected release/combo info as of yet. Just want to get this raised for review.

2016-04-07 22:15:34 INFO juju-log identity-service:12: Retrying 'get_keystone_manager' 1 more times (delay=15)
2016-04-07 22:15:49 INFO identity-service-relation-changed Traceback (most recent call last):
2016-04-07 22:15:49 INFO identity-service-relation-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/identity-service-relation-changed", line 689, in <module>
2016-04-07 22:15:49 INFO identity-service-relation-changed main()
2016-04-07 22:15:49 INFO identity-service-relation-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/identity-service-relation-changed", line 682, in main
2016-04-07 22:15:49 INFO identity-service-relation-changed hooks.execute(sys.argv)
2016-04-07 22:15:49 INFO identity-service-relation-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/charmhelpers/core/hookenv.py", line 717, in execute
2016-04-07 22:15:49 INFO identity-service-relation-changed self._hooks[hook_name]()
2016-04-07 22:15:49 INFO identity-service-relation-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/charmhelpers/contrib/openstack/utils.py", line 1571, in wrapped_f
2016-04-07 22:15:49 INFO identity-service-relation-changed (lambda: f(*args, **kwargs)), restart_map, stopstart)
2016-04-07 22:15:49 INFO identity-service-relation-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/charmhelpers/core/host.py", line 470, in restart_on_change_helper
2016-04-07 22:15:49 INFO identity-service-relation-changed r = lambda_f()
2016-04-07 22:15:49 INFO identity-service-relation-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/charmhelpers/contrib/openstack/utils.py", line 1571, in <lambda>
2016-04-07 22:15:49 INFO identity-service-relation-changed (lambda: f(*args, **kwargs)), restart_map, stopstart)
2016-04-07 22:15:49 INFO identity-service-relation-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/keystone_utils.py", line 1430, in inner_synchronize_ca_if_changed2
2016-04-07 22:15:49 INFO identity-service-relation-changed ret = f(*args, **kwargs)
2016-04-07 22:15:49 INFO identity-service-relation-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/identity-service-relation-changed", line 361, in identity_changed
2016-04-07 22:15:49 INFO identity-service-relation-changed add_service_to_keystone(relation_id, remote_unit)
2016-04-07 22:15:49 INFO identity-service-relation-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/keystone_utils.py", line 1576, in add_service_to_keystone
2016-04-07 22:15:49 INFO identity-service-relation-changed manager = get_manager()
2016-04-07 22:15:49 INFO identity-service-relation-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/keystone_utils.py", line 741, in get_manager
2016-04-07 22:15:49 INFO identity-service-relation-changed api_version)
2016-04-07 22:15:49 INFO identity-service-relation-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/charmhelpers/core/decorators.py", line 42, in _retry_on_exception_inner_2
2016-04-07 22:15:49 INFO identity-service-relation-changed return f(*args, **kwargs)
2016-04-07 22:15:49 INFO identity-service-relation-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/manager.py", line 60, in get_keystone_manager
2016-04-07 22:15:49 INFO identity-service-relation-changed for svc in manager.api.services.list():
2016-04-07 22:15:49 INFO identity-service-relation-changed File "/usr/lib/python2.7/dist-packages/keystoneclient/v2_0/services.py", line 32, in list
2016-04-07 22:15:49 INFO identity-service-relation-changed return self._list("/OS-KSADM/services", "OS-KSADM:services")
2016-04-07 22:15:49 INFO identity-service-relation-changed File "/usr/lib/python2.7/dist-packages/keystoneclient/base.py", line 124, in _list
2016-04-07 22:15:49 INFO identity-service-relation-changed resp, body = self.client.get(url, **kwargs)
2016-04-07 22:15:49 INFO identity-service-relation-changed File "/usr/lib/python2.7/dist-packages/keystoneclient/adapter.py", line 170, in get
2016-04-07 22:15:49 INFO identity-service-relation-changed return self.request(url, 'GET', **kwargs)
2016-04-07 22:15:49 INFO identity-service-relation-changed File "/usr/lib/python2.7/dist-packages/keystoneclient/adapter.py", line 206, in request
2016-04-07 22:15:49 INFO identity-service-relation-changed resp = super(LegacyJsonAdapter, self).request(*args, **kwargs)
2016-04-07 22:15:49 INFO identity-service-relation-changed File "/usr/lib/python2.7/dist-packages/keystoneclient/adapter.py", line 95, in request
2016-04-07 22:15:49 INFO identity-service-relation-changed return self.session.request(url, method, **kwargs)
2016-04-07 22:15:49 INFO identity-service-relation-changed File "/usr/lib/python2.7/dist-packages/keystoneclient/utils.py", line 337, in inner
2016-04-07 22:15:49 INFO identity-service-relation-changed return func(*args, **kwargs)
2016-04-07 22:15:49 INFO identity-service-relation-changed File "/usr/lib/python2.7/dist-packages/keystoneclient/session.py", line 386, in request
2016-04-07 22:15:49 INFO identity-service-relation-changed resp = send(**kwargs)
2016-04-07 22:15:49 INFO identity-service-relation-changed File "/usr/lib/python2.7/dist-packages/keystoneclient/session.py", line 430, in _send_request
2016-04-07 22:15:49 INFO identity-service-relation-changed raise exceptions.ConnectionRefused(msg)
2016-04-07 22:15:49 INFO identity-service-relation-changed keystoneclient.exceptions.ConnectionRefused: Unable to establish connection to http://localhost:35347/v2.0/OS-KSADM/services
2016-04-07 22:15:49 INFO juju.worker.uniter.context context.go:579 handling reboot
2016-04-07 22:15:49 ERROR juju.worker.uniter.operation runhook.go:107 hook "identity-service-relation-changed" failed: exit status 1
2016-04-07 22:15:49 DEBUG juju.worker.uniter modes.go:31 [AGENT-STATUS] failed: run relation-changed (12; glance/0) hook
2016-04-07 22:15:50 INFO juju.worker.uniter modes.go:569 ModeAbide exiting
2016-04-07 22:15:50 INFO juju.worker.uniter modes.go:567 ModeHookError starting
2016-04-07 22:15:50 DEBUG juju.worker.uniter.filter filter.go:601 want resolved event

[Liam Young (gnuoy)]

I haven't been able to reproduce this (tried wily/liberty amulet tests for glance and cinder). Next time it happens could you indicate which amulet tests the break was seen in and if it was a deploy on metal. Better still I'd love to get access to the env with the error'd hook still present

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/303538
Committed: https://git.openstack.org/cgit/openstack/charm-keystone/commit/?id=eae361c36e4084e85c78c9295467900e7a86c4c1
Submitter: Jenkins
Branch: master

commit eae361c36e4084e85c78c9295467900e7a86c4c1
Author: Liam Young <email address hidden>
Date: Fri Apr 8 16:57:02 2016 +0000

    Restart apache2 safely when using mod_wsgi

    The restart_on_change function uses the underlying init systems service
    control programs to stop/start/restart services. However, sometimes
    these misbehave like apache2 with mod_wsgi which can leave process
    running after stop has completed which then block start from running.
    These change ensures that apache really has stopped before starting it.

    Change-Id: I8255d8f5371f7bb0783878253afafcf27275b6b8
    Closes-Bug: 1567741