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

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

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.request в локальный файл:

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'handlers': {
        'file': {
            'level': 'DEBUG',
            'class': 'logging.FileHandler',
            'filename': '/path/to/django/debug.log',
        },
    },
    'loggers': {
        'django.request': {
            'handlers': ['file'],
            'level': 'DEBUG',
            'propagate': True,
        },
    },
}

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

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

По умолчанию эта конфигурация отправляет сообщения уровня INFO и выше в консоль. 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, который будет выводить любое сообщение DEBUG (или выше) в 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.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.security, и все дочерние логгеры будут передавать сообщения родительскому логгере. Логгер django.security настроен так же, как и логгер django.request, и любые события об ошибках будут отправлены администраторам по электронной почте. Запросы, приводящие к ответу 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.

Обработчики

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 (обработчик всех сообщений) отправляет все сообщения уровня WARNING или выше в консоль. Django не выполняет такие действия по логгированию в данный момент (все логгирование выполняется на уровне DEBUG или обрабатывается логгерами django.request и django.security).
• Логгер py.warnings (обработчик сообщений из warnings.warn()), отправляет сообщения в консоль.

Когда DEBUG имеет значение False:

• Логгеры django.request и django.security отправляют сообщения уровня ERROR или CRITICAL в AdminEmailHandler. Эти логгеры игнорируют сообщения уровня WARNING и ниже, и записи не распространяются на другие логгеры (они не достигнут логгера django даже когда DEBUG имеет значение True).

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