Логгирование

Быстрый пример использования логгирования

Django использует встроенный модуль Python logging для системного логгирования. Подробности об использовании этого модуля описаны в документации модуля. Но для тех, кто никогда не использовал этот модуль (да и для тех кто использовал), мы приводим небольшой пример.

Действующие лица

Конфигурация логгирования в Python состоит из четырех частей:

Loggers(Логгеры)

Логгер – это точка входа в систему логгирования. Каждый логгер как именованный канал для сообщений, в который они отправляются для обработки.

У каждого логгера есть уровень логгирования (log level). Уровень логгирования указывает важность принимаемых сообщений. Python определяет следующие уровни логгирования:

  • DEBUG: Низкий уровень логгирования системной информации для последующего использования в отладке
  • INFO: Общая системная информация
  • WARNING: Информация о мелких проблемах возникших при работе приложения
  • ERROR: Информация об ошибках возникших при работе приложения
  • CRITICAL: Информация о критических ошибках

Каждое сообщение записанное в логгер называется Log Record(Запись). Каждая запись содержит уровень логгирования, который указывает важность сообщения. Сообщение также может содержать метаданные, которые описывают произошедшее событие. Метаданные могут содержать код ошибки или отладочную информацию.

Когда сообщение передается в логгер, уровень логгирования сообщения сравнивается с уровнем логгирования логгера. Если уровень логгирования сообщения равен или выше уровню логгирования логгера, сообщение будет обработано, иначе - проигнорировано.

После того, как логгер принял сообщение на обработку, оно передается в Handler(Обработчик).

Handlers(Обработчики)

Обработчик определяет что делать с сообщением пришедшим из логгера. Он определяет поведение логгирования, например: вывести сообщение на экран, записать в файл или сокет.

Как и логгеры, обработчики имеют уровень логгирования. Если уровень логгирования сообщения ниже уровня логгирования обработчика, сообщение будет проигнорировано.

Логгер может содержать несколько обработчиков, которые могут иметь различный уровень логгирования. Это позволяет обрабатывать сообщения в соответствии с их уровнем важности. Например, вы можете установить обработчик для ERROR и CRITICAL сообщений, который будет отправлять через какой-то сервер сообщений, и в то же время обработчик записывающий все сообщения (включая ERROR и CRITICAL) в файл.

Filters(Фильтры)

Фильтры предоставляют дополнительный контроль над тем, какие сообщения будут переданы из логгера в обработчик.

По умолчанию все сообщения, прошедшие проверку уровня логгирования, будут переданы в обработчик. Добавив фильтры вы можете определить дополнительные правила проверки при обработке сообщений. Например, вы можете добавить фильтр, который позволяет обрабатывать ERROR сообщения отправленные определенным источником.

Фильтры также могу изменить сообщение. Например, вы можете создать фильтр, который изменяет уровень логгирования определенных сообщения с ERROR на WARNING.

Фильтр могут быть добавлены к логгеру или обработчику, можно использовать несколько фильтров.

Formatters(Форматер)

В результате сообщение должно быть представлено в виде текста. Форматеры определяют точный формат этого текста. Обычно это строка форматирования Python, содержащая атрибуты LogRecord;но вы также можете создать собственный класс форматера для реализации необходимого поведения.

Использование логгирования

Once you have configured your loggers, handlers, filters and formatters, you need to place logging calls into your code. Using the logging framework works like this:

# import the logging library
import logging

# Get an instance of a logger
logger = logging.getLogger(__name__)

def my_view(request, arg1, arg):
    ...
    if bad_mojo:
        # Log an error message
        logger.error('Something went wrong!')

Это все! При каждой успешной проверке условия bad_mojo будет записано сообщение ошибки.

Именование логгеров

Вызов logging.getLogger() возвращает (создает при необходимости) экземпляр логгера. Экземпляру логгера может назначить имя. Это имя используется при настройке логгирования.

By convention, the logger name is usually __name__, the name of the Python module that contains the logger. This allows you to filter and handle logging calls on a per-module basis. However, if you have some other way of organizing your logging messages, you can provide any dot-separated name to identify your logger:

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

Точки в названии логгера позволяют определять иерархию. Логгер project.interesting считается родительским по отношению к логгеру project.interesting.stuff; логгер project родительским по отношению к project.interesting.

Why is the hierarchy important? Well, because loggers can be set to propagate their logging calls to their parents. In this way, you can define a single set of handlers at the root of a logger tree, and capture all logging calls in the subtree of loggers. A logger defined in the project namespace will catch all logging messages issued on the project.interesting and project.interesting.stuff loggers.

Передачу сообщений можно настроить для конкретного логгера. Если вы не хотите, чтобы определенный логгер передавал свои сообщения родительского логгеру, вы можете отключить такое поведение.

Функции логгирования

Логгер предоставляет методы для каждого уровня логгирования:

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

Также есть два дополнительных метода:

  • logger.log(): отправить сообщение с указанным уровнем логгирования
  • logger.exception(): Создать ERROR сообщение из последнего исключения(пер. the current exception stack frame).

Настройка логгирования

Конечно же не достаточно просто добавить вызов функций логгирования в ваш код. Вы также должны настроить логгеры, обработчики, фильтры и форматеры, чтобы сообщения попали в нужное место.

Python’s logging library provides several techniques to configure logging, ranging from a programmatic interface to configuration files. By default, Django uses the dictConfig format.

Для настройки логгирования используется настройка LOGGING. Эта настройка описывает логгеры, обработчики, фильтры и форматеры а также их параметры.

По умолчанию, параметр конфигурации LOGGING совмещается с стандартной конфигурацией журналирования Django с помощью следующей схемы.

If the disable_existing_loggers key in the LOGGING dictConfig is set to True (which is the dictConfig default if the key is missing) then all loggers from the default configuration will be disabled. Disabled loggers are not the same as removed; the logger will still exist, but will silently discard anything logged to it, not even propagating entries to a parent logger. Thus you should be very careful using 'disable_existing_loggers': True; it’s probably not what you want. Instead, you can set disable_existing_loggers to False and redefine some or all of the default loggers; or you can set LOGGING_CONFIG to None and handle logging config yourself.

Настройка логгирования происходит в момент инициализации Django функцией setup(). Поэтому можно быть увереннем, что логгирование всегда доступно в коде вашего проекта.

Примеры

The full documentation for dictConfig format is 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 configuration which writes all logging from the django logger to a local file:

settings.py
LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'handlers': {
        'file': {
            'level': 'DEBUG',
            'class': 'logging.FileHandler',
            'filename': '/path/to/django/debug.log',
        },
    },
    'loggers': {
        'django': {
            'handlers': ['file'],
            'level': 'DEBUG',
            'propagate': True,
        },
    },
}

При использовании этого примера убедитесь, что пользователь, от которого запускается Django приложение, имеет права на запись файла, указанного в 'filename'.

Во-вторых, здесь представлен пример того, как заставить систему журналирования Django выводить сообщения на консоль. Это может пригодится в локальной разработке.

By default, this config only sends messages of level INFO or higher to the console (same as Django’s default logging config, except that the default only displays log records when DEBUG=True). Django does not log many such messages. With this config, however, you can also set the environment variable DJANGO_LOG_LEVEL=DEBUG to see all of Django’s debug logging which is very verbose as it includes all database queries:

settings.py
import os

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'handlers': {
        'console': {
            'class': 'logging.StreamHandler',
        },
    },
    'loggers': {
        'django': {
            'handlers': ['console'],
            'level': os.getenv('DJANGO_LOG_LEVEL', 'INFO'),
        },
    },
}

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

settings.py
LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'formatters': {
        'verbose': {
            'format': '{levelname} {asctime} {module} {process:d} {thread:d} {message}',
            'style': '{',
        },
        'simple': {
            'format': '{levelname} {message}',
            'style': '{',
        },
    },
    'filters': {
        'special': {
            '()': 'project.logging.SpecialFilter',
            'foo': 'bar',
        },
        'require_debug_true': {
            '()': 'django.utils.log.RequireDebugTrue',
        },
    },
    'handlers': {
        'console': {
            'level': 'INFO',
            'filters': ['require_debug_true'],
            'class': 'logging.StreamHandler',
            'formatter': 'simple'
        },
        'mail_admins': {
            'level': 'ERROR',
            'class': 'django.utils.log.AdminEmailHandler',
            'filters': ['special']
        }
    },
    'loggers': {
        'django': {
            'handlers': ['console'],
            'propagate': True,
        },
        'django.request': {
            'handlers': ['mail_admins'],
            'level': 'ERROR',
            'propagate': False,
        },
        'myproject.custom': {
            'handlers': ['console', 'mail_admins'],
            'level': 'INFO',
            'filters': ['special']
        }
    }
}

Эта конфигурация выполняет следующее:

  • Указывает что конфигурация задана в формате „dictConfig версия 1“. На данный момент это единственная версия dictConfig формата.

  • Определяет два форматера:

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

      The format string is a normal Python formatting string describing the details that are to be output on each logging line. The full list of detail that can be output can be found in Formatter Objects.

    • verbose, выведет уровень логгирования, сообщение, время, название процесса, потока и модуля, который создал сообщение.

  • Определяет два фильтра:

    • project.logging.SpecialFilter с названием special. Если конструктор фильтра требует наличия дополнительных аргументов, вы можете указать их в словаре настройки фильтра. В этом случае будет передан аргумент foo со значением bar при создании экземпляра SpecialFilter.
    • django.utils.log.RequireDebugTrue – пропускает записи только в случае когда параметр конфигурации DEBUG равен True.
  • Определяет два обработчика:

    • console, a StreamHandler, which prints any INFO (or higher) message to sys.stderr. This handler uses the simple output format.
    • mail_admins, an AdminEmailHandler, which emails any ERROR (or higher) message to the site ADMINS. This handler uses the special filter.
  • Настраивает три логгера:

    • django, который перенаправляет все сообщения в обработчик console.
    • django.request, который передает все сообщения уровня ERROR в обработчик mail_admins. Также указывается, что логгер не должен передавать сообщения родительским логгерам. Это означает что сообщения переданные в django.request не будут обрабатываться логгером django.
    • myproject.custom, который передает все сообщения уровня INFO и выше прошедшие фильтр special в два обработчика – console и mail_admins. Это означает что все сообщения уровня INFO (или выше) будут отправлены в консоль, сообщения ERROR и CRITICAL будут отосланы через e-mail.

Собственная конфигурация логгирования

Если вы не хотите использовать формат dictConfig для настройки логгирования, вы можете определить собственный формат.

Параметр конфигурации LOGGING_CONFIG определяет функцию, которая настраивает логгирование в Django. По умолчанию, параметр указывает на logging.dictConfig(). Однако, если вы хотите переопределить настройку логгирования, укажите функцию, которая принимает один аргумент. Содержимое LOGGING будет передано в функцию при настройке логгирования.

Отключение настройки логгирования

Если вы вообще не желаете настраивать журналирование (или требуется самостоятельно настроить журналирование, используя собственный механизм2), вы можете установить LOGGING_CONFIG в None. Это отключит процесс настройки журналирования для случая по умолчанию. Здесь приведён пример отключения конфигурации журналирования Django и затем ручной её настройки:

settings.py
LOGGING_CONFIG = None

import logging.config
logging.config.dictConfig(...)

Установка LOGGING_CONFIG в None только означает, что процесс автоматической настройки отключен, это не влияет на само журналирование. Если вы отключите процесс конфигурации, Django все равно будет вызывать методы журналирования, используя поведение логгеров, настроенное по умолчанию.

Расширения для логгирования в Django

Django предоставляет набор утилит для решения стандартных задач логгирования в Web-приложениях.

Loggers(Логгеры)

Django предоставляет несколько встроенных логгеров.

django

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

django.request

Log messages related to the handling of requests. 5XX responses are raised as ERROR messages; 4XX responses are raised as WARNING messages. Requests that are logged to the django.security logger aren’t logged to django.request.

Сообщения этого логгера содержат дополнительные данные:

  • status_code: HTTP код ответа.
  • request: объект запроса, который спровоцировал сообщение.

django.server

Log messages related to the handling of requests received by the server invoked by the runserver command. HTTP 5XX responses are logged as ERROR messages, 4XX responses are logged as WARNING messages, and everything else is logged as INFO.

Сообщения этого логгера содержат дополнительные данные:

  • status_code: HTTP код ответа.
  • request: объект запроса, который спровоцировал сообщение.

django.template

Записывает логи связанные с рендерингом шаблонов.

  • Отсутствие переменной шаблона записывается как DEBUG сообщение.

django.db.backends

Сообщения связанные с взаимодействием кода с базой данной. Например, каждый SQL запрос создает DEBUG сообщение в этот логер.

Сообщения этого логгера содержат дополнительные данные:

  • duration: Время выполнения SQL запроса.
  • sql: SQL запрос.
  • params: Параметры используемые при выполнении SQL запроса.

Для повышения производительности логгирование SQL запросов включено только при settings.DEBUG равном True, независимо от уровня логгирования и назначенных обработчиков.

Это логгирование не включает запросы, выполняемые при инициализации приложения (например, SET TIMEZONE), или запросы управления транзакциями (такие как BEGIN, COMMIT и ROLLBACK). Используйте логгирование на уровне базы данных, если вы хотите записывать все запросы.

django.security.*

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

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

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

'handlers': {
    'null': {
        'class': 'logging.NullHandler',
    },
},
'loggers': {
    'django.security.DisallowedHost': {
        'handlers': ['null'],
        'propagate': False,
    },
},

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 by the migrations framework. Note that it won’t log the queries executed by RunPython. Messages to this logger have params and sql in their extra context (but unlike django.db.backends, not duration). The values have the same meaning as explained in django.db.backends.

Handlers(Обработчики)

Django предоставляет один дополнительный обработчик.

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

This handler sends an email to the site ADMINS for each log message it receives.

If the log record contains a request attribute, the full details of the request will be included in the email. The email subject will include the phrase «internal IP» if the client’s IP address is in the INTERNAL_IPS setting; if not, it will include «EXTERNAL IP».

Если сообщение содержит стек трассировки(пер. stack trace information), он будет включен в e-mail.

The include_html argument of AdminEmailHandler is used to control whether the traceback email includes an HTML attachment containing the full content of the debug Web page that would have been produced if DEBUG were True. To set this value in your configuration, include it in the handler definition for django.utils.log.AdminEmailHandler, like this:

'handlers': {
    'mail_admins': {
        'level': 'ERROR',
        'class': 'django.utils.log.AdminEmailHandler',
        'include_html': True,
    }
},

Заметим, что HTML версия письма содержит полный трейсбек с названиями и значениями локальных переменных на каждом уровне стека, а также значения настроек Django. Эта информация потенциально очень важна и возможно вы не захотите отправлять её через электронную почту. Рекомендуется использовать что-то вроде django-sentry, чтобы получить все преимущества – полная информация c трейсбеком и отсутствие отправки важной информации через электронную почту. Вы можете также явно указать фильтрацию важной информации – подробнее в разделе о фильтрации отчетов об ошибках.

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

'handlers': {
    'mail_admins': {
        'level': 'ERROR',
        'class': 'django.utils.log.AdminEmailHandler',
        'email_backend': 'django.core.mail.backends.filebased.EmailBackend',
    }
},

По умолчанию используется экземпляр класса, указанного в EMAIL_BACKEND.

The reporter_class argument of AdminEmailHandler allows providing an django.views.debug.ExceptionReporter subclass to customize the traceback text sent in the email body. You provide a string import path to the class you wish to use, like this:

'handlers': {
    'mail_admins': {
        'level': 'ERROR',
        'class': 'django.utils.log.AdminEmailHandler',
        'include_html': True,
        'reporter_class': 'somepackage.error_reporter.CustomErrorReporter'
    }
},
New in Django 3.0:

The reporter_class argument was added.

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

Отправляет сообщения по электронной почте администраторам. Для изменения этого поведения следует унаследовать класс AdminEmailHandler и переопределить данный метод.

Filters(Фильтры)

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

class CallbackFilter(callback)

Этот фильтр принимает функцию (которая должна принимать один аргумент - логгированное сообщение), и вызывает ее для каждого переданного сообщения. Сообщение не будет обработано если функция вернет False.

Например, для исключения из писем информации об исключении UnreadablePostError (выбрасывается, когда пользователь прерывает загрузку файла), вы можете создать функцию фильтрации:

from django.http import UnreadablePostError

def skip_unreadable_post(record):
    if record.exc_info:
        exc_type, exc_value = record.exc_info[:2]
        if isinstance(exc_value, UnreadablePostError):
            return False
    return True

and then add it to your logging config:

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

Этот фильтр работает только если настройка DEBUG равна False.

This filter is used as follows in the default LOGGING configuration to ensure that the AdminEmailHandler only sends error emails to admins when DEBUG is False:

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

Этот фильтр аналогичен RequireDebugFalse за исключением того, что он пропускает записи только в случае когда параметр конфигурации DEBUG равен True.

Стандартная конфигурация логгирования

По умолчанию, Django настраивает следующую конфигурацию журналирования:

Если DEBUG равна True:

  • The django logger sends messages in the django hierarchy (except django.server) at the INFO level or higher to the console.

Если DEBUG установлен в False:

  • The django logger sends messages in the django hierarchy (except django.server) with ERROR or CRITICAL level to AdminEmailHandler.

Independent of the value of DEBUG:

  • The django.server logger sends messages at the INFO level or higher to the console.

All loggers except django.server propagate logging to their parents, up to the root django logger. The console and mail_admins handlers are attached to the root logger to provide the behavior described above.

See also Configuring logging to learn how you can complement or replace this default logging configuration defined in django/utils/log.py.