Django 日志过滤器实战

Django 的日志配置采用标准的 Python 日志配置方式,默认采用 dictConfig 的格式。Python 文档里对日志过滤器 Filter 的解释是一种控制日志记录 Record 是否输出的机制。就像物理世界中的筛子,只有特定大小或形状的物体才能通过,Filter 可以按照特定的需求“筛选”出我们需要的日志记录。

我们来看看 Django 的一个内置过滤器 RequireDebugFalse 。这个过滤器一般是用于发送错误邮件日志,只有设置了 DEBUG = False时才把错误日志发送给管理员(生产环境,避免邮件轰炸) :

'filters': {
    'require_debug_false': {
        '()': 'django.utils.log.RequireDebugFalse',
    }
},
'handlers': {
    'mail_admins': {
        'level': 'ERROR',
        'filters': ['require_debug_false'],
        'class': 'django.utils.log.AdminEmailHandler'
    }
},

可以看出,过滤器的配置方法是在 filters 的 dict 里指定一个别名 'require_debug_false'作为 key,value 又是一个 dict。这个 dict 用来描述过滤器如何被实例化。其中,'()'作为特殊的 key 用来指定过滤器是哪个类的实例(见 logging.config.DictConfigurator)。其它的 key 用来指定实例化过滤器是传给 __init__ 方法的参数。

再来看 RequireDebugFalse 过滤器的实现:

class RequireDebugFalse(logging.Filter):
    def filter(self, record):
        return not settings.DEBUG

很简单,就是定义 filter 方法,日志记录 record 作为唯一参数,返回值为 0False 表示日志记录将被抛弃,1True则表示记录别放过。

过滤器不仅可以用来滤除不需要的日志记录,还可以修改日志记录。例如,我们可以给日志记录添加自定义的属性,用来区分日志来自于哪个应用和运行环境。

class StaticFieldFilter(logging.Filter):

    def __init__(self, fields):
        self.static_fields = fields

    def filter(self, record):
        for k, v in self.static_fields.items():
            setattr(record, k, v)
        return True

这个过滤器把初始化时得到的属性键值对设为每条日志记录的属性,用法如下:

'filters': {
    'require_debug_false': {
        '()': 'django.utils.log.RequireDebugFalse',
    },
    'static_fields': {
        '()': 'example.utils.log.StaticFieldFilter',
        'fields': {
            'project': os.environ['PROJECT_NAME'],
            'environment': os.environ['ENV_NAME'],
        },
    }
},
'handlers': {
    'mail_admins': {
        'level': 'ERROR',
        'filters': ['require_debug_false', 'static_fields'],
        'class': 'django.utils.log.AdminEmailHandler'
    }
},

注意 fields 是如何配置传入的。

更进一步,我们还可以让错误日志邮件的标题也包含自定义的属性:

def filter(self, record):
    for k, v in self.static_fields.items():
        setattr(record, k, v)
        record.levelname = '[%s] %s' % (v, record.levelname)
    return True

再来看一个例子,Django 可以把 request 请求信息设为日志记录的属性,但有些日志处理器(比如 Graylog2 的 GELFHandler )不能序列化 Request 对象,需要做些处理:

from django.http import build_request_repr
class RequestFilter(logging.Filter):

    def filter(self, record):
        if hasattr(record, 'request'):
            record.request_repr = build_request_repr(record.request)
            del record.request
        return True

这里我们把 request 对象用 Django 内置的函数 build_request_repr 转为字符串格式,然后删掉日志记录的 request 属性。

配置方法:

'filters': {
    'require_debug_false': {
        '()': 'django.utils.log.RequireDebugFalse',
    },
    'static_fields': {
        '()': 'example.utils.log.StaticFieldFilter',
        'fields': {
            'project': os.environ['PROJECT_NAME'],
            'environment': os.environ['ENV_NAME'],
        },
    },
    'exclude_django_request': {
        '()': 'example.utils.log.RequestFilter',
    }
},
'handlers': {
    'gelf': {
        'level': 'DEBUG',
        'class': 'graypy.GELFHandler',
        'host': os.environ['GRAYLOG2_HOST'],
        'port': int(os.environ['GRAYLOG2_PORT']),
        'filters': [
            'require_debug_false', 
            'static_fields', 
            'exclude_django_request', 
        ],
    },
},

参考:

定制 Django REST Framework 的异常处理

今天借助修复其它 Bug 的机会,对项目中 REST API 的异常处理机制进行了优化。

项目的 REST API 是基于 Django REST Framework 实现的,之前已经按照其文档的说明,对 EXCEPTION_HANDLER 进行了定制,用统一的 JSON 数据格式来输出异常错误信息,包括 500 错误。没有定制时,对于系统所有未特殊处理的异常,Django REST Framework 的处理方法是继续向上抛出,而不是像其它情况那样处理成自己封装的 Exception Response。这样的话,客户端得到的响应是 Django 框架的 500 错误页面,不便于客户端的统一处理。

自定义的异常处理函数如下:

from rest_framework.views import exception_handler

def my_api_exception_handler(exc):
    # Call REST framework's default exception handler first to get the standard error response.
    response = exception_handler(exc)

    # handle 500 errors
    if response is None:
        if isinstance(exc, APIException):
            detail = exc.detail
        else:
            detail = exc.message if settings.DEBUG else 'Internal Server Error'
        response = Response({'detail': detail}, status=status.HTTP_500_INTERNAL_SERVER_ERROR)

    return response

这里先调用框架默认的异常处理函数(Line 5),当这个函数返回的 response 对象为 None 时(Line 8),说明异常没有被它处理。这时我们就自己生成一个 status 状态码为 500 的 Response 对象(Line 13),而不是返回 None 。

自定义的异常处理函数必须在 settings 里启用,如下

REST_FRAMEWORK = {
    'EXCEPTION_HANDLER': 'my_project.my_app.utils. my_api_exception_handler'
}

今天的改进是对异常处理函数中日志的改进。原来的日志记录在发生 500 的错误,就记录一条 Error 日志:

logger.error("api view 500 error: %s >>>\n %s", str(exc), traceback.format_exc())

在生产环境下,这条日志会产生一封通知邮件,但效果并不好,异常堆栈变成了一长串字符被塞进了邮件的主题里,也没有当前 Request 的上下文信息,很难从中分析定位错误。

改进后的日志语句被挪到了 APIView 的 handle_exception 方法里:

def handle_exception(self, exc):
    resp = super(GenericAPIView, self).handle_exception(exc)
    if resp.status_code == status.HTTP_500_INTERNAL_SERVER_ERROR:
        logger.error("API View 500 error: %s", self.request.path,
                     exc_info=sys.exc_info(),
                     extra={
                         'status_code': 500,
                         'request': self.request
                     })
    return resp

可以看到,异常信息和当前请求信息都被记录了( Line 5 和 Line 8)。exc_info 和 extra 参数的说明见 Python 标准库文档,这里也参考了 Django 中 AdminEmailHandler 类的实现。

以上。