Hi all,
I am running into an issue with our OpenStack Kolla-Ansible deployment (Release 2024.1, Keystone 25.0.1) where Keystone logs are being flooded (18k per day) with TokenNotFound: Failed to validate token stack traces[1].
From the traceback, it seems these requests are attempting to validate tokens that have already been revoked. The majority of these come from Nova and Cinder, but the request_id from Keystone does not appear in their logs.
Instead of finding the matching requests in Nova or Cinder logs, I only see InvalidToken: Token authorization failed messages[2].
Most of the time, the platform does not show any user-visible issues in these areas, although occasional failures can be observed.
Could this indicate an issue with token caching or revocation list synchronization between services? Memcached looks fine.
Any ideas what could be triggering this behavior are welcome. If you need more Information please let me know.
Thanks in advance.
Best regards,
Marc
[1]
ERROR keystone.server.flask.application [None req-326cbeaa-a363-4a82-b45b-498d6f2ad338 b30e2d031b6a4851b69f9b1791716919 d977f9d63d3043288bed6e549e507c9a - - default default] Failed to validate token: keystone.exception.TokenNotFound: Failed to validate token
ERROR keystone.server.flask.application Traceback (most recent call last):
ERROR keystone.server.flask.application File "/var/lib/kolla/venv/lib/python3.10/site-packages/flask/app.py", line 870, in full_dispatch_request
ERROR keystone.server.flask.application rv = self.dispatch_request()
ERROR keystone.server.flask.application File "/var/lib/kolla/venv/lib/python3.10/site-packages/flask/app.py", line 855, in dispatch_request
ERROR keystone.server.flask.application return self.ensure_sync(self.view_functions[rule.endpoint])(**view_args) # type: ignore[no-any-return]
ERROR keystone.server.flask.application File "/var/lib/kolla/venv/lib/python3.10/site-packages/flask_restful/__init__.py", line 489, in wrapper
ERROR keystone.server.flask.application resp = resource(*args, **kwargs)
ERROR keystone.server.flask.application File "/var/lib/kolla/venv/lib/python3.10/site-packages/flask/views.py", line 110, in view
ERROR keystone.server.flask.application return current_app.ensure_sync(self.dispatch_request)(**kwargs) # type: ignore[no-any-return]
ERROR keystone.server.flask.application File "/var/lib/kolla/venv/lib/python3.10/site-packages/flask_restful/__init__.py", line 604, in dispatch_request
ERROR keystone.server.flask.application resp = meth(*args, **kwargs)
ERROR keystone.server.flask.application File "/var/lib/kolla/venv/lib/python3.10/site-packages/keystone/api/auth.py", line 285, in get
ERROR keystone.server.flask.application ENFORCER.enforce_call(action='identity:validate_token')
ERROR keystone.server.flask.application File "/var/lib/kolla/venv/lib/python3.10/site-packages/keystone/common/rbac_enforcer/enforcer.py", line 422, in enforce_call
ERROR keystone.server.flask.application subj_token_target_data = cls._extract_subject_token_target_data()
ERROR keystone.server.flask.application File "/var/lib/kolla/venv/lib/python3.10/site-packages/keystone/common/rbac_enforcer/enforcer.py", line 261, in _extract_subject_token_target_data
ERROR keystone.server.flask.application token = PROVIDER_APIS.token_provider_api.validate_token(
ERROR keystone.server.flask.application File "/var/lib/kolla/venv/lib/python3.10/site-packages/keystone/common/manager.py", line 110, in wrapped
ERROR keystone.server.flask.application __ret_val = __f(*args, **kwargs)
ERROR keystone.server.flask.application File "/var/lib/kolla/venv/lib/python3.10/site-packages/keystone/token/provider.py", line 147, in validate_token
ERROR keystone.server.flask.application self._is_valid_token(token, window_seconds=window_seconds)
ERROR keystone.server.flask.application File "/var/lib/kolla/venv/lib/python3.10/site-packages/keystone/token/provider.py", line 201, in _is_valid_token
ERROR keystone.server.flask.application self.check_revocation(token)
ERROR keystone.server.flask.application File "/var/lib/kolla/venv/lib/python3.10/site-packages/keystone/common/manager.py", line 110, in wrapped
ERROR keystone.server.flask.application __ret_val = __f(*args, **kwargs)
ERROR keystone.server.flask.application File "/var/lib/kolla/venv/lib/python3.10/site-packages/keystone/token/provider.py", line 138, in check_revocation
ERROR keystone.server.flask.application return self.check_revocation_v3(token_values)
ERROR keystone.server.flask.application File "/var/lib/kolla/venv/lib/python3.10/site-packages/keystone/common/manager.py", line 110, in wrapped
ERROR keystone.server.flask.application __ret_val = __f(*args, **kwargs)
ERROR keystone.server.flask.application File "/var/lib/kolla/venv/lib/python3.10/site-packages/decorator.py", line 232, in fun
ERROR keystone.server.flask.application return caller(func, *(extras + args), **kw)
ERROR keystone.server.flask.application File "/var/lib/kolla/venv/lib/python3.10/site-packages/dogpile/cache/region.py", line 1632, in get_or_create_for_user_func
ERROR keystone.server.flask.application return self.get_or_create(
ERROR keystone.server.flask.application File "/var/lib/kolla/venv/lib/python3.10/site-packages/dogpile/cache/region.py", line 1092, in get_or_create
ERROR keystone.server.flask.application with Lock(
ERROR keystone.server.flask.application File "/var/lib/kolla/venv/lib/python3.10/site-packages/dogpile/lock.py", line 185, in __enter__
ERROR keystone.server.flask.application return self._enter()
ERROR keystone.server.flask.application File "/var/lib/kolla/venv/lib/python3.10/site-packages/dogpile/lock.py", line 94, in _enter
ERROR keystone.server.flask.application generated = self._enter_create(value, createdtime)
ERROR keystone.server.flask.application File "/var/lib/kolla/venv/lib/python3.10/site-packages/dogpile/lock.py", line 178, in _enter_create
ERROR keystone.server.flask.application return self.creator()
ERROR keystone.server.flask.application File "/var/lib/kolla/venv/lib/python3.10/site-packages/dogpile/cache/region.py", line 1046, in gen_value
ERROR keystone.server.flask.application created_value = creator(
ERROR keystone.server.flask.application File "/var/lib/kolla/venv/lib/python3.10/site-packages/keystone/token/provider.py", line 134, in check_revocation_v3
ERROR keystone.server.flask.application PROVIDERS.revoke_api.check_token(token_values)
ERROR keystone.server.flask.application File "/var/lib/kolla/venv/lib/python3.10/site-packages/keystone/common/manager.py", line 110, in wrapped
ERROR keystone.server.flask.application __ret_val = __f(*args, **kwargs)
ERROR keystone.server.flask.application File "/var/lib/kolla/venv/lib/python3.10/site-packages/keystone/revoke/core.py", line 137, in check_token
ERROR keystone.server.flask.application raise exception.TokenNotFound(_('Failed to validate token'))
ERROR keystone.server.flask.application keystone.exception.TokenNotFound: Failed to validate token
[2]
$ grep f47b3827 */*log
nova/nova-api.log: INFO nova.api.openstack.requestlog [None req-f47b3827-9070-4761-a9de-0f8c854ccc93 1f24a1c85bb24bc3aa83a22bc6b9a47e 2f764cefd79544f1959b3743281b072d - - 16cb1fce3b1b4842b3be2fb4e88c5c69 16cb1fce3b1b4842b3be2fb4e88c5c69] 10.70.142.1 "GET /v2.1/servers/72970654-cbaf-4e0e-94e0-70e7ba3e0db4" status: 200 len: 3747 microversion: 2.1 time: 0.104714
nova/nova-api.log: WARNING keystonemiddleware.auth_token [None req-f47b3827-9070-4761-a9de-0f8c854ccc93 1f24a1c85bb24bc3aa83a22bc6b9a47e 2f764cefd79544f1959b3743281b072d - - 16cb1fce3b1b4842b3be2fb4e88c5c69 16cb1fce3b1b4842b3be2fb4e88c5c69] Authorization failed for token: keystonemiddleware.auth_token._exceptions.InvalidToken: Token authorization failed
nova/nova-api.log: INFO nova.api.openstack.requestlog [None req-f47b3827-9070-4761-a9de-0f8c854ccc93 1f24a1c85bb24bc3aa83a22bc6b9a47e 2f764cefd79544f1959b3743281b072d - - 16cb1fce3b1b4842b3be2fb4e88c5c69 16cb1fce3b1b4842b3be2fb4e88c5c69] 10.70.142.1 "GET /v2.1/servers/detail?name=shoot--system--mon" status: 401 len: 114 microversion: - time: 0.078451