背景
近期我们的 Django 项目引入了 Jeager 做调用链监控,希望将调用链的 trace 信息和业务日志进行关联,以便能在出问题的业务尽快查询到对应的业务日志.
所以将 Jeager 的 trace_id 和 span_id 引入 Django 的日志是目前的改造方向.
Log过滤器
对于在日志输出中增加上下文信息, Python 的 logging 库提供了 Filters 的功能.
Filter 实例可以改变传入的 LogRecords ，比如添加附加属性后使用合适的 Formatter 输出。
这里我们实现一个 JeagerFilter, 通过 get_current_span() 方法我们拿到当前上下文的 span, 并且将 trace_id 和 span_id 添加到 LogRecords 中.
最后必须返回 True .逻辑是 Filter.filter 函数返回 True 的时候,这条日志才会被输出.
from opentracing_instrumentation import get_current_span
class JeagerFilter(logging.Filter):
def filter(self, record):
span = get_current_span()
record.trace_id = span.trace_id
record.span_id = span.span_id
return True
Django日志配置
接下来我们配置 Django 的 LOGGING
LOGGING = {
'version': 1,
'disable_existing_loggers': False,
'filters': {
'jeager': {
'()': 'utils.tracing_utils.JeagerFilter'
}
},
'formatters': {
'simple': {
'format': '[django] trace_id=%(trace_id)x span_id=%(span_id)x %(asctime)s %(levelname)s [%(process)d:%(processName)s] %(pathname)s %(module)s %(filename)s %(funcName)s %(lineno)d "%(message)s"'
},
},
'handlers': {
'null': {
'class': 'logging.NullHandler',
'level': 'DEBUG'
},
'console': {
'class': 'logging.StreamHandler',
'filters': ['jeager'],
'level': 'DEBUG',
'formatter': 'simple'
},
},
'loggers': {
'custom': {
'handlers': ['console'],
'level': 'DEBUG',
'propagate': False
},
},
'root': {
'handlers': ['null'],
'level': 'DEBUG'
},
可以看到在 filters 增加了一个自定义的 utils.tracing_utils.JeagerFilter,别名 jeager
然后在 console 这个 handler 中使用 jeager 这个 Filter 接下来使用 console 这个 handler 的日志中就会增加 trace_id 和 span_id 这两个字段了.
我们配置一下对应的 formatter 增加: trace_id=%(trace_id)x span_id=%(span_id)x
查看一下对应的输出:
[django] trace_id=2ddd108598ae190a span_id=fd08137be979e9a9 2020-01-15 13:27:19,951 INFO [400:MainProcess] ./custom/views.py views views.py list 83 "custom message"
这里Django日志和Jeager信息的关联就改造完成了.