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

Быстрое руководство по ведению журнала

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

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

Настройка ведения журнала Python состоит из четырёх частей:

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

Логгеры

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

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

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

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

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

После того, как логгер определил, что сообщение необходимо обработать, оно передаётся обработчику.

Обработчики

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

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

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

Фильтры

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

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

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

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

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

В конечном итоге, запись журнала должна быть представлена в виде текста. Форматировщики описывают точный формат этого текста. Форматировщик обычно состоит из строки форматирования 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__, имя модуля 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.security, не основанные на SuspiciousOperation:

• django.security.csrf: Для ошибок CSRF.

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 отправляет сообщения в иерархии django (кроме django.server) на уровне INFO или выше в консоль.

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

• Логгер django отправляет сообщения в иерархии django (кроме django.server) на уровне ERROR или CRITICAL в AdminEmailHandler.

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

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

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