日志

日志管理快速入门

Django 使用 Python 内置的 logging 模块处理系统日志。关于该模块的使用,Python 自己的文档里有更详细的探讨。不过,如果你从来没用过 Python 的 logging 框架(或者即便你用过),这里是一篇快速的入门讲解。

日志框架的组成元素

一份 Python logging 配置有下面四个部分组成:

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 把 ERRORCRITICAL 消息发到寻呼机,再添加另一个 handler 把所有的消息(包括 ERRORCRITICAL 消息)保存到文件里以便日后分析。

过滤器

在日志记录从 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 框架非常简单,下面是个例子:

  1. # import the logging library
  2. import logging
  3.  
  4. # Get an instance of a logger
  5. logger = logging.getLogger(__name__)
  6.  
  7. def my_view(request, arg1, arg):
  8. ...
  9. if bad_mojo:
  10. # Log an error message
  11. logger.error('Something went wrong!')

就这么简单!bad_mojo 条件每次满足都会写一条 error 日志。

为 logger 命名

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

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

  1. # Get an instance of a specific named logger
  2. logger = logging.getLogger('project.interesting.stuff')

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

为什么这种层级结构是重要的呢?因为 logger 可以设置为将日志的请求传播给上级。这样就可以在 logger 树结构的顶层定义一组单独的 handler,来捕获所有下层的日志请求。在 project 命名空间中定义的 logger handler 将会捕获 project.interestingproject.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 的日志库提供了一些配置方法,可以使用编程接口或者配置文件。Django默认使用 dictConfig format

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

默认情况下 LOGGING 配置和 Django's default logging configuration 按照下面的方式合并在一起:

如果 LOGGING 这个配置项中的 disable_existing_loggers 被设置为 True (默认就是 Ture),那么默认配置中的 logger 全部被禁用。被禁用的 logger 并不是被删除了,它们仍然存在,只是静默地丢弃所有发来的日志请求,甚至不会传播给上级 logger。所以你要谨慎使用 'disable_existing_loggers': True;这很可能不是你想要的。相反你应该把 disable_existing_loggers 设置为 False,然后再重新定义其中的一些默认 loggers,或者你也可以将 LOGGING_CONFIG 设置为 None 然后 handle logging config yourself

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

示例

The full documentation for dictConfig formatis the best source of information about logging configuration dictionaries.However, to give you a taste of what is possible, here are several examples.

First, here's a simple configuration which writes all logging from thedjango logger to a local file:

  1. LOGGING = {
  2. 'version': 1,
  3. 'disable_existing_loggers': False,
  4. 'handlers': {
  5. 'file': {
  6. 'level': 'DEBUG',
  7. 'class': 'logging.FileHandler',
  8. 'filename': '/path/to/django/debug.log',
  9. },
  10. },
  11. 'loggers': {
  12. 'django': {
  13. 'handlers': ['file'],
  14. 'level': 'DEBUG',
  15. 'propagate': True,
  16. },
  17. },
  18. }

If you use this example, be sure to change the 'filename' path to alocation that's writable by the user that's running the Django application.

Second, here's an example of how to make the logging system print Django'slogging to the console. It may be useful during local development.

By default, this config only sends messages of level INFO or higher to theconsole (same as Django's default logging config, except that the default onlydisplays log records when DEBUG=True). Django does not log many suchmessages. With this config, however, you can also set the environment variableDJANGO_LOG_LEVEL=DEBUG to see all of Django's debug logging which is veryverbose as it includes all database queries:

  1. import os
  2.  
  3. LOGGING = {
  4. 'version': 1,
  5. 'disable_existing_loggers': False,
  6. 'handlers': {
  7. 'console': {
  8. 'class': 'logging.StreamHandler',
  9. },
  10. },
  11. 'loggers': {
  12. 'django': {
  13. 'handlers': ['console'],
  14. 'level': os.getenv('DJANGO_LOG_LEVEL', 'INFO'),
  15. },
  16. },
  17. }

Finally, here's an example of a fairly complex logging setup:

  1. LOGGING = {
  2. 'version': 1,
  3. 'disable_existing_loggers': False,
  4. 'formatters': {
  5. 'verbose': {
  6. 'format': '{levelname} {asctime} {module} {process:d} {thread:d} {message}',
  7. 'style': '{',
  8. },
  9. 'simple': {
  10. 'format': '{levelname} {message}',
  11. 'style': '{',
  12. },
  13. },
  14. 'filters': {
  15. 'special': {
  16. '()': 'project.logging.SpecialFilter',
  17. 'foo': 'bar',
  18. },
  19. 'require_debug_true': {
  20. '()': 'django.utils.log.RequireDebugTrue',
  21. },
  22. },
  23. 'handlers': {
  24. 'console': {
  25. 'level': 'INFO',
  26. 'filters': ['require_debug_true'],
  27. 'class': 'logging.StreamHandler',
  28. 'formatter': 'simple'
  29. },
  30. 'mail_admins': {
  31. 'level': 'ERROR',
  32. 'class': 'django.utils.log.AdminEmailHandler',
  33. 'filters': ['special']
  34. }
  35. },
  36. 'loggers': {
  37. 'django': {
  38. 'handlers': ['console'],
  39. 'propagate': True,
  40. },
  41. 'django.request': {
  42. 'handlers': ['mail_admins'],
  43. 'level': 'ERROR',
  44. 'propagate': False,
  45. },
  46. 'myproject.custom': {
  47. 'handlers': ['console', 'mail_admins'],
  48. 'level': 'INFO',
  49. 'filters': ['special']
  50. }
  51. }
  52. }

This logging configuration does the following things:

  • Identifies the configuration as being in 'dictConfig version 1'format. At present, this is the only dictConfig format version.

  • Defines two formatters:

    • simple, that just outputs the log level name (e.g.,DEBUG) and the log message.

The format string is a normal Python formatting stringdescribing the details that are to be output on each loggingline. The full list of detail that can be output can befound in Formatter Objects.

  • verbose, that outputs the log level name, the logmessage, plus the time, process, thread and module thatgenerate the log message.
  • Defines two filters:

    • project.logging.SpecialFilter, using the alias special. If thisfilter required additional arguments, they can be provided as additionalkeys in the filter configuration dictionary. In this case, the argumentfoo will be given a value of bar when instantiatingSpecialFilter.
    • django.utils.log.RequireDebugTrue, which passes on records whenDEBUG is True.
  • Defines two handlers:

    • console, a StreamHandler, which prints any INFO(or higher) message to sys.stderr. This handler uses the simpleoutput format.
    • mail_admins, an AdminEmailHandler, which emails any ERROR(or higher) message to the site ADMINS. This handler uses thespecial filter.
  • Configures three loggers:

    • django, which passes all messages to the console handler.
    • django.request, which passes all ERROR messages tothe mailadmins handler. In addition, this logger ismarked to _not propagate messages. This means that logmessages written to django.request will not be handledby the django logger.
    • myproject.custom, which passes all messages at INFOor higher that also pass the special filter to twohandlers — the console, and mail_admins. Thismeans that all INFO level messages (or higher) will beprinted to the console; ERROR and CRITICALmessages will also be output via email.

Custom logging configuration

If you don't want to use Python's dictConfig format to configure yourlogger, you can specify your own configuration scheme.

The LOGGING_CONFIG setting defines the callable that willbe used to configure Django's loggers. By default, it points atPython's logging.config.dictConfig() function. However, if you want touse a different configuration process, you can use any other callablethat takes a single argument. The contents of LOGGING willbe provided as the value of that argument when logging is configured.

Disabling logging configuration

If you don't want to configure logging at all (or you want to manuallyconfigure logging using your own approach), you can setLOGGING_CONFIG to None. This will disable theconfiguration process for Django's default logging. Here's an example that disables Django'slogging configuration and then manually configures logging:

settings.py

  1. LOGGING_CONFIG = None
  2.  
  3. import logging.config
  4. logging.config.dictConfig(...)

Setting LOGGING_CONFIG to None only means that the automaticconfiguration process is disabled, not logging itself. If you disable theconfiguration process, Django will still make logging calls, falling back towhatever default logging behavior is defined.

Django's logging extensions

Django provides a number of utilities to handle the uniquerequirements of logging in Web server environment.

Loggers

Django provides several built-in loggers.

django

The catch-all logger for messages in the django hierarchy. No messages areposted using this name but instead using one of the loggers below.

django.request

Log messages related to the handling of requests. 5XX responses areraised as ERROR messages; 4XX responses are raised as WARNINGmessages. Requests that are logged to the django.security logger aren'tlogged to django.request.

Messages to this logger have the following extra context:

  • status_code: The HTTP response code associated with therequest.
  • request: The request object that generated the loggingmessage.

django.server

Log messages related to the handling of requests received by the server invokedby the runserver command. HTTP 5XX responses are logged as ERRORmessages, 4XX responses are logged as WARNING messages, and everything elseis logged as INFO.

Messages to this logger have the following extra context:

  • status_code: The HTTP response code associated with the request.
  • request: The request object that generated the logging message.

django.template

Log messages related to the rendering of templates.

  • Missing context variables are logged as DEBUG messages.

django.db.backends

Messages relating to the interaction of code with the database. For example,every application-level SQL statement executed by a request is logged at theDEBUG level to this logger.

Messages to this logger have the following extra context:

  • duration: The time taken to execute the SQL statement.
  • sql: The SQL statement that was executed.
  • params: The parameters that were used in the SQL call.
    For performance reasons, SQL logging is only enabled whensettings.DEBUG is set to True, regardless of the logginglevel or handlers that are installed.

This logging does not include framework-level initialization (e.g.SET TIMEZONE) or transaction management queries (e.g. BEGIN,COMMIT, and ROLLBACK). Turn on query logging in your database if youwish to view all database queries.

django.security.*

The security loggers will receive messages on any occurrence ofSuspiciousOperation and other security-relatederrors. There is a sub-logger for each subtype of security error, including allSuspiciousOperations. The level of the log event depends on where theexception is handled. Most occurrences are logged as a warning, whileany SuspiciousOperation that reaches the WSGI handler will be logged as anerror. For example, when an HTTP Host header is included in a request froma client that does not match ALLOWED_HOSTS, Django will return a 400response, and an error message will be logged to thedjango.security.DisallowedHost logger.

These log events will reach the django logger by default, which mails errorevents to admins when DEBUG=False. Requests resulting in a 400 response dueto a SuspiciousOperation will not be logged to the django.requestlogger, but only to the django.security logger.

To silence a particular type of SuspiciousOperation, you can override thatspecific logger following this example:

  1. 'handlers': {
  2. 'null': {
  3. 'class': 'logging.NullHandler',
  4. },
  5. },
  6. 'loggers': {
  7. 'django.security.DisallowedHost': {
  8. 'handlers': ['null'],
  9. 'propagate': False,
  10. },
  11. },

Other django.security loggers not based on SuspiciousOperation are:

django.db.backends.schema

Logs the SQL queries that are executed during schema changes to the database bythe migrations framework. Note that it won't log thequeries executed by RunPython.Messages to this logger have params and sql in their extra context (butunlike django.db.backends, not duration). The values have the same meaningas explained in django.db.backends.

Handlers

Django provides one log handler in addition to those provided by thePython logging module.

  • class AdminEmailHandler(include_html=False, email_backend=None)[源代码]
  • This handler sends an email to the site ADMINS for each logmessage it receives.

If the log record contains a request attribute, the full detailsof the request will be included in the email. The email subject willinclude the phrase "internal IP" if the client's IP address is in theINTERNAL_IPS setting; if not, it will include "EXTERNAL IP".

If the log record contains stack trace information, that stacktrace will be included in the email.

The include_html argument of AdminEmailHandler is used tocontrol whether the traceback email includes an HTML attachmentcontaining the full content of the debug Web page that would have beenproduced if DEBUG were True. To set this value in yourconfiguration, include it in the handler definition fordjango.utils.log.AdminEmailHandler, like this:

  1. 'handlers': {
  2. 'mail_admins': {
  3. 'level': 'ERROR',
  4. 'class': 'django.utils.log.AdminEmailHandler',
  5. 'include_html': True,
  6. }
  7. },

Note that this HTML version of the email contains a full traceback,with names and values of local variables at each level of the stack, plusthe values of your Django settings. This information is potentially verysensitive, and you may not want to send it over email. Consider usingsomething such as Sentry to get the best of both worlds — therich information of full tracebacks plus the security of not sending theinformation over email. You may also explicitly designate certainsensitive information to be filtered out of error reports — learn more onFiltering error reports.

By setting the email_backend argument of AdminEmailHandler, theemail backend that is being used by thehandler can be overridden, like this:

  1. 'handlers': {
  2. 'mail_admins': {
  3. 'level': 'ERROR',
  4. 'class': 'django.utils.log.AdminEmailHandler',
  5. 'email_backend': 'django.core.mail.backends.filebased.EmailBackend',
  6. }
  7. },

By default, an instance of the email backend specified inEMAIL_BACKEND will be used.

  • sendmail(_subject, message, *args, **kwargs)[源代码]
  • Sends emails to admin users. To customize this behavior, you cansubclass the AdminEmailHandler class andoverride this method.

过滤器

Django provides some log filters in addition to those provided by the Pythonlogging module.

  • class CallbackFilter(callback)[源代码]
  • This filter accepts a callback function (which should accept a singleargument, the record to be logged), and calls it for each record thatpasses through the filter. Handling of that record will not proceed if thecallback returns False.

For instance, to filter out UnreadablePostError(raised when a user cancels an upload) from the admin emails, you wouldcreate a filter function:

  1. from django.http import UnreadablePostError
  2.  
  3. def skip_unreadable_post(record):
  4. if record.exc_info:
  5. exc_type, exc_value = record.exc_info[:2]
  6. if isinstance(exc_value, UnreadablePostError):
  7. return False
  8. return True

and then add it to your logging config:

  1. 'filters': {
  2. 'skip_unreadable_posts': {
  3. '()': 'django.utils.log.CallbackFilter',
  4. 'callback': skip_unreadable_post,
  5. }
  6. },
  7. 'handlers': {
  8. 'mail_admins': {
  9. 'level': 'ERROR',
  10. 'filters': ['skip_unreadable_posts'],
  11. 'class': 'django.utils.log.AdminEmailHandler'
  12. }
  13. },
  • class RequireDebugFalse[源代码]
  • This filter will only pass on records when settings.DEBUG is False.

This filter is used as follows in the default LOGGINGconfiguration to ensure that the AdminEmailHandler only sendserror emails to admins when DEBUG is False:

  1. 'filters': {
  2. 'require_debug_false': {
  3. '()': 'django.utils.log.RequireDebugFalse',
  4. }
  5. },
  6. 'handlers': {
  7. 'mail_admins': {
  8. 'level': 'ERROR',
  9. 'filters': ['require_debug_false'],
  10. 'class': 'django.utils.log.AdminEmailHandler'
  11. }
  12. },

Django's default logging configuration

By default, Django configures the following logging:

When DEBUG is True:

  • The django logger sends messages in the django hierarchy (exceptdjango.server) at the INFO level or higher to the console.
    When DEBUG is False:

  • The django logger sends messages in the django hierarchy (exceptdjango.server) with ERROR or CRITICAL level toAdminEmailHandler.
    Independent of the value of DEBUG:

  • The django.server logger sends messages at the INFO levelor higher to the console.
    All loggers except django.server propagate logging to theirparents, up to the root django logger. The console and mail_adminshandlers are attached to the root logger to provide the behavior describedabove.

See also Configuring logging to learn how you cancomplement or replace this default logging configuration.