Ведение журнала

Быстрый обзор ведения журнала

Django использует встроенный модуль Python logging для выполнения системного ведения журнала. Использование этого модуля подробно описано в документации Python. Однако, если вы никогда не использовали фреймворк ведения журнала Python (или даже если использовали), вот быстрый обзор.

Участники процесса

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

• Логгеры
• Обработчики
• Фильтры
• Форматировщики

Логгеры

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

Логгер настроен на уровень журнала. Этот уровень журнала описывает уровень важности сообщений, которые будет обрабатывать логгер. Python определяет следующие уровни журнала:

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

Каждое сообщение, которое записывается в логгер, — это Запись журнала. Каждая запись журнала также имеет уровень журнала, указывающий на серьезность этого конкретного сообщения. Запись журнала также может содержать полезные метаданные, описывающие событие, которое регистрируется. Это может включать такие детали, как стек вызовов или код ошибки.

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

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

Обработчики

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

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

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

Фильтры

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

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

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

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

Форматировщики

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

Использование ведения журнала

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

# 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__, имя модуля Python, содержащего логгер. Это позволяет фильтровать и обрабатывать вызовы ведения журнала на основе каждого модуля. Однако, если у вас есть какой-либо другой способ организации сообщений ведения журнала, вы можете указать любое имя, разделённое точками, для идентификации логгера:

# 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.debug()
• logger.info()
• logger.warning()
• logger.error()
• logger.critical()

Доступны ещё два вызова ведения журнала:

• logger.log(): Ручная отправка сообщения ведения журнала с заданным уровнем журнала.
• logger.exception(): Создание сообщения ведения журнала уровня ERROR, содержащего текущий стек исключений.

Настройка ведения журнала

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

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

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

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

Если ключ disable_existing_loggers в словаре LOGGING установлен в True (по умолчанию), то все логгеры из стандартной конфигурации будут отключены. Отключенные логгеры не то же самое, что удалённые; логгер всё ещё существует, но молча игнорирует всё, что регистрируется в нём, даже не передавая записи родительскому логгеру. Поэтому вы должны быть очень осторожны при использовании 'disable_existing_loggers': True; это, вероятно, не то, что вам нужно. Вместо этого вы можете установить disable_existing_loggers в False и переопределить некоторые или все стандартные логгеры; или вы можете установить LOGGING_CONFIG в None и ручно обработать конфигурацию ведения журнала.

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

Примеры

Полная документация по формату dictConfig — лучший источник информации о словарях конфигурации ведения журнала. Однако, чтобы дать вам представление о том, что возможно, вот несколько примеров.

Сначала вот простая конфигурация, которая записывает все логи логгера django в локальный файл:

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,
        },
    },
}

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

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

По умолчанию эта конфигурация отправляет в консоль только сообщения уровня INFO и выше (так же, как и стандартная конфигурация ведения журнала Django, за исключением того, что стандартная отображает записи журнала, только когда уровень журнала DEBUG=True). Django не регистрирует много таких сообщений. Однако с этой конфигурацией вы также можете установить переменную окружения DJANGO_LOG_LEVEL=DEBUG, чтобы увидеть все дебаг-логи Django, которые очень подробны, так как включают все запросы к базе данных:

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'),
        },
    },
}

Наконец, вот пример достаточно сложной настройки ведения журнала:

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    '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',
        },
        '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 version 1». В настоящее время это единственный формат версии dictConfig.

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

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

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

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

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

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

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

  • console, StreamHandler, который будет выводить любое INFO (или более высокое) сообщение в stderr. Этот обработчик использует формат вывода simple.
  • mail_admins, AdminEmailHandler, который будет отправлять электронное письмо с любым ERROR (или более высоким) сообщением администраторам сайта. Этот обработчик использует фильтр special.

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

  • django, который передает все сообщения обработчику console.
  • django.request, который передает все ERROR сообщения обработчику mail_admins. Кроме того, этот логгер помечен как не передающий сообщения. Это означает, что сообщения журнала, написанные в django.request, не будут обрабатываться логгером django.
  • myproject.custom, который передает все сообщения уровня INFO или выше, которые также проходят фильтр special, двум обработчикам — console и mail_admins. Это означает, что все сообщения уровня INFO (или выше) будут выведены в консоль; сообщения уровня ERROR и CRITICAL также будут выведены по электронной почте.

Настройка ведения журнала

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

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

Отключение конфигурации ведения журнала

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

LOGGING_CONFIG = None

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

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

Расширения ведения журнала Django

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

Логгеры

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

django

django — универсальный логгер. Сообщения не публикуются напрямую в этот логгер.

django.request

Сообщения журнала, связанные с обработкой запросов. Ответы 5XX поднимаются как сообщения ERROR; ответы 4XX поднимаются как сообщения WARNING.

Сообщения в этом логгере имеют следующий контекст:

• status_code: Код HTTP-ответа, связанный с запросом.
• request: Объект запроса, который сгенерировал сообщение журнала.

django.server

Сообщения журнала, связанные с обработкой запросов, полученных сервером, вызванным командой runserver. Ответы HTTP 5XX регистрируются как сообщения ERROR, 4XX ответы регистрируются как WARNING сообщения, а все остальное регистрируется как INFO.

Сообщения в этом логгере имеют следующий контекст:

• status_code: Код HTTP-ответа, связанный с запросом.
• request: Объект запроса, который сгенерировал сообщение журнала.

django.template

Сообщения журнала, связанные с рендерингом шаблонов.

• Отсутствующие переменные контекста регистрируются как сообщения DEBUG.
• Необработанные исключения, возникающие во время рендеринга {% include %}, регистрируются как сообщения WARNING при выключенном режиме отладки (полезно, так как {% include %} подавляет исключение и возвращает пустую строку в этом случае).

django.db.backends

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

Сообщения в этом логгере имеют следующий контекст:

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

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

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

django.security.*

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

Эти события лога по умолчанию попадают в логгер «django», который отправляет события об ошибках администраторам, когда DEBUG=False. Запросы, приводящие к ответу 400 из-за SuspiciousOperation, не будут записываться в логгер django.request, а только в логгер django.security.

Чтобы отключить определенный тип SuspiciousOperation, можно переопределить соответствующий логгер, следуя этому примеру:

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

django.db.backends.schema

Регистрирует SQL-запросы, выполняемые во время изменений схемы в базе данных с помощью фреймворка миграций. Обратите внимание, что это не будет регистрировать запросы, выполняемые с помощью RunPython. Сообщения в этом логгере имеют params и sql в дополнительном контексте (но, в отличие от django.db.backends, не длительности). Значения имеют тот же смысл, что и в django.db.backends.

Обработчики

Django предоставляет один обработчик журнала в дополнение к тем, которые предоставляются модулем Python logging.

class AdminEmailHandler(include_html=False, email_backend=None) [source]

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

Если запись журнала содержит атрибут request, полные данные запроса будут включены в письмо. В теме письма будет указана фраза «внутренний IP», если IP-адрес клиента находится в настройке INTERNAL_IPS; в противном случае будет указана фраза «внешний IP».

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

Аргумент include_html в AdminEmailHandler используется для управления включением в отслеживаемое по почте исключение HTML-приложения, содержащего полное содержимое страницы отладки веб-сайта, которая была бы создана, если бы настройка DEBUG была True. Для установки этого значения в вашей конфигурации включите его в определение обработчика для django.utils.log.AdminEmailHandler, как показано ниже:

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

Обратите внимание, что этот HTML-вариант письма содержит полный стек вызовов с именами и значениями локальных переменных на каждом уровне стека, а также значениями настроек Django. Эта информация может быть очень чувствительной, и вы можете не захотеть отправлять её по электронной почте. Рассмотрите использование инструмента, такого как Sentry, чтобы получить лучшее из обоих миров — богатую информацию полных стеков вызовов плюс безопасность, позволяющую не отправлять эту информацию по электронной почте. Вы также можете явно указать определённую чувствительную информацию для фильтрации из отчетов об ошибках — подробнее об этом на странице Фильтрация отчетов об ошибках.

Указав аргумент email_backend в AdminEmailHandler, можно переопределить почтовый бэкенд, используемый обработчиком, как показано ниже:

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

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

send_mail(subject, message, *args, **kwargs) [source]

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

Фильтры

Django предоставляет два фильтра журнала в дополнение к тем, которые предоставляет модуль Python logging.

class CallbackFilter(callback) [source]

Этот фильтр принимает функцию обратного вызова (которая должна принимать один аргумент — запись, подлежащую регистрации) и вызывает её для каждой записи, которая проходит через фильтр. Обработка этой записи не продолжится, если функция обратного вызова вернёт 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 [source]

Этот фильтр пропускает записи только тогда, когда значение настройки settings.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 [source]

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

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

По умолчанию Django настраивает следующее логгирование:

Когда DEBUG равно True:

• Логгер django (глобальный логгер) отправляет все сообщения уровня INFO или выше на консоль.

Когда DEBUG равно False:

• Логгер django отправляет сообщения уровня ERROR или CRITICAL в AdminEmailHandler.

Независимо от значения DEBUG:

• Логгер django.server отправляет все сообщения уровня INFO или выше на консоль.

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