简介
openstack组件中的日志内容都包含request_id， 这样大大方便了依据日志内容进行问题的追踪和分析。Python中内置的记录日志的模块是logging模块。 在openstack中对logging模块进行了封装， 开发了一个供所有openstack组件使用的日志记录项目， 名称为: 。 一般request_id都是放到context中的， 所以要想在日志中打印request_id， 也需要用到另外一个openstack项目,
记录日志流程
python中的记录日志模块是logging， 这里面涉及几个概念：
- logger
- handler
- formatter
- record
每次需要记录日志时， 必须要有一个logger， logger才是记录日志的主体， 接收到日志记录请求后， logger会生成一个record实例， 每个logger可以有若干个handler， 每个handler在调用handle方法时会使用formatter进行format。
原理分析
日志内容中的request_id是在格式化日志内容时从context中获取的， 借助oslo.log中formatters模块中定义的ContextFormatter类， 会在类中定义的format(self, record)方法中将需要记录的日志record格式化， 并通过调用_update_record_with_context(record)方法， 将context中的属性赋给record对象。
在_update_record_with_context(record)中的context获取方式是首先尝试从record中获取context， 如果没有的话在获取当前线程中全局的context， 源代码如下:
from oslo_context import context as context_utilsdef _dictify_context(context): if context is None: return {} if not isinstance(context, dict) and getattr(context, 'to_dict', None): context = context.to_dict() return contextdef _update_record_with_context(record): context = record.__dict__.get( 'context', context_utils.get_current() ) d = _dictify_context(context) # Copy the context values directly onto the record so they can be # used by the formatting strings. for k, v in d.items(): setattr(record, k, v) return context 一般来讲record不会有context属性， 都是借助oslo.context项目中context.py模块中定义的get_current()函数来获取当前线程中的context对象。 其源代码如下:
import threading_request_store = threading.local()def get_current(): """Return this thread's current context If no context is set, returns None """ return getattr(_request_store, 'context', None)
这里就涉及到当前线程中的context属性是如何赋值的问题。 在openstack项目中要想在日志内容中有request_id， 则必须同时用到oslo.log项目和oslo.context项目。 在get_current函数定义的context.py模块中还定义了一个RequestContext类，每次实例化该类时， 默认会更新当前线程的context属性，其源代码节选如下：
import threading_request_store = threading.local()class RequestContext(object): def __init__(self, auth_token=None, request_id=None, ..., overwrite=True, ....): ... if overwrite or not get_current(): self.update_store() def update_store(self): _request_store.context = self
实例分析
oslo.log文档中给出了一个很简单的通过使用oslo.log和oslo.context项目来在日志中添加request_id的。 可以发现， 只要在调用日志记录方法之前实例化一个oslo.context项目中提供的RequestContext类实例就可以在打印的日志中看大req-[uuid]字样了。
明白了上述流程， 进一步我们以nova项目为例进行分析。
经过全局搜索RequestContext， 发现在nova/context.py模块中通过继承oslo.context项目中context.py模块中的RequestContext定义了一个RequestContext类。 然后在nova/api/auth.py模块中定义了一个NovaKeystoneContext的Middleware， 在其__call__方法中会通过调用nova/context.py中定义的RequestContext.from_environ方法来实例化一个ctx， 从而实例化一个oslo.context中context.py模块中定义的RequestContext实例， 将context绑定到当前线程， 这样每次在nova中调用LOG.info的话打印的日志就包含了request_id。 而NovaKeystoneContext这个Middleware会在api-paste.ini中用到。
[composite:osapi_compute]use = call:nova.api.openstack.urlmap:urlmap_factory/: oscomputeversions# v21 is an exactly feature match for v2, except it has more stringent# input validation on the wsgi surface (prevents fuzzing early on the# API). It also provides new features via API microversions which are# opt into for clients. Unaware clients will receive the same frozen# v2 API feature set, but with some relaxed validation/v2: openstack_compute_api_v21_legacy_v2_compatible/v2.1: openstack_compute_api_v21[composite:openstack_compute_api_v21]use = call:nova.api.auth:pipeline_factory_v21noauth2 = cors http_proxy_to_wsgi compute_req_id faultwrap sizelimit osprofiler noauth2 osapi_compute_app_v21keystone = cors http_proxy_to_wsgi compute_req_id faultwrap sizelimit osprofiler authtoken keystonecontext osapi_compute_app_v21[filter:keystonecontext]paste.filter_factory = nova.api.auth:NovaKeystoneContext.factory
定义的filter会最终在openstack_compute_api_v21中进行使用， 最终是被osapi_compute使用， 也就是nova-api启动时需要加载的wsgi application。