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

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

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 настройки LOGGING равен True (по умолчанию), стандартные настройки будут переопределены. Чтобы переопределить определенные логеры, установите disable_existing_loggers в False.

Журналирование настраивается сразу после загрузки настроек (вручную с помощью 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, независимо от уровня логирования и назначенных обработчиков.

django.security.*

Этот логер получает сообщения о появлении исключения SuspiciousOperation. Есть подлогеры для всех типов SuspiciousOperation. Уровень сообщения зависит от того, где обрабатывается исключение. Обычно это сообщения уровня предупреждения. SuspiciousOperation достигшие WSGI обработчика будут логированны как ошибки. Например, если HTTP Host заголовок указанный клиентом не соответствует ALLOWED_HOSTS, Django вернет 400 ответ и ошибка будет логирована в django.security.DisallowedHost.

По умолчанию настроен только django.security логер и все дочерние логеры передают ему сообщения. django.security настроен так же, как и django.request, и все ошибки будут отправлены администраторам через email. Запросы с 400 ответом, вызванным исключением``SuspiciousOperation``, не будут обработаны логером django.request, а только django.security.

Чтобы игнорировать определенные типы SuspiciousOperation, вы можете переопределить логер следующим образом:

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

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

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

class AdminEmailHandler(include_html=False, email_backend=None)

Этот логер отсылает 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 трейсбеком и отсутствие отправки важной информации через электронную почту. Вы можете также явно указать фильтрацию важной информации – подробнее в разделе о фильтрации отчетов об ошибках.

New in Django 1.6.

Через параметр email_backend класса AdminEmailHandler, можно переопределить бекенд отправки email:

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

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

Filters(Фильтры)

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

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

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

'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.

Этот фильтр используется в конфигурации 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
New in Django 1.5.

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

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

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

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

Changed in Django 1.5:

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

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