Сообщить об ошибке.

Примеры простого использование модуля logging

В этом разделе содержатся примеры простого использования модуля logging.

Содержание:

Обратите внимание, что параметры logging.basicConfig() должны передаваться до первого вызова функций ведения журнала. Если в консоли интерпретатора уже была вызвана хотя бы одна функция, то необходимо перезагрузить пакет logging или выйти и снова зайти в консоль интерпретатора. С версии Python-3.8 для этой цели можно использовать ключевой аргумент force=True


Логирование событий в файл.

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

# test.py
import logging

logging.basicConfig(filename='example.log', level=logging.DEBUG)
logging.debug('This message should go to the log file')
logging.info('So should this')
logging.warning('And this, too')

Теперь, если открыть файл example.log то можно увидеть сообщения журнала:

DEBUG:root:This message should go to the log file
INFO:root:So should this
WARNING:root:And this, too

В примере также показано, как можно установить уровень ведения журнала level, который служит порогом для отслеживания событий. Так как установлен уровень отображения событий level=logging.DEBUG, то в файл были записаны все сообщения.

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

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

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

Если необходимо установить уровень ведения журнала из командной строки, а значение параметра для --log=<level> было получено например в переменную loglevel, то можно использовать функцию getattr для получения значения, которое передается logging.basicConfig() в качестве аргумента level:

>>> import logging
>>> loglevel = 'info'
# 'loglevel' преобразовываем в верхний регистр, чтобы
# пользователь мог указать --log=INFO или --log=info
>>> getattr(logging, loglevel.upper())
# 20

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

...
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, ...)
...

Логирование событий из нескольких модулей.

Если программа состоит из нескольких модулей, вот пример того, как можно организовать код:

# app.py
import logging
import mylib

def main():
    logging.basicConfig(filename='myapp.log', level=logging.INFO)
    logging.info('Started')
    mylib.do_something()
    logging.info('Finished')

if __name__ == '__main__':
    main()

Регистрация сообщений в модуле mylib.py.

# mylib.py
import logging

def do_something():
    # регистрация сообщений в пользовательском модуле
    logging.info('Doing something')

Если запустить файл app.py, то в myapp.log увидим следующее:

INFO:root:Started
INFO:root:Doing something
INFO:root:Finished

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

Регистрация значений переменных.

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

>>> import logging
>>> x = 10
>>> y = 'See'
>>> logging.warning('%s how the variable is passed `x`: %d', y, x)
# WARNING:root:See how the variable is passed `x`: 10

Добавление значений переменных в описание события использует форматирование строк в стиле printf. Такое поведение в модуле logging сохранено для обратной совместимости. С версии Python-3.2 класс logging.Formatter() получил ключевой аргумент style='%', при помощи которого можно установить спецификации форматирования '{' или '$'. Эти спецификации поддерживают подходы, определенные в str.format() и string.Template() соответственно.

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

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

>>> import logging
>>> x = 10
>>> y = 'Look'
# подготовим сообщение, например используя f-строку
>>> msg = f'{y} how the variable is passed `x`: {x}'
>>> logging.warning(msg)
# WARNING:root:See how the variable is passed `x`: 10

Форматирование вида отображаемых сообщений.

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

import logging

logging.basicConfig(filename='example.log', 
                    format='[%(levelname)s] => %(message)s', 
                    level=logging.DEBUG)
logging.debug('This message should appear on the file')
logging.info('So should this')
logging.warning('And this, too')

Этот запишет в файл example.log следующее:

[DEBUG] => This message should appear on the file
[INFO] => So should this
[WARNING] => And this, too

Обратите внимание, что запись root, имевшая место в предыдущих примерах, исчезла. Для полного набора параметров, которые могут появляться в строке сообщения журналируемого события смотрите документацию по атрибутам объекта logging.LogRecord()

Для простого использования модуля достаточно использования таких атрибутов как levelname (серьезность), message (описание события, включая данные переменных) и возможно понадобится отображение времени, когда произошло событие.

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

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

import logging

logging.basicConfig(filename='example.log', 
                    format='[%(asctime)s] [%(levelname)s] => %(message)s', 
                    level=logging.DEBUG)
logging.warning('is when this event was logged.')

Код выше выведет в файл example.log следующее:

[2020-06-07 19:05:18,852] [WARNING] => is when this event was logged.

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

import logging

logging.basicConfig(filename='example.log', 
                    format='[%(asctime)s] [%(levelname)s] => %(message)s', 
                    datefmt='%Y-%m-%d %H:%M:%S',
                    level=logging.DEBUG)
logging.warning('is when this event was logged.')

Теперь в файл example.log можно увидеть запись:

[2020-06-07 19:15:40] [WARNING] => is when this event was logged.

Формат аргумента datefmt такой же, как поддерживается функцией time.strftime().

Логирование исключений с трассировкой стека.

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

import logging

# базовая настройка logging
...

# определение функции `main_loop()`
def main_loop():
    ...

while True:
    try:
        main_loop()
    except Exception:
        logging.exception('Фатальная ошибка в основном цикле')

Этот замечательная функция захватывает полную трассировку стека в контексте блока except и передает ее в журнал полностью. Обратите внимание, что не нужно передавать объект исключения в функцию logging.exception(). В функцию передается только строка с описанием события. Таким образом, многострочное сообщение, которое появляется журнале, может выглядеть так:

[2020-06-07 19:15:40] [ERROR] => Фатальная ошибка в основном цикле
Traceback (most recent call last):
  File "test.py", line 14, in
    main_loop()
  File "test.py", line 9, in main_loop
    print(foo(x))
  File "test.py", line 4, in foo
    return 10 // n
    ZeroDivisionError: integer division or modulo by zero

Обратите внимание, что первая строка - это сообщение, которое передается в logging.exception(), а последующие строки - трассировка полного стека, включая тип исключения, в данном случае ZeroDivisionError.

По умолчанию функция logging.exception() использует уровень журнала ERROR. Также для этих целей, можно использовать обычное функции регистрации событий, такие как logging.debug(), logging.info(), logging.warn() и т. д., только устанавливать значение аргумента exc_info=True:

import logging
...
...

while True:
    try:
        main_loop()
    except Exception:
        logging.error('Фатальная ошибка в основном цикле', exc_info=True)