Public bug reported:

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

** Affects: keystone
     Importance: Undecided
         Status: New


** Tags: fernet

** Summary changed:

- liberty to mitaka upgrade (stable) has broken caching
+ cached tokens break liberty to Mitaka upgrade

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to OpenStack Identity (keystone).
https://bugs.launchpad.net/bugs/1592169

Title:
  cached tokens break Liberty to Mitaka upgrade

Status in OpenStack Identity (keystone):
  New

Bug description:
  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

To manage notifications about this bug go to:
https://bugs.launchpad.net/keystone/+bug/1592169/+subscriptions

-- 
Mailing list: https://launchpad.net/~yahoo-eng-team
Post to     : yahoo-eng-team@lists.launchpad.net
Unsubscribe : https://launchpad.net/~yahoo-eng-team
More help   : https://help.launchpad.net/ListHelp

Reply via email to