From 18b8033b6bd1945bd27b03b779a32a883df5fb10 Mon Sep 17 00:00:00 2001 From: Gorka Eguileor Date: Fri, 4 Feb 2022 12:42:25 +0100 Subject: [PATCH] Fix request id mess on Cinder-API This patch fixes multiple issues related to request ids: - Duplicated request ID in logs - Missing request id header in response - Wrong request ID in response header when using noauth The source of these issues is the fact that the request ID and the request context are set too late, or not at all, in the paste filter chain. And the last bug is fixed as a freebie when the code in auth.py is refactored to reduce code duplication on setting the cinder.context key in the request's environment. The patch fixes these issue by changing the filter chains to have the request_id filter as the first filter, and using our own filter for it, to ensure that the context is correctly set. Not sure if values now defined in ENV_OVERWRITES are still necessary, so the patch preserves current behavior. Closes-Bug: #1960019 Closes-Bug: #1960020 Closes-Bug: #1960021 Closes-Bug: #1960329 Change-Id: Ide831a221a7561bbb7da193f0edb011f1989420e --- cinder/api/middleware/auth.py | 92 +++++++++---------- cinder/api/middleware/request_id.py | 71 ++++++++++++++ etc/cinder/api-paste.ini | 27 +++--- .../fix-request_id-6f6972b2c12d1a18.yaml | 15 +++ 4 files changed, 144 insertions(+), 61 deletions(-) create mode 100644 cinder/api/middleware/request_id.py create mode 100644 releasenotes/notes/fix-request_id-6f6972b2c12d1a18.yaml diff --git a/cinder/api/middleware/auth.py b/cinder/api/middleware/auth.py index caf36f65966..9758d28283d 100644 --- a/cinder/api/middleware/auth.py +++ b/cinder/api/middleware/auth.py @@ -22,7 +22,6 @@ import os from oslo_config import cfg from oslo_log import log as logging -from oslo_middleware import request_id from oslo_serialization import jsonutils import webob.dec import webob.exc @@ -60,6 +59,36 @@ def pipeline_factory(loader, global_conf, **local_conf): return app +def _set_request_context(req, **kwargs): + """Sets request context based on parameters and request.""" + remote_address = getattr(req, 'remote_address', '127.0.0.1') + + service_catalog = None + if req.headers.get('X_SERVICE_CATALOG') is not None: + try: + catalog_header = req.headers.get('X_SERVICE_CATALOG') + service_catalog = jsonutils.loads(catalog_header) + except ValueError: + raise webob.exc.HTTPInternalServerError( + explanation=_('Invalid service catalog json.')) + + if CONF.use_forwarded_for: + remote_address = req.headers.get('X-Forwarded-For', remote_address) + + kwargs.setdefault('remote_address', remote_address) + kwargs.setdefault('service_catalog', service_catalog) + + # Preserve the timestamp set by the RequestId middleware + kwargs['timestamp'] = getattr(req.environ.get('cinder.context'), + 'timestamp', + None) + + # request ID and global ID are present in the environment req.environ + ctx = context.RequestContext.from_environ(req.environ, **kwargs) + req.environ['cinder.context'] = ctx + return ctx + + class InjectContext(base_wsgi.Middleware): """Add a 'cinder.context' to WSGI environ.""" @@ -75,53 +104,25 @@ class InjectContext(base_wsgi.Middleware): class CinderKeystoneContext(base_wsgi.Middleware): """Make a request context from keystone headers.""" + ENV_OVERWRITES = { + 'X_PROJECT_DOMAIN_ID': 'project_domain_id', + 'X_PROJECT_DOMAIN_NAME': 'project_domain_name', + 'X_USER_DOMAIN_ID': 'user_domain_id', + 'X_USER_DOMAIN_NAME': 'user_domain_name', + } @webob.dec.wsgify(RequestClass=base_wsgi.Request) def __call__(self, req): - - # NOTE(jamielennox): from_environ handles these in newer versions - project_name = req.headers.get('X_TENANT_NAME') - req_id = req.environ.get(request_id.ENV_REQUEST_ID) - - # Build a context, including the auth_token... - remote_address = req.remote_addr - - service_catalog = None - if req.headers.get('X_SERVICE_CATALOG') is not None: - try: - catalog_header = req.headers.get('X_SERVICE_CATALOG') - service_catalog = jsonutils.loads(catalog_header) - except ValueError: - raise webob.exc.HTTPInternalServerError( - explanation=_('Invalid service catalog json.')) - - if CONF.use_forwarded_for: - remote_address = req.headers.get('X-Forwarded-For', remote_address) - - ctx = context.RequestContext.from_environ( - req.environ, - request_id=req_id, - remote_address=remote_address, - project_name=project_name, - service_catalog=service_catalog) + params = {'project_name': req.headers.get('X_TENANT_NAME')} + for env_name, param_name in self.ENV_OVERWRITES.items(): + if req.environ.get(env_name): + params[param_name] = req.environ[env_name] + ctx = _set_request_context(req, **params) if ctx.user_id is None: LOG.debug("Neither X_USER_ID nor X_USER found in request") return webob.exc.HTTPUnauthorized() - if req.environ.get('X_PROJECT_DOMAIN_ID'): - ctx.project_domain_id = req.environ['X_PROJECT_DOMAIN_ID'] - - if req.environ.get('X_PROJECT_DOMAIN_NAME'): - ctx.project_domain_name = req.environ['X_PROJECT_DOMAIN_NAME'] - - if req.environ.get('X_USER_DOMAIN_ID'): - ctx.user_domain_id = req.environ['X_USER_DOMAIN_ID'] - - if req.environ.get('X_USER_DOMAIN_NAME'): - ctx.user_domain_name = req.environ['X_USER_DOMAIN_NAME'] - - req.environ['cinder.context'] = ctx return self.application @@ -149,15 +150,8 @@ class NoAuthMiddlewareBase(base_wsgi.Middleware): token = req.headers['X-Auth-Token'] user_id, _sep, project_id = token.partition(':') project_id = project_id or user_id - remote_address = getattr(req, 'remote_address', '127.0.0.1') - if CONF.use_forwarded_for: - remote_address = req.headers.get('X-Forwarded-For', remote_address) - ctx = context.RequestContext(user_id, - project_id, - is_admin=True, - remote_address=remote_address) - - req.environ['cinder.context'] = ctx + _set_request_context(req, user_id=user_id, project_id=project_id, + is_admin=True) return self.application diff --git a/cinder/api/middleware/request_id.py b/cinder/api/middleware/request_id.py new file mode 100644 index 00000000000..87d93880879 --- /dev/null +++ b/cinder/api/middleware/request_id.py @@ -0,0 +1,71 @@ +# Copyright 2022 Red Hat, Inc. +# All Rights Reserved. +# +# Licensed under the Apache License, Version 2.0 (the "License"); you may +# not use this file except in compliance with the License. You may obtain +# a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, WITHOUT +# WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the +# License for the specific language governing permissions and limitations +# under the License. + +from oslo_log import log as logging +from oslo_middleware import request_id as oslo_req_id +from oslo_utils import timeutils + +from cinder import context as cinder_context + + +LOG = logging.getLogger(__name__) + + +class RequestId(oslo_req_id.RequestId): + def _context_setter(self, environ, *args, **kwargs): + """Wrapper to set a temporary context. + + It is necessary to replace the previous request's context, but at this + point when we are generating the new request ID we don't have the + keystone info, so use a placeholder with the information we have: + + - global_request_id ==> Extracted from the headers by the parent class + - request_id => Generated by the parent class __call__ method + - timestamp => The moment Cinder API starts processing the request + + This middleware needs to be the first in ALL the pipelines for things + to work as expected, otherwise we'll have the following issues: + + - Logs from other filters reuse a context from a previous request, + presenting the wrong request id and project and user info, and then + after the request passes the auth filter the request id will change + to the right one. We'll see this when enabling debug mode in the + keystonemiddleware module. + + - Requests that don't require authorization (/ and /healthcheck) won't + return a request ID in the headers. + """ + # Replace previous request's context with all the info we have now + placeholder_ctx = cinder_context.RequestContext( + request_id=environ[oslo_req_id.ENV_REQUEST_ID], + global_request_id=environ.get(oslo_req_id.GLOBAL_REQ_ID), + timestamp=timeutils.utcnow(), + ) + + # Only update environ, oslo_context local store was updated + # automatically when instantiating the request context. + environ['cinder.context'] = placeholder_ctx + + # Have a timestamped log with the start of the pipeline processing. + LOG.debug('RequestId filter calling following filter/app') + return self._application(environ, *args, **kwargs) + + def __init__(self, *args, **kwargs): + # Parent __call__ method creates the request id and makes the call to + # the chained app one after the other, so we need a wrapper on the app + # to set the context. + super().__init__(*args, **kwargs) + self._application = self.application + self.application = self._context_setter diff --git a/etc/cinder/api-paste.ini b/etc/cinder/api-paste.ini index ce2e0ea98b6..cd3040e112f 100644 --- a/etc/cinder/api-paste.ini +++ b/etc/cinder/api-paste.ini @@ -10,13 +10,10 @@ use = call:cinder.api:root_app_factory [composite:openstack_volume_api_v3] use = call:cinder.api.middleware.auth:pipeline_factory -noauth = cors http_proxy_to_wsgi request_id faultwrap sizelimit osprofiler noauth apiv3 -noauth_include_project_id = cors http_proxy_to_wsgi request_id faultwrap sizelimit osprofiler noauth_include_project_id apiv3 -keystone = cors http_proxy_to_wsgi request_id faultwrap sizelimit osprofiler authtoken keystonecontext apiv3 -keystone_nolimit = cors http_proxy_to_wsgi request_id faultwrap sizelimit osprofiler authtoken keystonecontext apiv3 - -[filter:request_id] -paste.filter_factory = oslo_middleware.request_id:RequestId.factory +noauth = request_id cors http_proxy_to_wsgi faultwrap sizelimit osprofiler noauth apiv3 +noauth_include_project_id = request_id cors http_proxy_to_wsgi faultwrap sizelimit osprofiler noauth_include_project_id apiv3 +keystone = request_id cors http_proxy_to_wsgi faultwrap sizelimit osprofiler authtoken keystonecontext apiv3 +keystone_nolimit = request_id cors http_proxy_to_wsgi faultwrap sizelimit osprofiler authtoken keystonecontext apiv3 [filter:http_proxy_to_wsgi] paste.filter_factory = oslo_middleware.http_proxy_to_wsgi:HTTPProxyToWSGI.factory @@ -44,11 +41,19 @@ paste.filter_factory = oslo_middleware.sizelimit:RequestBodySizeLimiter.factory paste.app_factory = cinder.api.v3.router:APIRouter.factory [pipeline:apiversions] -pipeline = cors http_proxy_to_wsgi faultwrap osvolumeversionapp +pipeline = request_id cors http_proxy_to_wsgi faultwrap osvolumeversionapp [app:osvolumeversionapp] paste.app_factory = cinder.api.versions:Versions.factory +[pipeline:healthcheck] +pipeline = request_id healthcheckapp + +[app:healthcheckapp] +paste.app_factory = oslo_middleware:Healthcheck.app_factory +backends = disable_by_file +disable_by_file_path = /etc/cinder/healthcheck_disable + ########## # Shared # ########## @@ -59,7 +64,5 @@ paste.filter_factory = cinder.api.middleware.auth:CinderKeystoneContext.factory [filter:authtoken] paste.filter_factory = keystonemiddleware.auth_token:filter_factory -[app:healthcheck] -paste.app_factory = oslo_middleware:Healthcheck.app_factory -backends = disable_by_file -disable_by_file_path = /etc/cinder/healthcheck_disable +[filter:request_id] +paste.filter_factory = cinder.api.middleware.request_id:RequestId.factory diff --git a/releasenotes/notes/fix-request_id-6f6972b2c12d1a18.yaml b/releasenotes/notes/fix-request_id-6f6972b2c12d1a18.yaml new file mode 100644 index 00000000000..f610fb26302 --- /dev/null +++ b/releasenotes/notes/fix-request_id-6f6972b2c12d1a18.yaml @@ -0,0 +1,15 @@ +--- +fixes: + - | + `Bug #1960019 `_: Fixed + value of the x-openstack-request-id header when Cinder is using noauth. + - | + `Bug #1960020 `_: Fixed + duplicated request-id values in logs for different requests, happens only + on request to / to get available api versions. + - | + `Bug #1960021 `_: Fixed + missing request id headers in requests to / to get available api versions. + - | + `Bug #1960329 `_: Fixed + wrong request ID on middleware filters.