| 2016-06-13 21:39:51 |
Matt Fischer |
bug |
|
|
added bug |
| 2016-06-13 21:40:18 |
Matt Fischer |
summary |
liberty to mitaka upgrade (stable) has broken caching |
cached tokens break liberty to Mitaka upgrade |
|
| 2016-06-13 21:40:44 |
Lance Bragstad |
summary |
cached tokens break liberty to Mitaka upgrade |
cached tokens break Liberty to Mitaka upgrade |
|
| 2016-06-13 21:40:54 |
Matt Fischer |
description |
Sequence of events.
- Running cluster with Liberty from about 6 weeks ago, so close to stable.
- Upgrade Keystone to Mitaka (automated)
- Tokens fail to issue for about 5 minutes, after this time, all the cached tokens are gone
- Everything works now.
Annotated logs:
Token call works.
db_sync is running here, but code is still Liberty, DB now Mitaka:
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-04dcb954-ae4e-41fa-b235-aa0b05ac8b44)
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-d27eee3a-723a-412e-a7b0-37ffd511c221)
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-265b6261-bcac-44f1-a806-8696b455ff5a)
Puppet bounces Keystone, the restarted code is Mitaka:
Discovering versions from the identity service failed when creating the password plugin. Attempting to determine version from URL.
Tokens fail to generate here due to the caching format changing. This will continue for about 5 minutes or so, I suspect it depends on whats in the cache and timeouts.
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-8b835f67-4a21-42d3-9030-b4dbfd820238)
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-b92bcd56-87da-4977-b82e-c717c7120f4f)
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-a787163f-20c1-493f-9b34-82708dea4191)
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-e2ab7bf1-3483-438e-8425-06e5cfbf2e37)
Keystone log is full of this:
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi Traceback (most recent call last):
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/common/wsgi.py", line 249, in __call__
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi result = method(context, **params)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/oslo_log/versionutils.py", line 165, in wrapped
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi return func_or_cls(*args, **kwargs)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/token/controllers.py", line 100, in authenticate
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi context, auth)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/token/controllers.py", line 310, in _authenticate_local
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi user_id, tenant_id)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/token/controllers.py", line 391, in _get_project_roles_and_ref
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi user_id, tenant_id)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/common/manager.py", line 124, in wrapped
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi __ret_val = __f(*args, **kwargs)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/cache/region.py", line 1053, in decorate
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi should_cache_fn)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/cache/region.py", line 657, in get_or_create
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi async_creator) as value:
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/core/dogpile.py", line 158, in __enter__
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi return self._enter()
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/core/dogpile.py", line 98, in _enter
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi generated = self._enter_create(createdtime)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/core/dogpile.py", line 149, in _enter_create
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi created = self.creator()
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/cache/region.py", line 625, in gen_value
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi created_value = creator()
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/cache/region.py", line 1049, in creator
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi return fn(*arg, **kw)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/assignment/core.py", line 149, in get_roles_for_user_and_project
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi user_id=user_id, project_id=tenant_id, effective=True)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/common/manager.py", line 124, in wrapped
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi __ret_val = __f(*args, **kwargs)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/assignment/core.py", line 977, in list_role_assignments
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi strip_domain_roles)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/assignment/core.py", line 886, in _list_effective_role_assignments
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi refs = self._strip_domain_roles(refs)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/assignment/core.py", line 721, in _strip_domain_roles
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi if _role_is_global(ref['role_id']):
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/assignment/core.py", line 717, in _role_is_global
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi return (ref['domain_id'] is None)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi KeyError: 'domain_id'
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi
Work-around: run flush_all in memcache (telnet localhost 11211) every few seconds during the upgrade |
Sequence of events.
- Running cluster with Liberty from about 6 weeks ago, so close to stable.
- Upgrade Keystone to Mitaka (automated)
- Tokens fail to issue for about 5 minutes, after this time, all the cached tokens are gone
- Everything works after that. See also Work-around at bottom.
Annotated logs:
Token call works.
db_sync is running here, but code is still Liberty, DB now Mitaka:
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-04dcb954-ae4e-41fa-b235-aa0b05ac8b44)
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-d27eee3a-723a-412e-a7b0-37ffd511c221)
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-265b6261-bcac-44f1-a806-8696b455ff5a)
Puppet bounces Keystone, the restarted code is Mitaka:
Discovering versions from the identity service failed when creating the password plugin. Attempting to determine version from URL.
Tokens fail to generate here due to the caching format changing. This will continue for about 5 minutes or so, I suspect it depends on whats in the cache and timeouts.
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-8b835f67-4a21-42d3-9030-b4dbfd820238)
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-b92bcd56-87da-4977-b82e-c717c7120f4f)
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-a787163f-20c1-493f-9b34-82708dea4191)
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-e2ab7bf1-3483-438e-8425-06e5cfbf2e37)
Keystone log is full of this:
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi Traceback (most recent call last):
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/common/wsgi.py", line 249, in __call__
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi result = method(context, **params)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/oslo_log/versionutils.py", line 165, in wrapped
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi return func_or_cls(*args, **kwargs)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/token/controllers.py", line 100, in authenticate
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi context, auth)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/token/controllers.py", line 310, in _authenticate_local
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi user_id, tenant_id)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/token/controllers.py", line 391, in _get_project_roles_and_ref
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi user_id, tenant_id)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/common/manager.py", line 124, in wrapped
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi __ret_val = __f(*args, **kwargs)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/cache/region.py", line 1053, in decorate
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi should_cache_fn)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/cache/region.py", line 657, in get_or_create
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi async_creator) as value:
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/core/dogpile.py", line 158, in __enter__
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi return self._enter()
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/core/dogpile.py", line 98, in _enter
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi generated = self._enter_create(createdtime)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/core/dogpile.py", line 149, in _enter_create
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi created = self.creator()
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/cache/region.py", line 625, in gen_value
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi created_value = creator()
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/cache/region.py", line 1049, in creator
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi return fn(*arg, **kw)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/assignment/core.py", line 149, in get_roles_for_user_and_project
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi user_id=user_id, project_id=tenant_id, effective=True)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/common/manager.py", line 124, in wrapped
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi __ret_val = __f(*args, **kwargs)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/assignment/core.py", line 977, in list_role_assignments
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi strip_domain_roles)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/assignment/core.py", line 886, in _list_effective_role_assignments
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi refs = self._strip_domain_roles(refs)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/assignment/core.py", line 721, in _strip_domain_roles
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi if _role_is_global(ref['role_id']):
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/assignment/core.py", line 717, in _role_is_global
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi return (ref['domain_id'] is None)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi KeyError: 'domain_id'
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi
Work-around: run flush_all in memcache (telnet localhost 11211) every few seconds during the upgrade |
|
| 2016-06-13 21:41:02 |
Matt Fischer |
description |
Sequence of events.
- Running cluster with Liberty from about 6 weeks ago, so close to stable.
- Upgrade Keystone to Mitaka (automated)
- Tokens fail to issue for about 5 minutes, after this time, all the cached tokens are gone
- Everything works after that. See also Work-around at bottom.
Annotated logs:
Token call works.
db_sync is running here, but code is still Liberty, DB now Mitaka:
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-04dcb954-ae4e-41fa-b235-aa0b05ac8b44)
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-d27eee3a-723a-412e-a7b0-37ffd511c221)
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-265b6261-bcac-44f1-a806-8696b455ff5a)
Puppet bounces Keystone, the restarted code is Mitaka:
Discovering versions from the identity service failed when creating the password plugin. Attempting to determine version from URL.
Tokens fail to generate here due to the caching format changing. This will continue for about 5 minutes or so, I suspect it depends on whats in the cache and timeouts.
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-8b835f67-4a21-42d3-9030-b4dbfd820238)
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-b92bcd56-87da-4977-b82e-c717c7120f4f)
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-a787163f-20c1-493f-9b34-82708dea4191)
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-e2ab7bf1-3483-438e-8425-06e5cfbf2e37)
Keystone log is full of this:
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi Traceback (most recent call last):
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/common/wsgi.py", line 249, in __call__
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi result = method(context, **params)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/oslo_log/versionutils.py", line 165, in wrapped
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi return func_or_cls(*args, **kwargs)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/token/controllers.py", line 100, in authenticate
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi context, auth)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/token/controllers.py", line 310, in _authenticate_local
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi user_id, tenant_id)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/token/controllers.py", line 391, in _get_project_roles_and_ref
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi user_id, tenant_id)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/common/manager.py", line 124, in wrapped
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi __ret_val = __f(*args, **kwargs)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/cache/region.py", line 1053, in decorate
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi should_cache_fn)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/cache/region.py", line 657, in get_or_create
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi async_creator) as value:
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/core/dogpile.py", line 158, in __enter__
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi return self._enter()
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/core/dogpile.py", line 98, in _enter
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi generated = self._enter_create(createdtime)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/core/dogpile.py", line 149, in _enter_create
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi created = self.creator()
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/cache/region.py", line 625, in gen_value
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi created_value = creator()
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/cache/region.py", line 1049, in creator
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi return fn(*arg, **kw)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/assignment/core.py", line 149, in get_roles_for_user_and_project
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi user_id=user_id, project_id=tenant_id, effective=True)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/common/manager.py", line 124, in wrapped
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi __ret_val = __f(*args, **kwargs)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/assignment/core.py", line 977, in list_role_assignments
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi strip_domain_roles)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/assignment/core.py", line 886, in _list_effective_role_assignments
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi refs = self._strip_domain_roles(refs)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/assignment/core.py", line 721, in _strip_domain_roles
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi if _role_is_global(ref['role_id']):
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/assignment/core.py", line 717, in _role_is_global
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi return (ref['domain_id'] is None)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi KeyError: 'domain_id'
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi
Work-around: run flush_all in memcache (telnet localhost 11211) every few seconds during the upgrade |
Sequence of events.
- Running cluster with Liberty from about 6 weeks ago, so close to stable.
- Upgrade Keystone to Mitaka (automated)
- Tokens fail to issue for about 5 minutes, after this time, all the cached tokens are gone
- Everything works after that. See also Work-around at bottom.
Annotated logs:
Token call works to this point.
db_sync is running here, but code is still Liberty, DB now Mitaka:
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-04dcb954-ae4e-41fa-b235-aa0b05ac8b44)
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-d27eee3a-723a-412e-a7b0-37ffd511c221)
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-265b6261-bcac-44f1-a806-8696b455ff5a)
Puppet bounces Keystone, the restarted code is Mitaka:
Discovering versions from the identity service failed when creating the password plugin. Attempting to determine version from URL.
Tokens fail to generate here due to the caching format changing. This will continue for about 5 minutes or so, I suspect it depends on whats in the cache and timeouts.
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-8b835f67-4a21-42d3-9030-b4dbfd820238)
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-b92bcd56-87da-4977-b82e-c717c7120f4f)
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-a787163f-20c1-493f-9b34-82708dea4191)
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-e2ab7bf1-3483-438e-8425-06e5cfbf2e37)
Keystone log is full of this:
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi Traceback (most recent call last):
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/common/wsgi.py", line 249, in __call__
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi result = method(context, **params)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/oslo_log/versionutils.py", line 165, in wrapped
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi return func_or_cls(*args, **kwargs)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/token/controllers.py", line 100, in authenticate
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi context, auth)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/token/controllers.py", line 310, in _authenticate_local
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi user_id, tenant_id)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/token/controllers.py", line 391, in _get_project_roles_and_ref
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi user_id, tenant_id)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/common/manager.py", line 124, in wrapped
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi __ret_val = __f(*args, **kwargs)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/cache/region.py", line 1053, in decorate
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi should_cache_fn)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/cache/region.py", line 657, in get_or_create
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi async_creator) as value:
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/core/dogpile.py", line 158, in __enter__
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi return self._enter()
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/core/dogpile.py", line 98, in _enter
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi generated = self._enter_create(createdtime)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/core/dogpile.py", line 149, in _enter_create
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi created = self.creator()
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/cache/region.py", line 625, in gen_value
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi created_value = creator()
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/cache/region.py", line 1049, in creator
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi return fn(*arg, **kw)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/assignment/core.py", line 149, in get_roles_for_user_and_project
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi user_id=user_id, project_id=tenant_id, effective=True)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/common/manager.py", line 124, in wrapped
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi __ret_val = __f(*args, **kwargs)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/assignment/core.py", line 977, in list_role_assignments
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi strip_domain_roles)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/assignment/core.py", line 886, in _list_effective_role_assignments
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi refs = self._strip_domain_roles(refs)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/assignment/core.py", line 721, in _strip_domain_roles
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi if _role_is_global(ref['role_id']):
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/assignment/core.py", line 717, in _role_is_global
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi return (ref['domain_id'] is None)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi KeyError: 'domain_id'
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi
Work-around: run flush_all in memcache (telnet localhost 11211) every few seconds during the upgrade |
|
| 2016-06-13 21:42:28 |
Lance Bragstad |
tags |
|
fernet |
|
| 2016-06-13 21:42:39 |
Matt Fischer |
description |
Sequence of events.
- Running cluster with Liberty from about 6 weeks ago, so close to stable.
- Upgrade Keystone to Mitaka (automated)
- Tokens fail to issue for about 5 minutes, after this time, all the cached tokens are gone
- Everything works after that. See also Work-around at bottom.
Annotated logs:
Token call works to this point.
db_sync is running here, but code is still Liberty, DB now Mitaka:
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-04dcb954-ae4e-41fa-b235-aa0b05ac8b44)
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-d27eee3a-723a-412e-a7b0-37ffd511c221)
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-265b6261-bcac-44f1-a806-8696b455ff5a)
Puppet bounces Keystone, the restarted code is Mitaka:
Discovering versions from the identity service failed when creating the password plugin. Attempting to determine version from URL.
Tokens fail to generate here due to the caching format changing. This will continue for about 5 minutes or so, I suspect it depends on whats in the cache and timeouts.
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-8b835f67-4a21-42d3-9030-b4dbfd820238)
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-b92bcd56-87da-4977-b82e-c717c7120f4f)
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-a787163f-20c1-493f-9b34-82708dea4191)
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-e2ab7bf1-3483-438e-8425-06e5cfbf2e37)
Keystone log is full of this:
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi Traceback (most recent call last):
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/common/wsgi.py", line 249, in __call__
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi result = method(context, **params)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/oslo_log/versionutils.py", line 165, in wrapped
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi return func_or_cls(*args, **kwargs)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/token/controllers.py", line 100, in authenticate
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi context, auth)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/token/controllers.py", line 310, in _authenticate_local
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi user_id, tenant_id)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/token/controllers.py", line 391, in _get_project_roles_and_ref
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi user_id, tenant_id)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/common/manager.py", line 124, in wrapped
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi __ret_val = __f(*args, **kwargs)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/cache/region.py", line 1053, in decorate
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi should_cache_fn)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/cache/region.py", line 657, in get_or_create
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi async_creator) as value:
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/core/dogpile.py", line 158, in __enter__
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi return self._enter()
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/core/dogpile.py", line 98, in _enter
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi generated = self._enter_create(createdtime)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/core/dogpile.py", line 149, in _enter_create
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi created = self.creator()
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/cache/region.py", line 625, in gen_value
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi created_value = creator()
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/cache/region.py", line 1049, in creator
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi return fn(*arg, **kw)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/assignment/core.py", line 149, in get_roles_for_user_and_project
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi user_id=user_id, project_id=tenant_id, effective=True)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/common/manager.py", line 124, in wrapped
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi __ret_val = __f(*args, **kwargs)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/assignment/core.py", line 977, in list_role_assignments
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi strip_domain_roles)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/assignment/core.py", line 886, in _list_effective_role_assignments
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi refs = self._strip_domain_roles(refs)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/assignment/core.py", line 721, in _strip_domain_roles
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi if _role_is_global(ref['role_id']):
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/assignment/core.py", line 717, in _role_is_global
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi return (ref['domain_id'] is None)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi KeyError: 'domain_id'
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi
Work-around: run flush_all in memcache (telnet localhost 11211) every few seconds during the upgrade |
Sequence of events.
- Fernet tokens (didnt test with UUID)
- Running cluster with Liberty from about 6 weeks ago, so close to stable.
- Upgrade Keystone to Mitaka (automated)
- Tokens fail to issue for about 5 minutes, after this time, all the cached tokens are gone
- Everything works after that. See also Work-around at bottom.
Annotated logs:
Token call works to this point.
db_sync is running here, but code is still Liberty, DB now Mitaka:
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-04dcb954-ae4e-41fa-b235-aa0b05ac8b44)
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-d27eee3a-723a-412e-a7b0-37ffd511c221)
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-265b6261-bcac-44f1-a806-8696b455ff5a)
Puppet bounces Keystone, the restarted code is Mitaka:
Discovering versions from the identity service failed when creating the password plugin. Attempting to determine version from URL.
Tokens fail to generate here due to the caching format changing. This will continue for about 5 minutes or so, I suspect it depends on whats in the cache and timeouts.
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-8b835f67-4a21-42d3-9030-b4dbfd820238)
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-b92bcd56-87da-4977-b82e-c717c7120f4f)
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-a787163f-20c1-493f-9b34-82708dea4191)
An unexpected error prevented the server from fulfilling your request. (HTTP 500) (Request-ID: req-e2ab7bf1-3483-438e-8425-06e5cfbf2e37)
Keystone log is full of this:
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi Traceback (most recent call last):
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/common/wsgi.py", line 249, in __call__
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi result = method(context, **params)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/oslo_log/versionutils.py", line 165, in wrapped
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi return func_or_cls(*args, **kwargs)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/token/controllers.py", line 100, in authenticate
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi context, auth)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/token/controllers.py", line 310, in _authenticate_local
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi user_id, tenant_id)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/token/controllers.py", line 391, in _get_project_roles_and_ref
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi user_id, tenant_id)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/common/manager.py", line 124, in wrapped
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi __ret_val = __f(*args, **kwargs)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/cache/region.py", line 1053, in decorate
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi should_cache_fn)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/cache/region.py", line 657, in get_or_create
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi async_creator) as value:
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/core/dogpile.py", line 158, in __enter__
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi return self._enter()
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/core/dogpile.py", line 98, in _enter
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi generated = self._enter_create(createdtime)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/core/dogpile.py", line 149, in _enter_create
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi created = self.creator()
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/cache/region.py", line 625, in gen_value
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi created_value = creator()
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/dogpile/cache/region.py", line 1049, in creator
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi return fn(*arg, **kw)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/assignment/core.py", line 149, in get_roles_for_user_and_project
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi user_id=user_id, project_id=tenant_id, effective=True)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/common/manager.py", line 124, in wrapped
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi __ret_val = __f(*args, **kwargs)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/assignment/core.py", line 977, in list_role_assignments
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi strip_domain_roles)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/assignment/core.py", line 886, in _list_effective_role_assignments
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi refs = self._strip_domain_roles(refs)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/assignment/core.py", line 721, in _strip_domain_roles
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi if _role_is_global(ref['role_id']):
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi File "/venv/local/lib/python2.7/site-packages/keystone/assignment/core.py", line 717, in _role_is_global
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi return (ref['domain_id'] is None)
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi KeyError: 'domain_id'
2016-06-13 21:37:58.947 35 ERROR keystone.common.wsgi
Work-around: run flush_all in memcache (telnet localhost 11211) every few seconds during the upgrade |
|
| 2016-06-13 21:46:19 |
Dolph Mathews |
keystone: importance |
Undecided |
High |
|
| 2016-06-13 21:46:45 |
Dolph Mathews |
tags |
fernet |
fernet mitaka-backport-potential |
|
| 2016-06-13 21:46:58 |
Dolph Mathews |
keystone: status |
New |
Triaged |
|
| 2016-07-26 14:37:32 |
Steve Martinelli |
keystone: milestone |
|
newton-3 |
|
| 2016-07-26 20:10:32 |
OpenStack Infra |
keystone: status |
Triaged |
In Progress |
|
| 2016-07-26 20:10:32 |
OpenStack Infra |
keystone: assignee |
|
Colleen Murphy (krinkle) |
|
| 2016-08-16 17:02:42 |
Steve Martinelli |
nominated for series |
|
keystone/newton |
|
| 2016-08-16 17:02:42 |
Steve Martinelli |
bug task added |
|
keystone/newton |
|
| 2016-08-16 17:02:42 |
Steve Martinelli |
nominated for series |
|
keystone/mitaka |
|
| 2016-08-16 17:02:42 |
Steve Martinelli |
bug task added |
|
keystone/mitaka |
|
| 2016-08-16 17:02:58 |
Steve Martinelli |
keystone/mitaka: assignee |
|
Colleen Murphy (krinkle) |
|
| 2016-08-16 17:03:00 |
Steve Martinelli |
keystone/mitaka: importance |
Undecided |
High |
|
| 2016-08-16 17:03:05 |
Steve Martinelli |
keystone/mitaka: status |
New |
In Progress |
|
| 2016-08-18 18:55:16 |
OpenStack Infra |
keystone: status |
In Progress |
Fix Released |
|
| 2016-08-18 19:03:29 |
OpenStack Infra |
keystone/mitaka: assignee |
Colleen Murphy (krinkle) |
Steve Martinelli (stevemar) |
|
| 2016-08-18 19:03:53 |
Steve Martinelli |
keystone/mitaka: assignee |
Steve Martinelli (stevemar) |
Colleen Murphy (krinkle) |
|
| 2016-08-20 00:49:01 |
OpenStack Infra |
keystone/mitaka: status |
In Progress |
Fix Committed |
|
| 2016-10-11 15:25:30 |
Steve Martinelli |
keystone/mitaka: status |
Fix Committed |
Fix Released |
|
