Логирование в Django. Правильный путь
Правильное ведение логирования играет решающее значение для процесса отладки и устранения неполадок. Оно не только полезно для локального девелопменга, но и для продашен. При просмотре журналов в поиске проблемы, редко кто-то говорит: "Наше приложение слишком много логирует." Но чаще можно услышать иное. Итак, принимая это во внимание, давайте начнем.
Введение в логирование на Python
В верхней части каждого файла должно быть что-то подобное:
import logging
logger = logging.getLogger(__name__)
Переменная name будет заменена точечным путём до Python модуля, например, скрипт myproject/myapp/views.py, то будет использоваться myproject.myapp.views. Теперь можно применять logger по всему файлу:
# Простая строка, зарегистрированная на уровне «warning»
logger.warning("Your log message is here")
# Строка с переменной на уровне «info»
logger.info("The value of var is %s", var)
# Ведение журнала трассировки для пойманного исключения
try:
function_that_might_raise_index_error()
except IndexError:
# эквивалентно logger.error(msg, exc_info=True)
logger.exception("Something bad happened")
Примечание: логеры в Python будут обрабатывать вставки переменных в сообщение журнала, если передать их в качестве аргументов в функцию логирования. Если не требуется выводить журнал, замена переменной производиться не будет, что поможет избежать небольшого падения производительности для журнала, который никогда не будет использоваться.
Перепишите свой код с помощью операторов логирования. Краткие рекомендации для выбора уровней журналирования:
- debug. Информация не нужна для повседневной работы, но полезна в разработке.
- info: Информация, которая полезна во время обычной работы.
- warning: Информация, которая может быть проблематичной, но не является срочной.
- error: Информация, которая важна и, вероятно, требует срочного внимания.
- critical: на практике используется редко, но если вам нужно больше, чем ошибка, то это то что нужно.
Куда логировать
Ваше приложение не должно беспокоиться о том, куда идут log сообщения. Вместо этого оно должно записывать все в консоль (stdout / stderr), и пусть сервер сам решает, что дальше делать с этой информацией. Обычно они помещаются в выделенный файл, захваченный журналом Systemd или Docker, с последующей отправкой на отдельный сервис, такой как ElasticSearch, или некоторое их сочетание. Хранение файлов журналов – это задача развертывания, а не приложения.
Единственное, что нужно вашему приложению – это формат журналов. Обычно это всего лишь строка с соответствующими данными, но если ваш сервер уже добавляет отметку времени в журнал, то вероятно, нужно будет исключить ее из своего собственного форматирования. Аналогично, если ваш агрегатор журналов может принимать JSON, возможно, более подходящим является форматирование, такое как python-json-logger.
Конфигурирование логирования. Настройка Sentry
Служба отчетов об ошибках играют решающее значение для любого нетривиального сайта. По умолчанию они хранят необработанные исключения, уведомляя о проблеме (только один раз за инцидент) и предоставляют удобный интерфейс для просмотра состояния приложения, когда возникло исключение. Примером такого сервиса может быть Sentry.
Настроим Sentry, отправив любые сообщения службы в журнал, уровня warning или выше. В противном случае они были бы потеряны в море журнальных файлов, которые на практике редко проверяются. Для этого добавим «корневой» журнал, который будет использоваться для всех log сообщений, которые отправляются из любого модуля Python. Пример настройки Django:
import logging.config
LOGGING_CONFIG = None
logging.config.dictConfig({
'version': 1,
'disable_existing_loggers': False,
'formatters': {
'console': {
# точный формат не важен, это минимальная информация
'format': '%(asctime)s %(name)-12s %(levelname)-8s %(message)s',
},
},
'handlers': {
'console': {
'class': 'logging.StreamHandler',
'formatter': 'console',
},
# Добавить обработчик для Sentry для `warning` и выше
'sentry': {
'level': 'WARNING',
'class': 'raven.contrib.django.raven_compat.handlers.SentryHandler',
},
},
'loggers': {
# корневой логгер
'': {
'level': 'WARNING',
'handlers': ['console', 'sentry'],
},
},
})
Логирование из приложения
Как правило требуется сведения о предупреждениях и ошибках о сторонних зависимостей, но, как правило, требуется гораздо глубокое понимание кода приложения. В идеале, код целиком живет в одном пространстве имён, чтобы его можно было охватить одним логером. Предположим, что проект использует пространство имен myproject, основываясь на коде выше.
logging.config.dictConfig({
# ...
'loggers': {
'': {
'level': 'WARNING',
'handlers': ['console', 'sentry'],
},
'myproject': {
'level': 'INFO',
'handlers': ['console', 'sentry'],
# требуется, чтобы избежать двойного ведения журнала с помощью корневого логгера
'propagate': False,
},
},
})
Как быть, если нудно исследовать что-то в своем приложении глубже, чем debug уровень журналированя? Коммит нового кода и его развертывая ощущается излишним. Лучшим вариантом в этом случае воспользоваться переменной окружения среды. Модифицируем предыдущий код, приведя к такому виду:
import os
LOGLEVEL = os.environ.get('LOGLEVEL', 'info').upper()
logging.config.dictConfig({
# ...
'loggers': {
'': {
'level': 'WARNING',
'handlers': ['console', 'sentry'],
},
'myproject': {
'level': LOGLEVEL,
'handlers': ['console', 'sentry'],
# требуется, чтобы избежать двойного ведения журнала с помощью корневого регистратора
'propagate': False,
},
},
})
Теперь ведение журнала по умолчанию будет info, но может быть легко временно изменено, установив переменную среды LOGLEVEL = debug. В качестве альтернативы, если хранилище журналов не является проблемой, учитывайте возможность ведения журнала на уровне debug. Их достаточно легко отфильтровать с помощью простого grep или с помощью инструмента визуализации журнала, например, Kibana.
Отфильтровывание шума
После того, как установлено и запущено логирование, может появляться информация о некоторых модулях, которые не являются важными, продуцирующими дополнительный шум в журнальные файлы. Для таких модулей можно добавить еще один регистратор в настройки. Первый вариант заключается в том, чтобы вывести их на консоль, но не распространять их на корневой журнал, который отправит их в Sentry:
logging.config.dictConfig({
# ...
'loggers': {
'': {
'level': 'WARNING',
'handlers': ['console', 'sentry'],
},
'myproject': {
'level': LOGLEVEL,
'handlers': ['console', 'sentry'],
# требуется, чтобы избежать двойного ведения журнала с помощью корневого регистратора
'propagate': False,
},
# Не отправляйте журналы этого модуля в Sentry
'noisy_module': {
'level':'ERROR',
'handlers': ['console'],
'propagate': False,
},
},
})
Если обнаружится, что они слишком шумные, даже для консоли, можно полностью отказаться от них логирования:
logging.config.dictConfig({
# ...
'loggers': {
# ...
# Не логгировать этот модуль
'noisy_module': {
'level': 'NOTSET',
'propagate': False,
},
},
})
Логирование локальный запросов
По умолчанию в Django будет выполняться журналирование запросов с runserver. Переопределяя конфигурацию Django происходит потеря этой возможности. Но её достаточно легко добавить:
from django.utils.log import DEFAULT_LOGGING
logging.config.dictConfig({
# ...
'formatters': {
# ...
'django.server': DEFAULT_LOGGING['formatters']['django.server'],
},
'handlers' {
# ...
'django.server': DEFAULT_LOGGING['handlers']['django.server'],
},
'loggers': {
# ...
'django.server': DEFAULT_LOGGING['loggers']['django.server'],
},
})
Этот метод немного хрупкий, поскольку зависит от некоторых внутренних компонентов, которые могут меняться между версиями, но поломки легко исправить используя прямое копирование/вставку из исходников Django.