ERROR juju-log The call within manager.py failed with the error: 'The request you have made requires authentication. (HTTP 401)

Bug #1852379 reported by Frode Nordahl
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
OpenStack Keystone Charm
Triaged
High
Unassigned

Bug Description

During a gate test for a different charm for release combination xenial-ocata:
Traceback (most recent call last):
  File "/tmp/tmp.szFWl0WDlc/func/bin/functest-run-suite", line 8, in <module>
    sys.exit(main())
  File "/tmp/tmp.szFWl0WDlc/func/lib/python3.5/site-packages/zaza/charm_lifecycle/func_test_runner.py", line 162, in main
    bundle=args.bundle)
  File "/tmp/tmp.szFWl0WDlc/func/lib/python3.5/site-packages/zaza/charm_lifecycle/func_test_runner.py", line 107, in func_test_runner
    run_env_deployment(env_deployment, keep_model=preserve_model)
  File "/tmp/tmp.szFWl0WDlc/func/lib/python3.5/site-packages/zaza/charm_lifecycle/func_test_runner.py", line 58, in run_env_deployment
    config_steps.get(deployment.model_alias, []))
  File "/tmp/tmp.szFWl0WDlc/func/lib/python3.5/site-packages/zaza/charm_lifecycle/configure.py", line 48, in configure
    run_configure_list(functions)
  File "/tmp/tmp.szFWl0WDlc/func/lib/python3.5/site-packages/zaza/charm_lifecycle/configure.py", line 37, in run_configure_list
    utils.get_class(func)()
  File "/tmp/tmp.szFWl0WDlc/func/lib/python3.5/site-packages/zaza/openstack/charm_tests/keystone/setup.py", line 114, in add_demo_user
    _v3()
  File "/usr/lib/python3.5/contextlib.py", line 66, in __exit__
    next(self.gen)
  File "/tmp/tmp.szFWl0WDlc/func/lib/python3.5/site-packages/zaza/openstack/charm_tests/test_utils.py", line 192, in config_change
    model.block_until_all_units_idle()
  File "/tmp/tmp.szFWl0WDlc/func/lib/python3.5/site-packages/zaza/__init__.py", line 48, in _wrapper
    return run(_run_it())
  File "/tmp/tmp.szFWl0WDlc/func/lib/python3.5/site-packages/zaza/__init__.py", line 36, in run
    return task.result()
  File "/usr/lib/python3.5/asyncio/futures.py", line 274, in result
    raise self._exception
  File "/usr/lib/python3.5/asyncio/tasks.py", line 239, in _step
    result = coro.send(None)
  File "/tmp/tmp.szFWl0WDlc/func/lib/python3.5/site-packages/zaza/__init__.py", line 47, in _run_it
    return await f(*args, **kwargs)
  File "/tmp/tmp.szFWl0WDlc/func/lib/python3.5/site-packages/zaza/model.py", line 943, in async_block_until_all_units_idle
    raise UnitError(errored_units)
zaza.model.UnitError: Units keystone/0 in error state

/var/log/juju/unit-keystone-0.log:
2019-11-13 00:12:32 INFO juju-log Registered config file: /etc/keystone/keystone.conf
2019-11-13 00:12:32 INFO juju-log Registered config file: /etc/keystone/logging.conf
2019-11-13 00:12:32 INFO juju-log Registered config file: /etc/haproxy/haproxy.cfg
2019-11-13 00:12:32 INFO juju-log Registered config file: /etc/apache2/sites-available/openstack_https_frontend.conf
2019-11-13 00:12:32 INFO juju-log Registered config file: /etc/keystone/policy.json
2019-11-13 00:12:33 INFO juju-log Registered config file: /etc/cron.d/keystone-token-flush
2019-11-13 00:12:33 INFO juju-log Registered config file: /etc/cron.d/keystone-fernet-rotate-sync
2019-11-13 00:12:33 INFO juju-log Registered config file: /etc/apache2/sites-enabled/wsgi-openstack-api.conf
2019-11-13 00:12:33 INFO juju-log Registered config file: /etc/memcached.conf
2019-11-13 00:12:35 DEBUG juju-log Hardening function 'config_changed'
2019-11-13 00:12:35 DEBUG juju-log No hardening applied to 'config_changed'
2019-11-13 00:12:36 DEBUG juju-log Hardening function 'config_changed_postupgrade'
2019-11-13 00:12:36 DEBUG juju-log No hardening applied to 'config_changed_postupgrade'
2019-11-13 00:12:39 INFO juju-log Installing [] with options: ['--option=Dpkg::Options::=--force-confold']
2019-11-13 00:12:39 DEBUG config-changed Reading package lists...
2019-11-13 00:12:39 DEBUG config-changed Building dependency tree...
2019-11-13 00:12:39 DEBUG config-changed Reading state information...
2019-11-13 00:12:39 DEBUG config-changed 0 upgraded, 0 newly installed, 0 to remove and 19 not upgraded.
2019-11-13 00:12:39 DEBUG config-changed inactive
2019-11-13 00:12:40 DEBUG config-changed none
2019-11-13 00:12:40 INFO juju-log Configuring Keystone to use a random admin token.
2019-11-13 00:12:40 INFO juju-log Loading a previously generated admin token from /var/lib/keystone/keystone.token
2019-11-13 00:12:40 INFO juju-log Loaded template from templates/wsgi-openstack-api.conf
2019-11-13 00:12:40 INFO juju-log Rendering from template: /etc/apache2/sites-enabled/wsgi-openstack-api.conf
2019-11-13 00:12:40 INFO juju-log Wrote template /etc/apache2/sites-enabled/wsgi-openstack-api.conf.
2019-11-13 00:12:41 INFO juju-log Checking no pids for apache2 exist
2019-11-13 00:12:41 DEBUG config-changed 31513
2019-11-13 00:12:41 DEBUG config-changed 31516
2019-11-13 00:12:41 DEBUG config-changed 31517
2019-11-13 00:12:41 INFO juju-log Retrying 'check_pids_gone' 5 more times (delay=3)
2019-11-13 00:12:44 INFO juju-log Checking no pids for apache2 exist
2019-11-13 00:12:52 INFO juju-log Installing [] with options: ['--option=Dpkg::Options::=--force-confold']
2019-11-13 00:12:52 DEBUG config-changed Reading package lists...
2019-11-13 00:12:52 DEBUG config-changed Building dependency tree...
2019-11-13 00:12:52 DEBUG config-changed Reading state information...
2019-11-13 00:12:52 DEBUG config-changed 0 upgraded, 0 newly installed, 0 to remove and 19 not upgraded.
2019-11-13 00:12:52 DEBUG config-changed none
2019-11-13 00:12:53 INFO juju-log Configuring Keystone to use a random admin token.
2019-11-13 00:12:53 INFO juju-log Loading a previously generated admin token from /var/lib/keystone/keystone.token
2019-11-13 00:12:53 INFO juju-log Loaded template from templates/wsgi-openstack-api.conf
2019-11-13 00:12:53 INFO juju-log Rendering from template: /etc/apache2/sites-enabled/wsgi-openstack-api.conf
2019-11-13 00:12:53 INFO juju-log Wrote template /etc/apache2/sites-enabled/wsgi-openstack-api.conf.
2019-11-13 00:12:54 INFO juju-log Configuring Keystone to use a random admin token.
2019-11-13 00:12:54 INFO juju-log Loading a previously generated admin token from /var/lib/keystone/keystone.token
2019-11-13 00:12:54 DEBUG config-changed ERROR no relation id specified
2019-11-13 00:12:54 INFO juju-log HAProxy context is incomplete, this unit has no peers.
2019-11-13 00:12:54 DEBUG config-changed none
2019-11-13 00:12:54 DEBUG juju-log 0 section(s) found
2019-11-13 00:12:54 INFO juju-log Loaded template from templates/ocata/keystone.conf
2019-11-13 00:12:54 INFO juju-log Rendering from template: /etc/keystone/keystone.conf
2019-11-13 00:12:54 INFO juju-log Wrote template /etc/keystone/keystone.conf.
2019-11-13 00:12:55 INFO juju-log Loaded template from templates/openstack_https_frontend.conf
2019-11-13 00:12:55 INFO juju-log Rendering from template: /etc/apache2/sites-available/openstack_https_frontend.conf
2019-11-13 00:12:55 INFO juju-log Wrote template /etc/apache2/sites-available/openstack_https_frontend.conf.
2019-11-13 00:12:55 INFO juju-log Configuring Keystone to use a random admin token.
2019-11-13 00:12:55 INFO juju-log Loading a previously generated admin token from /var/lib/keystone/keystone.token
2019-11-13 00:12:55 INFO juju-log Loaded template from templates/ocata/policy.json
2019-11-13 00:12:55 INFO juju-log Rendering from template: /etc/keystone/policy.json
2019-11-13 00:12:55 INFO juju-log Wrote template /etc/keystone/policy.json.
2019-11-13 00:12:55 INFO juju-log Loaded template from templates/keystone-fernet-rotate-sync
2019-11-13 00:12:55 INFO juju-log Rendering from template: /etc/cron.d/keystone-fernet-rotate-sync
2019-11-13 00:12:55 INFO juju-log Wrote template /etc/cron.d/keystone-fernet-rotate-sync.
2019-11-13 00:12:56 INFO juju-log Loaded template from templates/keystone-token-flush
2019-11-13 00:12:56 INFO juju-log Rendering from template: /etc/cron.d/keystone-token-flush
2019-11-13 00:12:56 INFO juju-log Wrote template /etc/cron.d/keystone-token-flush.
2019-11-13 00:12:56 INFO juju-log Loaded template from /var/lib/juju/agents/unit-keystone-0/charm/charmhelpers/contrib/openstack/templates/memcached.conf
2019-11-13 00:12:56 INFO juju-log Rendering from template: /etc/memcached.conf
2019-11-13 00:12:56 INFO juju-log Wrote template /etc/memcached.conf.
2019-11-13 00:12:56 DEBUG juju-log Ensuring haproxy enabled in /etc/default/haproxy.
2019-11-13 00:12:57 INFO juju-log HAProxy context is incomplete, this unit has no peers.
2019-11-13 00:12:57 INFO juju-log Loaded template from /var/lib/juju/agents/unit-keystone-0/charm/charmhelpers/contrib/openstack/templates/haproxy.cfg
2019-11-13 00:12:57 INFO juju-log Rendering from template: /etc/haproxy/haproxy.cfg
2019-11-13 00:12:57 INFO juju-log Wrote template /etc/haproxy/haproxy.cfg.
2019-11-13 00:12:57 INFO juju-log Loaded template from templates/ocata/logging.conf
2019-11-13 00:12:57 INFO juju-log Rendering from template: /etc/keystone/logging.conf
2019-11-13 00:12:57 INFO juju-log Wrote template /etc/keystone/logging.conf.
2019-11-13 00:12:57 DEBUG config-changed none
2019-11-13 00:12:57 INFO juju-log Configuring Keystone to use a random admin token.
2019-11-13 00:12:57 INFO juju-log Loading a previously generated admin token from /var/lib/keystone/keystone.token
2019-11-13 00:12:57 INFO juju-log Configuring Keystone to use a random admin token.
2019-11-13 00:12:58 INFO juju-log Loading a previously generated admin token from /var/lib/keystone/keystone.token
2019-11-13 00:12:58 DEBUG config-changed Site openstack_https_frontend already disabled
2019-11-13 00:12:58 INFO juju-log Updating NRPE configuration
2019-11-13 00:12:58 INFO juju-log Installing python-dbus with options: ['--option=Dpkg::Options::=--force-confold']
2019-11-13 00:12:58 DEBUG config-changed Reading package lists...
2019-11-13 00:12:58 DEBUG config-changed Building dependency tree...
2019-11-13 00:12:58 DEBUG config-changed Reading state information...
2019-11-13 00:12:58 DEBUG config-changed python-dbus is already the newest version (1.2.0-3).
2019-11-13 00:12:58 DEBUG config-changed 0 upgraded, 0 newly installed, 0 to remove and 19 not upgraded.
2019-11-13 00:12:58 INFO juju-log Check command not found: check_systemd.py
2019-11-13 00:12:59 INFO juju-log Check command not found: check_systemd.py
2019-11-13 00:12:59 INFO juju-log Check command not found: check_systemd.py
2019-11-13 00:12:59 INFO juju-log Nagios user not set up, nrpe checks not updated
2019-11-13 00:12:59 DEBUG config-changed none
2019-11-13 00:12:59 INFO juju-log Configuring Keystone to use a random admin token.
2019-11-13 00:12:59 INFO juju-log Loading a previously generated admin token from /var/lib/keystone/keystone.token
2019-11-13 00:12:59 INFO juju-log Loaded template from templates/wsgi-openstack-api.conf
2019-11-13 00:12:59 INFO juju-log Rendering from template: /etc/apache2/sites-enabled/wsgi-openstack-api.conf
2019-11-13 00:12:59 INFO juju-log Wrote template /etc/apache2/sites-enabled/wsgi-openstack-api.conf.
2019-11-13 00:12:59 INFO juju-log Configuring Keystone to use a random admin token.
2019-11-13 00:12:59 INFO juju-log Loading a previously generated admin token from /var/lib/keystone/keystone.token
2019-11-13 00:13:00 INFO juju-log HAProxy context is incomplete, this unit has no peers.
2019-11-13 00:13:00 DEBUG config-changed none
2019-11-13 00:13:00 DEBUG juju-log 0 section(s) found
2019-11-13 00:13:00 INFO juju-log Loaded template from templates/ocata/keystone.conf
2019-11-13 00:13:00 INFO juju-log Rendering from template: /etc/keystone/keystone.conf
2019-11-13 00:13:00 INFO juju-log Wrote template /etc/keystone/keystone.conf.
2019-11-13 00:13:00 INFO juju-log Loaded template from templates/openstack_https_frontend.conf
2019-11-13 00:13:00 INFO juju-log Rendering from template: /etc/apache2/sites-available/openstack_https_frontend.conf
2019-11-13 00:13:00 INFO juju-log Wrote template /etc/apache2/sites-available/openstack_https_frontend.conf.
2019-11-13 00:13:00 INFO juju-log Configuring Keystone to use a random admin token.
2019-11-13 00:13:00 INFO juju-log Loading a previously generated admin token from /var/lib/keystone/keystone.token
2019-11-13 00:13:01 INFO juju-log Loaded template from templates/ocata/policy.json
2019-11-13 00:13:01 INFO juju-log Rendering from template: /etc/keystone/policy.json
2019-11-13 00:13:01 INFO juju-log Wrote template /etc/keystone/policy.json.
2019-11-13 00:13:01 INFO juju-log Loaded template from templates/keystone-fernet-rotate-sync
2019-11-13 00:13:01 INFO juju-log Rendering from template: /etc/cron.d/keystone-fernet-rotate-sync
2019-11-13 00:13:01 INFO juju-log Wrote template /etc/cron.d/keystone-fernet-rotate-sync.
2019-11-13 00:13:01 INFO juju-log Loaded template from templates/keystone-token-flush
2019-11-13 00:13:01 INFO juju-log Rendering from template: /etc/cron.d/keystone-token-flush
2019-11-13 00:13:01 INFO juju-log Wrote template /etc/cron.d/keystone-token-flush.
2019-11-13 00:13:01 INFO juju-log Loaded template from /var/lib/juju/agents/unit-keystone-0/charm/charmhelpers/contrib/openstack/templates/memcached.conf
2019-11-13 00:13:01 INFO juju-log Rendering from template: /etc/memcached.conf
2019-11-13 00:13:01 INFO juju-log Wrote template /etc/memcached.conf.
2019-11-13 00:13:02 DEBUG juju-log Ensuring haproxy enabled in /etc/default/haproxy.
2019-11-13 00:13:02 INFO juju-log HAProxy context is incomplete, this unit has no peers.
2019-11-13 00:13:02 INFO juju-log Loaded template from /var/lib/juju/agents/unit-keystone-0/charm/charmhelpers/contrib/openstack/templates/haproxy.cfg
2019-11-13 00:13:02 INFO juju-log Rendering from template: /etc/haproxy/haproxy.cfg
2019-11-13 00:13:02 INFO juju-log Wrote template /etc/haproxy/haproxy.cfg.
2019-11-13 00:13:03 INFO juju-log Loaded template from templates/ocata/logging.conf
2019-11-13 00:13:03 INFO juju-log Rendering from template: /etc/keystone/logging.conf
2019-11-13 00:13:03 INFO juju-log Wrote template /etc/keystone/logging.conf.
2019-11-13 00:13:03 DEBUG juju-log Database is initialised
2019-11-13 00:13:04 DEBUG config-changed /usr/lib/python2.7/dist-packages/keystoneauth1/adapter.py:136: UserWarning: Using keystoneclient sessions has been deprecated. Please update your software to use keystoneauth1.
2019-11-13 00:13:04 DEBUG config-changed warnings.warn('Using keystoneclient sessions has been deprecated. '
2019-11-13 00:13:04 DEBUG juju-log Tenant 'admin' already exists.
2019-11-13 00:13:04 DEBUG juju-log Tenant 'services' already exists.
2019-11-13 00:13:04 DEBUG juju-log Creating service credentials for 'admin'
2019-11-13 00:13:04 DEBUG config-changed Traceback (most recent call last):
2019-11-13 00:13:04 DEBUG config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/manager.py", line 562, in <module>
2019-11-13 00:13:04 DEBUG config-changed result = {'result': _callable(*spec['args'], **spec['kwargs'])}
2019-11-13 00:13:04 DEBUG config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/manager.py", line 393, in user_exists
2019-11-13 00:13:04 DEBUG config-changed if manager.resolve_user_id(name, user_domain=domain):
2019-11-13 00:13:04 DEBUG config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/manager.py", line 331, in resolve_user_id
2019-11-13 00:13:04 DEBUG config-changed for user in self.api.users.list(domain=domain_id):
2019-11-13 00:13:04 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/debtcollector/renames.py", line 45, in wrapper
2019-11-13 00:13:04 DEBUG config-changed return f(*args, **kwargs)
2019-11-13 00:13:04 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/positional/__init__.py", line 101, in inner
2019-11-13 00:13:04 DEBUG config-changed return wrapped(*args, **kwargs)
2019-11-13 00:13:04 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/keystoneclient/v3/users.py", line 139, in list
2019-11-13 00:13:04 DEBUG config-changed **kwargs)
2019-11-13 00:13:04 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/keystoneclient/base.py", line 75, in func
2019-11-13 00:13:04 DEBUG config-changed return f(*args, **new_kwargs)
2019-11-13 00:13:04 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/keystoneclient/base.py", line 390, in list
2019-11-13 00:13:04 DEBUG config-changed self.collection_key)
2019-11-13 00:13:04 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/keystoneclient/base.py", line 125, in _list
2019-11-13 00:13:04 DEBUG config-changed resp, body = self.client.get(url, **kwargs)
2019-11-13 00:13:04 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/keystoneauth1/adapter.py", line 217, in get
2019-11-13 00:13:04 DEBUG config-changed return self.request(url, 'GET', **kwargs)
2019-11-13 00:13:04 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/keystoneauth1/adapter.py", line 374, in request
2019-11-13 00:13:04 DEBUG config-changed resp = super(LegacyJsonAdapter, self).request(*args, **kwargs)
2019-11-13 00:13:04 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/keystoneauth1/adapter.py", line 142, in request
2019-11-13 00:13:04 DEBUG config-changed return self.session.request(url, method, **kwargs)
2019-11-13 00:13:04 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/positional/__init__.py", line 101, in inner
2019-11-13 00:13:04 DEBUG config-changed return wrapped(*args, **kwargs)
2019-11-13 00:13:04 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/keystoneclient/session.py", line 445, in request
2019-11-13 00:13:04 DEBUG config-changed raise exceptions.from_response(resp, method, url)
2019-11-13 00:13:04 DEBUG config-changed Unauthorized: The request you have made requires authentication. (HTTP 401) (Request-ID: req-6320c658-ff0c-42e9-8273-c02029e8f4a2)
2019-11-13 00:13:04 ERROR juju-log The call within manager.py failed with the error: 'The request you have made requires authentication. (HTTP 401) (Request-ID: req-6320c658-ff0c-42e9-8273-c02029e8f4a2)'. The call was: path=['user_exists'], args=('admin',), kwargs={'domain': None}, api_version=None
2019-11-13 00:13:04 INFO juju-log Retrying '_ensure_initial_admin' 3 more times (delay=3)
2019-11-13 00:13:07 DEBUG juju-log Tenant 'admin' already exists.
2019-11-13 00:13:07 DEBUG juju-log Tenant 'services' already exists.
2019-11-13 00:13:08 DEBUG juju-log Creating service credentials for 'admin'
2019-11-13 00:13:08 DEBUG config-changed Traceback (most recent call last):
2019-11-13 00:13:08 DEBUG config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/manager.py", line 562, in <module>
2019-11-13 00:13:08 DEBUG config-changed result = {'result': _callable(*spec['args'], **spec['kwargs'])}
2019-11-13 00:13:08 DEBUG config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/manager.py", line 393, in user_exists
2019-11-13 00:13:08 DEBUG config-changed if manager.resolve_user_id(name, user_domain=domain):
2019-11-13 00:13:08 DEBUG config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/manager.py", line 331, in resolve_user_id
2019-11-13 00:13:08 DEBUG config-changed for user in self.api.users.list(domain=domain_id):
2019-11-13 00:13:08 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/debtcollector/renames.py", line 45, in wrapper
2019-11-13 00:13:08 DEBUG config-changed return f(*args, **kwargs)
2019-11-13 00:13:08 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/positional/__init__.py", line 101, in inner
2019-11-13 00:13:08 DEBUG config-changed return wrapped(*args, **kwargs)
2019-11-13 00:13:08 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/keystoneclient/v3/users.py", line 139, in list
2019-11-13 00:13:08 DEBUG config-changed **kwargs)
2019-11-13 00:13:08 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/keystoneclient/base.py", line 75, in func
2019-11-13 00:13:08 DEBUG config-changed return f(*args, **new_kwargs)
2019-11-13 00:13:08 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/keystoneclient/base.py", line 390, in list
2019-11-13 00:13:08 DEBUG config-changed self.collection_key)
2019-11-13 00:13:08 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/keystoneclient/base.py", line 125, in _list
2019-11-13 00:13:08 DEBUG config-changed resp, body = self.client.get(url, **kwargs)
2019-11-13 00:13:08 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/keystoneauth1/adapter.py", line 217, in get
2019-11-13 00:13:08 DEBUG config-changed return self.request(url, 'GET', **kwargs)
2019-11-13 00:13:08 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/keystoneauth1/adapter.py", line 374, in request
2019-11-13 00:13:08 DEBUG config-changed resp = super(LegacyJsonAdapter, self).request(*args, **kwargs)
2019-11-13 00:13:08 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/keystoneauth1/adapter.py", line 142, in request
2019-11-13 00:13:08 DEBUG config-changed return self.session.request(url, method, **kwargs)
2019-11-13 00:13:08 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/positional/__init__.py", line 101, in inner
2019-11-13 00:13:08 DEBUG config-changed return wrapped(*args, **kwargs)
2019-11-13 00:13:08 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/keystoneclient/session.py", line 445, in request
2019-11-13 00:13:08 DEBUG config-changed raise exceptions.from_response(resp, method, url)
2019-11-13 00:13:08 DEBUG config-changed Unauthorized: The request you have made requires authentication. (HTTP 401) (Request-ID: req-7d41850e-db55-45a4-ab4a-fe72df86b3dd)
2019-11-13 00:13:08 ERROR juju-log The call within manager.py failed with the error: 'The request you have made requires authentication. (HTTP 401) (Request-ID: req-7d41850e-db55-45a4-ab4a-fe72df86b3dd)'. The call was: path=['user_exists'], args=('admin',), kwargs={'domain': None}, api_version=None
2019-11-13 00:13:08 INFO juju-log Retrying '_ensure_initial_admin' 2 more times (delay=6)
2019-11-13 00:13:14 DEBUG juju-log Tenant 'admin' already exists.
2019-11-13 00:13:14 DEBUG juju-log Tenant 'services' already exists.
2019-11-13 00:13:14 DEBUG juju-log Creating service credentials for 'admin'
2019-11-13 00:13:14 DEBUG config-changed Traceback (most recent call last):
2019-11-13 00:13:14 DEBUG config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/manager.py", line 562, in <module>
2019-11-13 00:13:14 DEBUG config-changed result = {'result': _callable(*spec['args'], **spec['kwargs'])}
2019-11-13 00:13:14 DEBUG config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/manager.py", line 393, in user_exists
2019-11-13 00:13:14 DEBUG config-changed if manager.resolve_user_id(name, user_domain=domain):
2019-11-13 00:13:14 DEBUG config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/manager.py", line 331, in resolve_user_id
2019-11-13 00:13:14 DEBUG config-changed for user in self.api.users.list(domain=domain_id):
2019-11-13 00:13:14 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/debtcollector/renames.py", line 45, in wrapper
2019-11-13 00:13:14 DEBUG config-changed return f(*args, **kwargs)
2019-11-13 00:13:14 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/positional/__init__.py", line 101, in inner
2019-11-13 00:13:14 DEBUG config-changed return wrapped(*args, **kwargs)
2019-11-13 00:13:14 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/keystoneclient/v3/users.py", line 139, in list
2019-11-13 00:13:14 DEBUG config-changed **kwargs)
2019-11-13 00:13:14 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/keystoneclient/base.py", line 75, in func
2019-11-13 00:13:14 DEBUG config-changed return f(*args, **new_kwargs)
2019-11-13 00:13:14 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/keystoneclient/base.py", line 390, in list
2019-11-13 00:13:14 DEBUG config-changed self.collection_key)
2019-11-13 00:13:14 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/keystoneclient/base.py", line 125, in _list
2019-11-13 00:13:14 DEBUG config-changed resp, body = self.client.get(url, **kwargs)
2019-11-13 00:13:14 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/keystoneauth1/adapter.py", line 217, in get
2019-11-13 00:13:14 DEBUG config-changed return self.request(url, 'GET', **kwargs)
2019-11-13 00:13:14 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/keystoneauth1/adapter.py", line 374, in request
2019-11-13 00:13:14 DEBUG config-changed resp = super(LegacyJsonAdapter, self).request(*args, **kwargs)
2019-11-13 00:13:14 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/keystoneauth1/adapter.py", line 142, in request
2019-11-13 00:13:14 DEBUG config-changed return self.session.request(url, method, **kwargs)
2019-11-13 00:13:14 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/positional/__init__.py", line 101, in inner
2019-11-13 00:13:14 DEBUG config-changed return wrapped(*args, **kwargs)
2019-11-13 00:13:14 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/keystoneclient/session.py", line 445, in request
2019-11-13 00:13:14 DEBUG config-changed raise exceptions.from_response(resp, method, url)
2019-11-13 00:13:14 DEBUG config-changed Unauthorized: The request you have made requires authentication. (HTTP 401) (Request-ID: req-e22a9021-1880-4cbe-9cc1-6562a0c2de52)
2019-11-13 00:13:14 ERROR juju-log The call within manager.py failed with the error: 'The request you have made requires authentication. (HTTP 401) (Request-ID: req-e22a9021-1880-4cbe-9cc1-6562a0c2de52)'. The call was: path=['user_exists'], args=('admin',), kwargs={'domain': None}, api_version=None
2019-11-13 00:13:14 INFO juju-log Retrying '_ensure_initial_admin' 1 more times (delay=9)
2019-11-13 00:13:24 DEBUG juju-log Tenant 'admin' already exists.
2019-11-13 00:13:24 DEBUG juju-log Tenant 'services' already exists.
2019-11-13 00:13:24 DEBUG juju-log Creating service credentials for 'admin'
2019-11-13 00:13:24 DEBUG config-changed Traceback (most recent call last):
2019-11-13 00:13:24 DEBUG config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/manager.py", line 562, in <module>
2019-11-13 00:13:24 DEBUG config-changed result = {'result': _callable(*spec['args'], **spec['kwargs'])}
2019-11-13 00:13:24 DEBUG config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/manager.py", line 393, in user_exists
2019-11-13 00:13:24 DEBUG config-changed if manager.resolve_user_id(name, user_domain=domain):
2019-11-13 00:13:24 DEBUG config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/manager.py", line 331, in resolve_user_id
2019-11-13 00:13:24 DEBUG config-changed for user in self.api.users.list(domain=domain_id):
2019-11-13 00:13:24 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/debtcollector/renames.py", line 45, in wrapper
2019-11-13 00:13:24 DEBUG config-changed return f(*args, **kwargs)
2019-11-13 00:13:24 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/positional/__init__.py", line 101, in inner
2019-11-13 00:13:24 DEBUG config-changed return wrapped(*args, **kwargs)
2019-11-13 00:13:24 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/keystoneclient/v3/users.py", line 139, in list
2019-11-13 00:13:24 DEBUG config-changed **kwargs)
2019-11-13 00:13:24 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/keystoneclient/base.py", line 75, in func
2019-11-13 00:13:24 DEBUG config-changed return f(*args, **new_kwargs)
2019-11-13 00:13:24 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/keystoneclient/base.py", line 390, in list
2019-11-13 00:13:24 DEBUG config-changed self.collection_key)
2019-11-13 00:13:24 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/keystoneclient/base.py", line 125, in _list
2019-11-13 00:13:24 DEBUG config-changed resp, body = self.client.get(url, **kwargs)
2019-11-13 00:13:24 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/keystoneauth1/adapter.py", line 217, in get
2019-11-13 00:13:24 DEBUG config-changed return self.request(url, 'GET', **kwargs)
2019-11-13 00:13:24 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/keystoneauth1/adapter.py", line 374, in request
2019-11-13 00:13:24 DEBUG config-changed resp = super(LegacyJsonAdapter, self).request(*args, **kwargs)
2019-11-13 00:13:24 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/keystoneauth1/adapter.py", line 142, in request
2019-11-13 00:13:24 DEBUG config-changed return self.session.request(url, method, **kwargs)
2019-11-13 00:13:24 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/positional/__init__.py", line 101, in inner
2019-11-13 00:13:24 DEBUG config-changed return wrapped(*args, **kwargs)
2019-11-13 00:13:24 DEBUG config-changed File "/usr/lib/python2.7/dist-packages/keystoneclient/session.py", line 445, in request
2019-11-13 00:13:24 DEBUG config-changed raise exceptions.from_response(resp, method, url)
2019-11-13 00:13:24 DEBUG config-changed Unauthorized: The request you have made requires authentication. (HTTP 401) (Request-ID: req-4f2193e5-af6c-49a0-9343-e42cd3141408)
2019-11-13 00:13:24 ERROR juju-log The call within manager.py failed with the error: 'The request you have made requires authentication. (HTTP 401) (Request-ID: req-4f2193e5-af6c-49a0-9343-e42cd3141408)'. The call was: path=['user_exists'], args=('admin',), kwargs={'domain': None}, api_version=None
2019-11-13 00:13:24 DEBUG config-changed Traceback (most recent call last):
2019-11-13 00:13:24 DEBUG config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/config-changed", line 892, in <module>
2019-11-13 00:13:24 DEBUG config-changed main()
2019-11-13 00:13:24 DEBUG config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/config-changed", line 885, in main
2019-11-13 00:13:24 DEBUG config-changed hooks.execute(sys.argv)
2019-11-13 00:13:24 DEBUG config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/charmhelpers/core/hookenv.py", line 914, in execute
2019-11-13 00:13:24 DEBUG config-changed self._hooks[hook_name]()
2019-11-13 00:13:24 DEBUG config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/charmhelpers/contrib/openstack/utils.py", line 1573, in wrapped_f
2019-11-13 00:13:24 DEBUG config-changed stopstart, restart_functions)
2019-11-13 00:13:24 DEBUG config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/charmhelpers/core/host.py", line 741, in restart_on_change_helper
2019-11-13 00:13:24 DEBUG config-changed r = lambda_f()
2019-11-13 00:13:24 DEBUG config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/charmhelpers/contrib/openstack/utils.py", line 1572, in <lambda>
2019-11-13 00:13:24 DEBUG config-changed (lambda: f(*args, **kwargs)), __restart_map_cache['cache'],
2019-11-13 00:13:24 DEBUG config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/charmhelpers/contrib/hardening/harden.py", line 93, in _harden_inner2
2019-11-13 00:13:24 DEBUG config-changed return f(*args, **kwargs)
2019-11-13 00:13:24 DEBUG config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/config-changed", line 237, in config_changed
2019-11-13 00:13:24 DEBUG config-changed config_changed_postupgrade()
2019-11-13 00:13:24 DEBUG config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/charmhelpers/contrib/openstack/utils.py", line 1573, in wrapped_f
2019-11-13 00:13:24 DEBUG config-changed stopstart, restart_functions)
2019-11-13 00:13:24 DEBUG config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/charmhelpers/core/host.py", line 741, in restart_on_change_helper
2019-11-13 00:13:24 DEBUG config-changed r = lambda_f()
2019-11-13 00:13:24 DEBUG config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/charmhelpers/contrib/openstack/utils.py", line 1572, in <lambda>
2019-11-13 00:13:24 DEBUG config-changed (lambda: f(*args, **kwargs)), __restart_map_cache['cache'],
2019-11-13 00:13:24 DEBUG config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/charmhelpers/contrib/hardening/harden.py", line 93, in _harden_inner2
2019-11-13 00:13:24 DEBUG config-changed return f(*args, **kwargs)
2019-11-13 00:13:24 DEBUG config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/config-changed", line 283, in config_changed_postupgrade
2019-11-13 00:13:24 DEBUG config-changed ensure_initial_admin(config)
2019-11-13 00:13:24 DEBUG config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/keystone_utils.py", line 1424, in ensure_initial_admin
2019-11-13 00:13:24 DEBUG config-changed return _ensure_initial_admin(config)
2019-11-13 00:13:24 DEBUG config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/charmhelpers/core/decorators.py", line 40, in _retry_on_exception_inner_2
2019-11-13 00:13:24 DEBUG config-changed return f(*args, **kwargs)
2019-11-13 00:13:24 DEBUG config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/keystone_utils.py", line 1411, in _ensure_initial_admin
2019-11-13 00:13:24 DEBUG config-changed new_roles=[config('admin-role')])
2019-11-13 00:13:24 DEBUG config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/keystone_utils.py", line 1527, in create_user_credentials
2019-11-13 00:13:24 DEBUG config-changed if user_exists(user, domain=domain):
2019-11-13 00:13:24 DEBUG config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/keystone_utils.py", line 1010, in user_exists
2019-11-13 00:13:24 DEBUG config-changed return manager.user_exists(name, domain=domain)
2019-11-13 00:13:24 DEBUG config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/keystone_utils.py", line 1063, in __call__
2019-11-13 00:13:24 DEBUG config-changed return _proxy_manager_call(self._path, self.api_version, args, kwargs)
2019-11-13 00:13:24 DEBUG config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/charmhelpers/core/decorators.py", line 40, in _retry_on_exception_inner_2
2019-11-13 00:13:24 DEBUG config-changed return f(*args, **kwargs)
2019-11-13 00:13:24 DEBUG config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/keystone_utils.py", line 1107, in _proxy_manager_call
2019-11-13 00:13:24 DEBUG config-changed raise e
2019-11-13 00:13:24 DEBUG config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/keystone_utils.py", line 1101, in _proxy_manager_call
2019-11-13 00:13:24 DEBUG config-changed raise RuntimeError(s)
2019-11-13 00:13:24 DEBUG config-changed RuntimeError: The call within manager.py failed with the error: 'The request you have made requires authentication. (HTTP 401) (Request-ID: req-4f2193e5-af6c-49a0-9343-e42cd3141408)'. The call was: path=['user_exists'], args=('admin',), kwargs={'domain': None}, api_version=None
2019-11-13 00:13:24 DEBUG config-changed /var/lib/juju/agents/unit-keystone-0/charm/hooks/manager.py: something went wrong: The request you have made requires authentication. (HTTP 401) (Request-ID: req-6320c658-ff0c-42e9-8273-c02029e8f4a2)
2019-11-13 00:13:24 DEBUG config-changed /var/lib/juju/agents/unit-keystone-0/charm/hooks/manager.py: something went wrong: The request you have made requires authentication. (HTTP 401) (Request-ID: req-7d41850e-db55-45a4-ab4a-fe72df86b3dd)
2019-11-13 00:13:24 DEBUG config-changed /var/lib/juju/agents/unit-keystone-0/charm/hooks/manager.py: something went wrong: The request you have made requires authentication. (HTTP 401) (Request-ID: req-e22a9021-1880-4cbe-9cc1-6562a0c2de52)
2019-11-13 00:13:24 DEBUG config-changed /var/lib/juju/agents/unit-keystone-0/charm/hooks/manager.py: something went wrong: The request you have made requires authentication. (HTTP 401) (Request-ID: req-4f2193e5-af6c-49a0-9343-e42cd3141408)
2019-11-13 00:13:24 DEBUG config-changed Traceback (most recent call last):
2019-11-13 00:13:24 DEBUG config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/manager.py", line 591, in <module>
2019-11-13 00:13:24 DEBUG config-changed uds_client.send(result_json)
2019-11-13 00:13:24 DEBUG config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/uds_comms.py", line 227, in send
2019-11-13 00:13:24 DEBUG config-changed raise UDSException(str(e))
2019-11-13 00:13:24 DEBUG config-changed uds_comms.UDSException: [Errno 32] Broken pipe
2019-11-13 00:13:24 ERROR juju.worker.uniter.operation runhook.go:132 hook "config-changed" failed: exit status 1

Frode Nordahl (fnordahl)
description: updated
Revision history for this message
Alex Kavanagh (ajkavanagh) wrote :

These happen when the underlying keystone service has restarted but the manager.py hasn't noticed/been restarted itself. I think there probably needs to be some logic in the manager.py to read the PID of the local keystone service when the manager.py first connects, and then if this error occurs during a an attempt to use the keystone API and the PID has changed, to re-connect to the new service, using the existing credentials. Thoughts?

Changed in charm-keystone:
status: New → Triaged
importance: Undecided → High
Revision history for this message
João Pedro Seara (jpseara) wrote :

Just adding that a simple unit reboot is enough to clear up this error, as it will make the services restart in an orderly fashion.

Thanks,
JP

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

Other bug subscribers

Remote bug watches

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