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

Когда использовать ведение журнала¶

Вы можете получить доступ к функциям ведения журнала, создав программу ведения журнала с помощью logger = getLogger(__name__), а затем вызвав методы ведения журнала debug(), info(), warning(), error() и critical(). Чтобы определить, когда следует использовать ведение журнала, и посмотреть, какие методы ведения журнала следует использовать, ознакомьтесь с таблицей ниже. В ней для каждой из распространенных задач указывается наилучший инструмент, который можно использовать для этой задачи.

Методы ведения журнала названы в честь уровня или серьезности событий, которые они используются для отслеживания. Стандартные уровни и их применимость описаны ниже (в порядке возрастания серьезности).:

Уровень по умолчанию - WARNING, что означает, что будут отслеживаться только события этого уровня и выше, если только пакет ведения журнала не настроен на иное.

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

Простой пример¶

Очень простым примером является:

import logging
logging.warning('Watch out!')  # will print a message to the console
logging.info('I told you so')  # will not print anything

Если вы введете эти строки в скрипт и запустите его, вы увидите:

WARNING:root:Watch out!

распечатывается на консоли. Сообщение INFO не отображается, поскольку уровень по умолчанию равен WARNING. Напечатанное сообщение содержит указание уровня и описание события, приведенное в протоколе вызова, т.е. «Осторожно!». Фактические выходные данные могут быть отформатированы достаточно гибко, если вам это нужно; параметры форматирования также будут объяснены позже.

Обратите внимание, что в этом примере мы используем функции непосредственно в модуле logging, например, logging.debug, вместо того, чтобы создавать регистратор и вызывать в нем функции. Эти функции работают в корневом регистраторе, но могут быть полезны, поскольку они вызовут basicConfig() для вас, если он еще не был вызван, как в этом примере. Однако в более крупных программах вам обычно требуется явно управлять конфигурацией ведения журнала, поэтому по этой причине, а также по другим причинам, лучше создавать регистраторы и вызывать их методы.

Запись в файл¶

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

import logging
logger = logging.getLogger(__name__)
logging.basicConfig(filename='example.log', encoding='utf-8', level=logging.DEBUG)
logger.debug('This message should go to the log file')
logger.info('So should this')
logger.warning('And this, too')
logger.error('And non-ASCII stuff, too, like Øresund and Malmö')

И теперь, если мы откроем файл и посмотрим, что у нас есть, мы должны найти сообщения журнала:

DEBUG:__main__:This message should go to the log file
INFO:__main__:So should this
WARNING:__main__:And this, too
ERROR:__main__:And non-ASCII stuff, too, like Øresund and Malmö

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

Если вы хотите установить уровень ведения журнала с помощью параметра командной строки, например:

--log=INFO

и у вас есть значение параметра, переданного для --log в некоторой переменной loglevel, вы можете использовать:

getattr(logging, loglevel.upper())

чтобы получить значение, которое вы передадите в basicConfig() с помощью аргумента level. Возможно, вы захотите проверить на ошибку любое введенное пользователем значение, возможно, как в следующем примере:

# assuming loglevel is bound to the string value obtained from the
# command line argument. Convert to upper case to allow the user to
# specify --log=DEBUG or --log=debug
numeric_level = getattr(logging, loglevel.upper(), None)
if not isinstance(numeric_level, int):
    raise ValueError('Invalid log level: %s' % loglevel)
logging.basicConfig(level=numeric_level, ...)

Вызов basicConfig() должен выполняться до любых вызовов методов регистратора, таких как debug(), info(), и т.д. В противном случае это событие регистрации может быть обработано не так, как требуется.

Если вы запустите описанный выше скрипт несколько раз, сообщения о последовательных запусках будут добавлены в файл example.log. Если вы хотите, чтобы каждый запуск начинался заново, не запоминая сообщения из предыдущих запусков, вы можете указать аргумент filemode, изменив вызов в приведенном выше примере на:

logging.basicConfig(filename='example.log', filemode='w', level=logging.DEBUG)

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

Ведение журнала переменных данных¶

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

import logging
logging.warning('%s before you %s', 'Look', 'leap!')

будет отображаться:

WARNING:root:Look before you leap!

Как вы можете видеть, при объединении переменных данных в сообщении с описанием события используется старое форматирование строк в %-ном стиле. Это сделано для обеспечения обратной совместимости: пакет ведения журнала поддерживает более новые параметры форматирования, такие как str.format() и string.Template. Эти новые параметры форматирования поддерживаются, но их изучение выходит за рамки данного руководства: смотрите Использование определенных стилей форматирования в вашем приложении для получения дополнительной информации.

Изменение формата отображаемых сообщений¶

Чтобы изменить формат, используемый для отображения сообщений, вам необходимо указать формат, который вы хотите использовать:

import logging
logging.basicConfig(format='%(levelname)s:%(message)s', level=logging.DEBUG)
logging.debug('This message should appear on the console')
logging.info('So should this')
logging.warning('And this, too')

который будет печатать:

DEBUG:This message should appear on the console
INFO:So should this
WARNING:And this, too

Обратите внимание, что «корень», который появлялся в предыдущих примерах, исчез. Для получения полного набора параметров, которые могут отображаться в строках формата, вы можете обратиться к документации для Атрибуты записи журнала, но для простого использования вам просто нужны имяуровня (серьезность), сообщение (описание события, включая переменные данные) и, возможно, для отображения, когда событие произошло. Это описано в следующем разделе.

Отображение даты/времени в сообщениях¶

Чтобы отобразить дату и время события, вы должны поместить «%(asctime)s» в строку вашего формата:

import logging
logging.basicConfig(format='%(asctime)s %(message)s')
logging.warning('is when this event was logged.')

который должен напечатать что-то вроде этого:

2010-12-12 11:41:42,612 is when this event was logged.

Формат отображения даты и времени по умолчанию (показанный выше) соответствует стандарту ISO8601 или RFC 3339. Если вам нужно больше контролировать форматирование даты/времени, укажите аргумент datefmt в basicConfig, как в этом примере:

import logging
logging.basicConfig(format='%(asctime)s %(message)s', datefmt='%m/%d/%Y %I:%M:%S %p')
logging.warning('is when this event was logged.')

который отображал бы что-то вроде этого:

12/12/2010 11:46:36 AM is when this event was logged.

Формат аргумента datefmt такой же, как и в time.strftime().

следующие шаги¶

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

Если ваши потребности в ведении журнала просты, то используйте приведенные выше примеры, чтобы включить ведение журнала в свои собственные скрипты, а если у вас возникнут проблемы или вы чего-то не поймете, пожалуйста, задайте вопрос в группе comp.lang.python Usenet (доступна по адресу https://groups.google.com/g/comp.lang.python), и вы скоро получите помощь.

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

Поток ведения журнала¶

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

Лесорубы¶

Logger объекты выполняют три задачи. Во-первых, они предоставляют несколько методов коду приложения, чтобы приложения могли регистрировать сообщения во время выполнения. Во-вторых, объекты-регистраторы определяют, с какими сообщениями журнала следует действовать, исходя из серьезности (средство фильтрации по умолчанию) или объектов-фильтров. В-третьих, объекты регистратора передают соответствующие сообщения журнала всем заинтересованным обработчикам журналов.

Наиболее широко используемые методы работы с объектами регистратора делятся на две категории: настройка и отправка сообщений.

Это наиболее распространенные методы настройки:

• Logger.setLevel() указывает лог-сообщение с наименьшей степенью серьезности, которое будет обрабатываться средством ведения журнала, где debug - это самый низкий встроенный уровень серьезности, а critical - самый высокий встроенный уровень серьезности. Например, если уровень серьезности равен INFO, то регистратор будет обрабатывать только информационные сообщения, ПРЕДУПРЕЖДЕНИЯ, сообщения об ошибках и КРИТИЧЕСКИЕ сообщения и игнорировать сообщения ОТЛАДКИ.

• Logger.addHandler() и Logger.removeHandler() добавляют и удаляют объекты-обработчики из объекта logger. Более подробно обработчики описаны в Обработчики.

• Logger.addFilter() и Logger.removeFilter() добавляют и удаляют объекты фильтра из объекта регистратора. Более подробно фильтры описаны в Фильтровать объекты.

Вам не нужно всегда вызывать эти методы в каждом создаваемом вами журнале регистрации. Смотрите последние два абзаца в этом разделе.

При настроенном объекте logger сообщения журнала создаются следующими методами:

• Logger.debug(), Logger.info(), Logger.warning(), Logger.error(), и Logger.critical() все они создают записи журнала с сообщением и уровнем, которые соответствуют их соответствующим названиям методов. Сообщение на самом деле представляет собой строку формата, которая может содержать стандартный синтаксис подстановки строк %s, %d, %f, и так далее. Остальные их аргументы представляют собой список объектов, которые соответствуют полям подстановки в сообщении. Что касается **kwargs, методы ведения журнала обращают внимание только на ключевое слово exc_info и используют его для определения того, следует ли регистрировать информацию об исключении.

• Logger.exception() создает сообщение журнала, аналогичное Logger.error(). Разница в том, что Logger.exception() выводит трассировку стека вместе с ним. Вызывайте этот метод только из обработчика исключений.

• Logger.log() принимает уровень журнала в качестве явного аргумента. Это немного более подробное описание сообщений для ведения журнала, чем при использовании методов, описанных выше, но это то, как вести журнал на пользовательских уровнях журнала.

getLogger() возвращает ссылку на экземпляр регистратора с указанным именем, если оно указано, или root, если нет. Имена представляют собой иерархические структуры, разделенные точкой. Несколько вызовов getLogger() с одним и тем же именем вернут ссылку на один и тот же объект logger. Логгеры, расположенные ниже в иерархическом списке, являются дочерними по отношению к логгерам, расположенным выше в списке. Например, если задан логгер с именем foo, все логгеры с именами foo.bar, foo.bar.baz, и foo.bam являются потомками foo.

У регистраторов есть понятие «эффективный уровень». Если уровень явно не задан в регистраторе, в качестве эффективного уровня используется уровень его родительского элемента. Если у родительского элемента не задан явный уровень, проверяется его родительский элемент и так далее - выполняется поиск по всем предкам, пока не будет найден явно заданный уровень. Корневой регистратор всегда имеет явно заданный уровень (WARNING по умолчанию). При принятии решения о том, обрабатывать ли событие, используется эффективный уровень средства ведения журнала, чтобы определить, передается ли событие обработчикам средства ведения журнала.

Дочерние регистраторы передают сообщения в обработчики, связанные с их родительскими регистраторами. Из-за этого нет необходимости определять и настраивать обработчики для всех регистраторов, используемых приложением. Достаточно настроить обработчики для регистратора верхнего уровня и при необходимости создать дочерние регистраторы. (Однако вы можете отключить распространение, установив для атрибута propagate регистратора значение False.)

Обработчики¶

Handler объекты отвечают за отправку соответствующих сообщений журнала (в зависимости от их серьезности) в указанный адрес обработчика. Logger объекты могут добавлять к себе ноль или более объектов обработчика с помощью метода addHandler(). В качестве примера сценария приложение может захотеть отправить все сообщения журнала в файл журнала, все сообщения журнала об ошибках или выше - в стандартный вывод, а все критические сообщения - на адрес электронной почты. Для этого сценария требуются три отдельных обработчика, каждый из которых отвечает за отправку сообщений определенной степени серьезности в определенное место.

Стандартная библиотека включает в себя довольно много типов обработчиков (см. Полезные обработчики); в примерах руководства используются в основном StreamHandler и FileHandler.

В обработчике очень мало методов, которые могли бы заинтересовать разработчиков приложений. Единственные методы обработчика, которые кажутся подходящими для разработчиков приложений, использующих встроенные объекты обработчика (то есть не создающих пользовательские обработчики), - это следующие методы настройки:

• Метод setLevel(), как и в объектах logger, определяет наименьшую степень серьезности, которая будет отправлена соответствующему получателю. Почему существует два метода setLevel()? Уровень, установленный в регистраторе, определяет, какую степень серьезности сообщений он будет передавать своим обработчикам. Уровень, установленный в каждом обработчике, определяет, какие сообщения этот обработчик будет отправлять.

• setFormatter() выбирает объект форматирования, который будет использоваться этим обработчиком.

• addFilter() и removeFilter() соответственно настраивают и отменяют настройку объектов фильтра в обработчиках.

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

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

Объекты Formatter настраивают окончательный порядок, структуру и содержимое сообщения журнала. В отличие от базового класса logging.Handler, код приложения может создавать экземпляры классов formatter, хотя вы, вероятно, могли бы создать подкласс formatter, если вашему приложению требуется особое поведение. Конструктор принимает три необязательных аргумента - строку формата сообщения, строку формата даты и индикатор стиля.

logging.Formatter.__init__(fmt=None, datefmt=None, style='%')¶

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

%Y-%m-%d %H:%M:%S

с отсчетом миллисекунд в конце. style является одним из '%', '{', или '$'. Если один из них не указан, то будет использоваться '%'.

Если style равно '%', в строке формата сообщения используется подстановка в стиле %(<dictionary key>)s; возможные ключи описаны в Атрибуты записи журнала. Если стиль '{', то предполагается, что строка формата сообщения совместима с str.format() (с использованием аргументов ключевого слова), в то время как если стиль '$', то строка формата сообщения должна соответствовать ожиданиям string.Template.substitute().

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

'%(asctime)s - %(levelname)s - %(message)s'

Форматировщики используют настраиваемую пользователем функцию для преобразования времени создания записи в кортеж. По умолчанию используется time.localtime(); чтобы изменить это значение для конкретного экземпляра средства форматирования, присвойте атрибуту экземпляра converter значение функции с той же сигнатурой, что и time.localtime() или time.gmtime(). Чтобы изменить его для всех форматировщиков, например, если вы хотите, чтобы все время регистрации отображалось по Гринвичу, установите атрибут converter в классе Formatter (на time.gmtime для отображения по Гринвичу).

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

Программисты могут настроить ведение журнала тремя способами:

1. Создание регистраторов, обработчиков и форматировщиков явно с использованием кода на Python, который вызывает методы настройки, перечисленные выше.

2. Создаем файл конфигурации ведения журнала и считываем его с помощью функции fileConfig().

3. Создаем словарь конфигурационной информации и передаем его в функцию dictConfig().

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

import logging

# create logger
logger = logging.getLogger('simple_example')
logger.setLevel(logging.DEBUG)

# create console handler and set level to debug
ch = logging.StreamHandler()
ch.setLevel(logging.DEBUG)

# create formatter
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')

# add formatter to ch
ch.setFormatter(formatter)

# add ch to logger
logger.addHandler(ch)

# 'application' code
logger.debug('debug message')
logger.info('info message')
logger.warning('warn message')
logger.error('error message')
logger.critical('critical message')

Запуск этого модуля из командной строки приводит к следующему результату:

$ python simple_logging_module.py
2005-03-19 15:10:26,618 - simple_example - DEBUG - debug message
2005-03-19 15:10:26,620 - simple_example - INFO - info message
2005-03-19 15:10:26,695 - simple_example - WARNING - warn message
2005-03-19 15:10:26,697 - simple_example - ERROR - error message
2005-03-19 15:10:26,773 - simple_example - CRITICAL - critical message

Следующий модуль Python создает регистратор, обработчик и средство форматирования, почти идентичные тем, что приведены в приведенном выше примере, с единственной разницей в именах объектов:

import logging
import logging.config

logging.config.fileConfig('logging.conf')

# create logger
logger = logging.getLogger('simpleExample')

# 'application' code
logger.debug('debug message')
logger.info('info message')
logger.warning('warn message')
logger.error('error message')
logger.critical('critical message')

Вот файл logging.conf:

[loggers]
keys=root,simpleExample

[handlers]
keys=consoleHandler

[formatters]
keys=simpleFormatter

[logger_root]
level=DEBUG
handlers=consoleHandler

[logger_simpleExample]
level=DEBUG
handlers=consoleHandler
qualname=simpleExample
propagate=0

[handler_consoleHandler]
class=StreamHandler
level=DEBUG
formatter=simpleFormatter
args=(sys.stdout,)

[formatter_simpleFormatter]
format=%(asctime)s - %(name)s - %(levelname)s - %(message)s

Выходные данные почти идентичны полученным в примере, не основанном на конфигурационном файле:

$ python simple_logging_config.py
2005-03-19 15:38:55,977 - simpleExample - DEBUG - debug message
2005-03-19 15:38:55,979 - simpleExample - INFO - info message
2005-03-19 15:38:56,054 - simpleExample - WARNING - warn message
2005-03-19 15:38:56,055 - simpleExample - ERROR - error message
2005-03-19 15:38:56,130 - simpleExample - CRITICAL - critical message

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

Обратите внимание, что имена классов, на которые ссылаются в конфигурационных файлах, должны быть либо относительными к модулю ведения журнала, либо абсолютными значениями, которые могут быть определены с помощью обычных механизмов импорта. Таким образом, вы могли бы использовать либо WatchedFileHandler (относительно модуля ведения журнала), либо mypackage.mymodule.MyHandler (для класса, определенного в пакете mypackage и модуле mymodule, где mypackage доступен в пути импорта Python).

В Python 3.2 появилось новое средство настройки ведения журнала, использующее словари для хранения информации о конфигурации. Это расширяет функциональные возможности описанного выше подхода на основе конфигурационных файлов и является рекомендуемым методом настройки для новых приложений и развертываний. Поскольку словарь Python используется для хранения информации о конфигурации, и поскольку вы можете заполнить этот словарь различными способами, у вас есть больше возможностей для настройки. Например, вы можете использовать файл конфигурации в формате JSON или, если у вас есть доступ к функциям обработки YAML, файл в формате YAML для заполнения словаря конфигурации. Или, конечно, вы можете создать словарь в коде Python, получить его в обработанном виде через сокет или использовать любой другой подход, который имеет смысл для вашего приложения.

Вот пример той же конфигурации, что и выше, в формате YAML для нового подхода, основанного на словаре:

version: 1
formatters:
  simple:
    format: '%(asctime)s - %(name)s - %(levelname)s - %(message)s'
handlers:
  console:
    class: logging.StreamHandler
    level: DEBUG
    formatter: simple
    stream: ext://sys.stdout
loggers:
  simpleExample:
    level: DEBUG
    handlers: [console]
    propagate: no
root:
  level: DEBUG
  handlers: [console]

Дополнительные сведения о ведении журнала с использованием словаря см. в разделе Функции настройки.

Что произойдет, если конфигурация не будет предоставлена¶

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

Событие выводится с помощью «обработчика последней инстанции», хранящегося в lastResort. Этот внутренний обработчик не связан ни с каким регистратором и действует как StreamHandler, который записывает сообщение с описанием события в текущее значение sys.stderr (таким образом, соблюдая любые перенаправления, которые могут действовать). Сообщение не форматируется - печатается только сообщение с описанием события. Уровень обработчика установлен на WARNING, поэтому будут выводиться все события с этой и более высокой степенью серьезности.

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

При разработке библиотеки, использующей ведение журнала, вам следует позаботиться о документировании того, как библиотека использует ведение журнала - например, имена используемых регистраторов. Также необходимо уделить некоторое внимание конфигурации ведения журнала. Если использующее приложение не использует протоколирование, а библиотечный код выполняет вызовы протоколирования, то (как описано в предыдущем разделе) события с серьезностью WARNING и выше будут отображаться как sys.stderr. Это считается наилучшим поведением по умолчанию.

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

В пакет ведения журнала включен обработчик бездействия: NullHandler (начиная с Python 3.1). Экземпляр этого обработчика может быть добавлен в регистратор верхнего уровня пространства имен ведения журнала, используемого библиотекой (если вы хотите предотвратить вывод зарегистрированных событий вашей библиотеки в sys.stderr при отсутствии конфигурации ведения журнала). Если все протоколирование библиотекой foo выполняется с использованием регистраторов с именами, совпадающими с „foo.x“, „foo.x.y“ и т.д., то код:

import logging
logging.getLogger('foo').addHandler(logging.NullHandler())

должно дать желаемый эффект. Если организация выпускает несколько библиотек, то указанным именем регистратора может быть «orgname».foo, а не просто «foo».

Пользовательские уровни¶

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