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

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

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, но вы так же можете создать собственный класс форматера.

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

После настройки логеров, обработчиков, фильтров и форматеров, добавим логирование в наш код. Использовать логирование очень просто. Вот небольшой пример:

# 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() возвращает (создает при необходимости) экземпляр логера. Экземпляру логера может назначить имя. Это имя используется при настройке журналирования.

Для удобства обычно используется __name__ в качестве названия – название модуля, который содержит логер. Это позволяет вам управлять логированием на уровне модулей. Однако, если вы используете другую систему организации сообщений, вы может использовать любое составное название, разделенное точками:

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

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

Почему иерархия так важна? Потому что логеры могут быть настроены на передачу сообщений родительским логерам. Таким образом вы можете определить один обработчик для корневого логера и обрабатывать сообщения ко всем дочерним логерам. Обработчик назначенный логеру project будет обрабатывать сообщения к project.interesting и project.interesting.stuff.

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

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

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

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

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

  • logger.log(): отправить сообщение с указанным уровнем логирования

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

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

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

Библиотека логирования Python предоставляет несколько способов настроить логирования – от программного интерфейса и до конфигурационных файлов. По умолчанию Django использует dictConfig формат.

Примечание

Библиотека logging.dictConfig встроена в Python 2.7. Для того, чтобы предоставить доступ к библиотеке для пользователей других версий Python, Django содержит копию в django.utils.log. Если вы используете Python 2.7, будет использоваться системная версия модуля. Если вы используете Python 2.6 и ниже, будет использоваться копия модуля из Django.

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

До Django 1.5 параметр конфигурации LOGGING перезаписывал стандартные настройки журналирования Django. Начиная с Django 1.5, конфигурация журналирования объединяется стандартные настройки Django, следовательно, вы можете решать добавлять или заменять параметры существующей конфигурации. Для того, чтобы полностью переопределить стандартную конфигурацию, сделайте disable_existing_loggers равным True в параметре конфигурации LOGGING. Аналогично вы можете переопределить некоторые или все логеры.

Журналирование настраивается сразу после загрузки настроек (вручную с помощью configure() или при первом доступе к конфигурации журналирования). Так как настройки загружаются в первую очередь, вы можете быть уверены, что журналирование уже работает при запуске вашего кода.

Пример

Официальная документация формата dictConfig лучше всего описывает формат словаря конфигурации журналирования. Однако, чтобы показать вам её возможности, мы приведем пример достаточно сложной настройки журналирования с использованием logging.dictConfig():

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

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

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

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

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

    • simple, просто возвращает уровень логирования сообщения (например, DEBUG) и содержимое сообщения.

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

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

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

  • Определяет три обработчика:

    • null, NullHandler, который отправляет все сообщения уровня DEBUG (или выше) в /dev/null.

    • console, StreamHandler, который перенаправляет все сообщения уровня DEBUG (и выше) в stderr. Этот обработчик использует формат simple.

    • mail_admins, AdminEmailHandler, который отправляет e-mail с сообщением уровня ERROR (и выше) администраторам сайта. Этот обработчик использует фильтр special.

  • Настраивает три логера:

    • django, который перенаправляет все сообщения уровня INFO и выше в обработчик null.

    • 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 будет передано в функцию при настройке журналирования.

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

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

Примечание

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

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

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

Loggers(Логеры)

Django использует три логера.

django

django – логер принимающий все сообщения. Сообщения не записываются непосредственно в этот логер.

django.request

Принимает сообщения связанные с процессом обработки запросов. 5XX ответы отправляют ERROR сообщения, 4XX ответы – WARNING сообщения.

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

  • status_code: HTTP код ответа.

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

django.db.backends

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

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

  • duration: Время выполнения SQL запроса.

  • sql: SQL запрос.

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

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

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

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

class AdminEmailHandler([include_html=False])

Этот логер отсылает e-mail администраторам сайта с принятый сообщением.

Если сообщение содержит атрибут request, полная информация о запросе будет включена в e-mail.

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

Параметр include_html в AdminEmailHandler указывает будет ли e-mail содержать HTML содержимое debug-страницы, которая была бы создана при DEBUG равном True. Что бы установить этот параметр, укажите его в словаре конфигурации django.utils.log.AdminEmailHandler, например так:

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

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

Filters(Фильтры)

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

class CallbackFilter(callback)
Добавлено в Django 1.4.

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

и затем добавить её в свою конфигурацию журналирования:

'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
Добавлено в Django 1.4.

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

Этот фильтр используется в конфигурации LOGGING по-умолчанию, чтобы предотвратить отсылку писем обработчиком AdminEmailHandler если настройка DEBUG не равна 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
Добавлено в Django 1.5.

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

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

По умолчанию, Django настраивает логгер для django.request, так что все сообщения уровня ERROR или CRITICAL будут отправлены в AdminEmailHandler. Такое поведение имеет место быть только когда параметр конфигурации DEBUG равен False.

Все сообщения, достигающие глобального логгера django, при параметре конфигурации DEBUG равным True, отправляются на консоль. При DEBUG равном False они просто игнорируются (точнее отправляются в NullHandler).

Изменено в Django 1.5:

Before Django 1.5, all messages reaching the django logger were discarded, regardless of DEBUG.

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