• 进入"运维那点事"后,希望您第一件事就是阅读“关于”栏目,仔细阅读“关于Ctrl+c问题”,不希望误会!

Django日志详解

Python框架 彭东稳 6年前 (2019-01-16) 26003次浏览 已收录 0个评论

Django对于日志输出的信息是很完善的,request的信息,setting配置,trackback的信息,一应俱全,足够我们调试了。但是在线上环境,如果让用户看到这些信息,是很不安全的(暴露代码)。所以在线上我们要关闭Debug,但是又不能扔掉这些调试信息,这就要用到日志了。Django使用Python内建的logging模块打印日志,但在Django中有很多本地化的支持。关于该模块具体介绍及使用方式可参考logging

首先要理解logging的工作,这里面主要有四个东西:格式器formatter,过滤器filter,处理器handler,记录器logger。

  • Loggers

logger 是日志系统的入口。每个 logger 都是命名了的 bucket,消息写入 bucket 以便进一步处理。

logger 可以配置日志级别。日志级别描述了由该 logger 处理的消息的严重性。Python 定义了下面几种日志级别:

DEBUG:排查故障时使用的低级别系统信息

INFO:一般的系统信息

WARNING:描述系统发生了一些小问题的信息

ERROR:描述系统发生了大问题的信息

CRITICAL:描述系统发生严重问题的信息

每一条写入 logger 的消息都是一条*日志记录*。每一条日志记录也包含*日志级别*,代表对应消息的严重程度。日志记录还包含有用的元数据,来描述被记录了日志的事件细节,例如堆栈跟踪或者错误码。

当 logger 处理一条消息时,会将自己的日志级别和这条消息的日志级别做对比。如果消息的日志级别匹配或者高于 logger 的日志级别,它就会被进一步处理。否则这条消息就会被忽略掉。

当 logger 确定了一条消息需要处理之后,会把它传给 Handler

  • Handlers

Handler 是决定如何处理 logger 中每一条消息的引擎。它描述特定的日志行为,比如把消息输出到屏幕、文件或网络 socket。和 logger 一样,handler 也有日志级别的概念。如果一条日志记录的级别不匹配或者低于 handler 的日志级别,对应的消息会被 handler 忽略。

一个 logger 可以有多个 handler,每一个 handler 可以有不同的日志级别。这样就可以根据消息的重要性不同,来提供不同格式的输出。例如,你可以添加一个 handler 把 ERROR 和 CRITICAL 消息发到寻呼机,再添加另一个 handler 把所有的消息(包括 ERROR 和 CRITICAL 消息)保存到文件里以便日后分析。

  • Filters

在日志记录从 logger 传到 handler 的过程中,使用 Filter 来做额外的控制。

默认情况下,只要级别匹配,任何日志消息都会被处理。不过,也可以通过添加 filter 来给日志处理的过程增加额外条件。例如,可以添加一个 filter 只允许某个特定来源的 ERROR 消息输出。

Filter 还被用来在日志输出之前对日志记录做修改。例如,可以写一个 filter,当满足一定条件时,把日志记录从 ERROR 降到 WARNING 级别。

Filter 在 logger 和 handler 中都可以添加;多个 filter 可以链接起来使用,来做多重过滤操作。

  • Formatters

日志记录最终是需要以文本来呈现的。Formatter 描述了文本的格式。一个 formatter 通常由包含 :ref:`LogRecord attributes `<python:logrecord-attributes> 的 Python 格式化字符串组成,不过你也可以为特定的格式来配置自定义的 formatter。

一、使用logging模块

配置好了 logger,handler,filter 和 formatter 之后,需要在代码里发起 logging 的调用。使用 logging 框架非常简单,下面是个例子:

为 logger 命名

logging.getLogger()的调用会获取(必要时会创建)一个 logger 的实例。不同的 logger 实例用名字来区分。这个名字是为了在配置的时候指定 logger。

按照惯例,logger 的名字通常是包含该 logger 的 Python 模块名,即 __name__。这样可以基于模块来过滤和处理日志请求。不过,如果你有其他的方式来组织你的日志消息,可以为 logger 提供点号分割的名字来标识它:

这种 logger 的名字,用点号分隔的路径定义了一种层次结构。project.interesting 这个 logger 是 project.interesting.stuff logger 的上级;而 project logger 是 project.interesting logger 的上级。

为什么这种层级结构是重要的呢?因为 logger 可以设置为将日志的请求 *传播* 给上级。这样就可以在 logger 树结构的顶层定义一组单独的 handler,来捕获所有下层的日志请求。在 project 命名空间中定义的 logger handler 将会捕获 project.interesting 和 project.interesting.stuff 这两个 logger 中的所有日志请求。

可以基于 logger 来控制传播的行为,如果你不希望某个 logger 传播给上级,可以关闭它。

发起 logging 调用

logger 实例包含了每种默认日志级别的入口方法:

  • logger.debug()
  • logger.info()
  • logger.warning()
  • logger.error()
  • logger.critical()

还有两种其他的调用方法:

  • logger.log():手动输出一条指定日志级别的日志消息。
  • logger.exception():创建一个包含当前异常堆栈帧的 ERROR 级别日志消息。

二、日志模块的配置

当然,仅仅在代码里调用 logging 是不够的。还需要配置 logger、handler、filter 和 formatter 来确保日志框架能有效地输出日志。

Python的logging模块提供了好几种配置方式。默认情况下,Django使用dictConfig format,也就是字典方式。在Django中通过在settings文件中使用LOGGING来定制日志输出。

为了配置 logging ,用字典的格式定义一个 LOGGING 配置项,这些配置描述了你想要的 logger、handler、filter 和 formatter,以及它们的日志级别和其他你想要的属性。

默认情况下 LOGGING 配置和 “Django的默认日志配置” 按照下面的方式合并在一起:

如果LOGGING中的disable_existing_loggers值为True(默认值),那么默认配置中的所有 logger 都将禁用。logger 的禁用与删除不同,logger仍然存在,但是将默默丢弃任何传递给它的信息,也不会传播给上一级 logger。所以,你应该非常小心使用'disable_existing_loggers': True,它可能不是你想要的。相反你应该把disable_existing_loggers设置为False,然后再重新定义其中的一些默认 loggers。

或者你也可以将LOGGING_CONFIG设置为None,这将禁用Django默认日志记录。这是一个禁用Django日志配置然后手动配置日志记录的示例:

logging 被配置成了 Django setup() 函数的一部分。因此,你可以确定的是,logger 一直都可以在项目代码里使用。

这是一个简单的配置,它将来自django记录器的所有日志记录写入本地文件:

如果你使用此示例,请确保将“filename”路径更改为运行Django应用程序的用户可写的位置。

其次,这是一个如何使日志系统将Django的日志记录打印到控制台的示例。它可能在本地开发期间很有用。

默认情况下,此配置仅向控制台发送级别为 INFO 或更高级别的消息(与Django的默认日志记录配置相同,但默认情况下仅在 DEBUG=True 时显示日志记录)。 Django没有记录很多这样的消息。但是,使用此配置,你还可以设置环境变量 DJANGO_LOG_LEVEL = DEBUG 以查看 Django 的所有调试日志记录,因为它包含所有数据库查询,因此非常详细:

最后,这是一个相当复杂的日志设置示例:

此日志记录配置执行以下操作:

将配置标识为“dictConfig version 1”格式。目前,这是唯一的dictConfig格式版本。

定义两个 formatters:

simple,只输出日志级别名称(例如,DEBUG)和日志消息。

verbose,输出日志级别名称,日志消息,以及生成日志消息的时间,进程,线程和模块。

其中格式字符串是一个普通的Python格式化字符串,用于描述要在每个日志记录行上输出的详细信息。而 style 参数默认为 “%” 百分符,这表示前面的格式化字符串参数应该是一个%(<dictionary key>)s格式的字符串,这里将 style 参数设置为 “{” 花括号,就可以将格式化字符串参数写成 {(<dictionary key>)}格式。而可以使用的logging内置的keys,如下表所示:

属性 格式 描述
asctime %(asctime)s 日志产生的时间,默认格式为2003-07-08 16:49:45,896
created %(created)f time.time()生成的日志创建时间戳
filename %(filename)s 生成日志的程序名
funcName %(funcName)s 调用日志的函数名
levelname %(levelname)s 日志级别 (‘DEBUG’, ‘INFO’, ‘WARNING’, ‘ERROR’, ‘CRITICAL’)
levelno %(levelno)s 日志级别对应的数值
lineno %(lineno)d 日志所针对的代码行号(如果可用的话)
module %(module)s 生成日志的模块名
msecs %(msecs)d 日志生成时间的毫秒部分
message %(message)s 具体的日志信息
name %(name)s 日志调用者
pathname %(pathname)s 生成日志的文件的完整路径
process %(process)d 生成日志的进程ID(如果可用)
processName %(processName)s 进程名(如果可用)
thread %(thread)d 生成日志的线程ID(如果可用)
threadName %(threadName)s 线程名(如果可用)

定义两个 filters:

project.logging.SpecialFilter,使用 special 别名。如果此过滤器需要其他参数,则可以将它们作为过滤器配置字典中的附加键提供。在这个例子中,在实例化 SpecialFilter 时,参数foo将被赋予bar值。

django.utils.log.RequireDebugTrue,当DEBUG为True时传递记录。

定义两个 handlers:

console,一个StreamHandler,它向sys.stderr输出任何INFO(或更高版本)消息。此处理程序使用简单的输出格式。

mail_admins,一个AdminEmailHandler,它将任何ERROR(或更高版本)消息通过电子邮件发送到站点ADMINS。此处理程序使用特殊过滤器。

定义三个 loggers:

django,它将所有消息传递给控制台处理程序。

django.request,它将所有ERROR消息传递给mail_admins处理程序。此外,此记录器标记为不传播消息。这意味着django记录器不会处理写入django.request的日志消息。

myproject.custom,它传递INFO或更高级别的所有消息,这些消息也将 special 过滤器传递给两个 handler 程序 – console和mail_admins。这意味着所有INFO级别消息(或更高级别)将打印到console;ERROR和CRITICAL消息也将通过邮件输出。

最后再给一个目前项目中使用的日志案例:

三、Django对logging模块的扩展

Django对logging模块进行了一定的扩展,用来满足Web服务器专门的日志记录需求。

1. 记录器Loggers

Django额外提供了几个其内建的logger。

  • django

不要使用这个记录器,用下面的。这是一个被供起来的记录器。

  • django.request

记录与请求处理相关的消息。HTTP 5XX响应记录为ERROR消息,4XX响应记录为WARNING消息。记录到django.security记录器的请求不会记录到django.request。

另外,发送给此记录器的消息具有以下额外的信息:

status_code:与请求关联的HTTP响应状态码。

request:生成日志消息的请求对象。

  • django.server

记录与runserver命令调用的服务器接收的请求的处理相关的消息。 HTTP 5XX响应记录为ERROR消息,4XX响应记录为WARNING消息,其他所有响应记录为INFO。同样,也具有 status_code 与 request 信息。

  • django.template

记录与渲染模板相关的日志。

  • django.db.backends

记录与数据库交互相关的消息。例如,请求执行的每个应用程序级SQL语句都会在DEBUG级别记录到此记录器。

另外,发送给此记录器的消息具有以下额外的信息:

duration:执行SQL语句所需的时间。

sql:已执行的SQL语句。

params:SQL调用中使用的参数。

出于性能原因,只有在settings.DEBUG设置为True时才会启用SQL日志记录,而不管安装的日志记录级别或处理程序如何。

此日志记录不包括框架级初始化(例如SET TIMEZONE)或事务管理查询(例如BEGIN,COMMIT和ROLLBACK)。如果要查看所有数据库查询,请在数据库中启用查询日志记录。

  • django.security

记录任何与安全相关的错误。

  • django.security.csrf

记录CSRF验证失败日志。

  • django.db.backends.schema

当迁移框架执行的SQL 查询会改变数据库的模式时,则记录这些SQL 查询。注意,它不会记录 RunPython 执行的查询。

2. 处理器Handlers

  • class AdminEmailHandler(include_html=False, email_backend=None)

Django额外提供了一个handler,AdminEmailHandler。这个处理器将它收到的每个日志信息用邮件发送给站点管理员。

如果日志记录包含 request 属性,该请求的完整细节都将包含在邮件中。如果日志记录包含栈追踪信息,该栈追踪信息也将包含在邮件中。

AdminEmailHandler 的 include_html 参数用于控制邮件中是否包含 HTML 附件,这个附件包含 DEBUG 为 True 时的完整网页。若要在配置中设置这个值,可以将它包含在 django.utils.log.AdminEmailHandler handler 的定义中,像下面这样:

注意,邮件中的 HTML 包含完整的跟踪栈,包括栈每个层级局部变量的名称和值以及你的 Django 设置。这些信息可能非常敏感,你也许不想通过邮件发送它们。此时可以考虑使用类似 Sentry 这样的东西。

通过设置 AdminEmailHandler 的 email_backend 参数,可以覆盖 handler 使用的 email backend,像这样:

默认情况下,将使用EMAIL_BACKEND 中指定的邮件后端。

  • send_mail(subject, message, *args, **kwargs)

向管理员用户发送电子邮件。若要自定义此行为,你可以继承AdminEmailHandler类并重写此方法。

3. 过滤器Filters

Django还额外提供两个过滤器。

  • class CallbackFilter(callback)

这个过滤器接受一个回调函数,并对每个传递给过滤器的记录调用它。如果回调函数返回False,将不会进行记录的处理。

例如,要从管理员电子邮件中过滤掉UnreadablePostError(在用户取消上载时引发),你将创建一个过滤器函数:

然后把它添加到你的日志配置中:

  • class RequireDebugFalse

此过滤器仅在settings.DEBUG为False时传递记录。

此过滤器在默认LOGGING配置中使用如下,以确保AdminEmailHandler仅在DEBUG为False时向管理员发送错误电子邮件:

  • class RequireDebugTrue

此过滤器类似于RequireDebugFalse,但只有在DEBUG为True时才传递记录。

四、Django的默认日志配置

当DEBUG为True时:

django logger 将 INFO 级别或更高级别的django层次结构(django.server除外)中的消息发送到控制台。

当DEBUG为False时:

django logger 将具有 ERROR 或 CRITICAL 级别的Django层次结构(django.server除外)中的消息发送到AdminEmailHandler。

独立于DEBUG的值:

django.server logger 将 INFO 级别或更高级别的消息发送到控制台。

除 django.server 之外的所有记录器都会将日志记录传播到其父级,直到根django记录器。 console和mail_admins处理程序附加到根记录器以提供上述行为。

五、源码跟踪

上面说了,logging 被配置成了 django.setup() 函数的一部分。这个方法在 get_wsgi_application() 方法中被调用,及执行 runserver 时在 utility.execute() 方法中被调用。

可以看到 configure_logging 传进去了上面提到的 settings.LOGGING_CONFIG 和 settings.LOGGING 参数。这里注意一下,如果我们没有在 settings 文件中定义这两个参数,那么就会从默认 settings 中获取,看一下默认 django/conf/global_settings.py 对这两个参数的定义(Django会把settings文件与默认全局settings文件进行合并):

知道了这个简单的因果关系,接下来看一下 configure_logging 方法主要干嘛了,代码如下:

逻辑很简单,如果 logging_config 为真就返回 dictConfig() 方法,并且使用 logging.conf 的 dictConfig() 方法,获取默认日志配置信息。如果我们在 settings 中设置了 settings.LOGGING,那么就会应用用户自定义设置。这也顺便说明了我们没有设置 LOGGING 时,日志输出的来源。

看一下默认的 LOGGING 设置:

都配置完成后,就涉及到 logger 的调用了。调用处理逻辑在 WSGIRequestHandler 类中,这是创建 WSGIServer 实例时指定的 HTTP 请求类,其中 log_message 方法就是处理请求日志的,此方法是重写了 simple_server.WSGIRequestHandler(http.server.BaseHTTPRequestHandler) 中的 log_message 方法。

然后日志在 WSGIServer 响应时处理,简单的逻辑就是视图处理完后,最终会调用 finish_response() 完成响应。而在 finish_response() 方法中返回 content 后会调用 close() 方法,那么 close() 方法又调用了 log_request() 请求日志处理方法,最终 log_request() 会调用 log_message() 方法进行日志处理。

如果是返回错误,那么就会调用 log_error() 方法,同样调用 log_message() 方法。

日志处理只是 Django 从请求到响应中的一个环节,所以理解从请求到响应整个流程才更有利于明白日志处理这个环节到底是如何工作的,这里也说的不是很详细,大致带过。


如果您觉得本站对你有帮助,那么可以支付宝扫码捐助以帮助本站更好地发展,在此谢过。
喜欢 (2)
[资助本站您就扫码 谢谢]
分享 (0)

您必须 登录 才能发表评论!