Как использовать журналирование в Python 3

Введение

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

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

Предварительные условия

У вас должен быть установлен Python 3 и настроена среда программирования на вашем компьютере или сервере. Если у вас нет настроенной среды программирования, вы можете обратиться к руководствам по установке и настройке для локальной среды программирования или для среды программирования на вашем сервере, подходящей для вашей операционной системы (Ubuntu, CentOS, Debian и т. д.).

Зачем использовать модуль logging

Модуль logging ведет запись событий, происходящих в программе, что позволяет видеть вывод, связанный с любыми событиями, происходящими во время выполнения программного обеспечения.

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

• Становится сложно различать между выводом отладки и обычным выводом программы, потому что они смешаны
• При использовании операторов print(), распределенных по всему коду, нет эффективного способа отключить те, которые предоставляют вывод отладки
• Становится сложно удалить все операторы print(), когда вы закончили отладку
• Отсутствует запись журнала, содержащая готовую диагностическую информацию

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

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

Вывод отладочных сообщений в консоль

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

class Pizza():
    def __init__(self, name, price):
        self.name = name
        self.price = price
        print("Pizza created: {} (${})".format(self.name, self.price))

    def make(self, quantity=1):
        print("Made {} {} pizza(s)".format(quantity, self.name))

    def eat(self, quantity=1):
        print("Ate {} pizza(s)".format(quantity, self.name))

pizza_01 = Pizza("artichoke", 15)
pizza_01.make()
pizza_01.eat()

pizza_02 = Pizza("margherita", 12)
pizza_02.make(2)
pizza_02.eat()

Приведенный выше код имеет метод __init__ для определения name и price объекта класса Pizza. Затем он имеет два метода: один называется make() для приготовления пиццы, а другой – eat() для поедания пиццы. Эти два метода принимают параметр quantity, который инициализируется значением 1.

Теперь давайте запустим программу:

python pizza.py

Мы получим следующий вывод:

Output
Pizza created: artichoke ($15)
Made 1 artichoke pizza(s)
Ate 1 pizza(s)
Pizza created: margherita ($12)
Made 2 margherita pizza(s)
Ate 1 pizza(s)

В то время как оператор print() позволяет нам убедиться, что код работает, мы можем использовать модуль logging, чтобы делать это вместо него.

Давайте удалим или закомментируем операторы print() во всем коде и добавим import logging в верхней части файла:

import logging


class Pizza():
    def __init__(self, name, value):
        self.name = name
        self.value = value
...

Модуль logging имеет стандартный уровень WARNING, который выше уровня DEBUG. Поскольку мы собираемся использовать модуль logging для отладки в этом примере, нам нужно изменить конфигурацию, чтобы уровень logging.DEBUG возвращал информацию на консоль для нас. Мы можем сделать это, добавив следующую строку после оператора import:

import logging

logging.basicConfig(level=logging.DEBUG)


class Pizza():
...

Этот уровень logging.DEBUG относится к постоянному целочисленному значению, на которое мы ссылаемся в коде выше, чтобы установить порог. Уровень DEBUG равен 10.

Теперь мы заменим все операторы print() операторами logging.debug(). В отличие от logging.DEBUG, который является константой, logging.debug() – это метод модуля logging. При работе с этим методом мы можем использовать тот же строковый аргумент, переданный в print(), как показано ниже:

import logging

logging.basicConfig(level=logging.DEBUG)


class Pizza():
    def __init__(self, name, price):
        self.name = name
        self.price = price
        logging.debug("Pizza created: {} (${})".format(self.name, self.price))

    def make(self, quantity=1):
        logging.debug("Made {} {} pizza(s)".format(quantity, self.name))

    def eat(self, quantity=1):
        logging.debug("Ate {} pizza(s)".format(quantity, self.name))

pizza_01 = Pizza("artichoke", 15)
pizza_01.make()
pizza_01.eat()

pizza_02 = Pizza("margherita", 12)
pizza_02.make(2)
pizza_02.eat()

На этом этапе, когда мы запускаем программу с помощью команды python pizza.py, мы получим следующий вывод:

Output
DEBUG:root:Pizza created: artichoke ($15)
DEBUG:root:Made 1 artichoke pizza(s)
DEBUG:root:Ate 1 pizza(s)
DEBUG:root:Pizza created: margherita ($12)
DEBUG:root:Made 2 margherita pizza(s)
DEBUG:root:Ate 1 pizza(s)

Сообщения журнала имеют уровень серьезности DEBUG, а также в них содержится слово root, которое относится к уровню вашего модуля Python. Модуль logging может использоваться с иерархией регистраторов, имеющих разные имена, так что вы можете использовать разные регистраторы для каждого из ваших модулей.

Например, вы можете установить регистраторы равными разным регистраторам с разными именами и разным выводом:

logger1 = logging.getLogger("module_1")
logger2 = logging.getLogger("module_2")

logger1.debug("Module 1 debugger")
logger2.debug("Module 2 debugger")

Output
DEBUG:module_1:Module 1 debugger
DEBUG:module_2:Module 2 debugger

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

Вывод сообщений в файл

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

Чтобы начать ведение журнала в файл, мы можем изменить метод logging.basicConfig(), чтобы добавить параметр filename. В этом случае давайте назовем файл test.log:

import logging

logging.basicConfig(filename="test.log", level=logging.DEBUG)


class Pizza():
    def __init__(self, name, price):
        self.name = name
        self.price = price
        logging.debug("Pizza created: {} (${})".format(self.name, self.price))

    def make(self, quantity=1):
        logging.debug("Made {} {} pizza(s)".format(quantity, self.name))

    def eat(self, quantity=1):
        logging.debug("Ate {} pizza(s)".format(quantity, self.name))

pizza_01 = Pizza("artichoke", 15)
pizza_01.make()
pizza_01.eat()

pizza_02 = Pizza("margherita", 12)
pizza_02.make(2)
pizza_02.eat()

Код выше такой же, как и в предыдущем разделе, за исключением того, что теперь мы добавили имя файла для вывода журнала. После запуска кода с помощью команды python pizza.py у нас должен появиться новый файл в нашем каталоге с именем test.log.

Давайте откроем файл test.log с помощью nano (или текстового редактора по вашему выбору):

nano test.log

Когда файл откроется, мы увидим следующее:

DEBUG:root:Pizza created: artichoke ($15)
DEBUG:root:Made 1 artichoke pizza(s)
DEBUG:root:Ate 1 pizza(s)
DEBUG:root:Pizza created: margherita ($12)
DEBUG:root:Made 2 margherita pizza(s)
DEBUG:root:Ate 1 pizza(s)

Это аналогично выводу в консоли, с которым мы сталкивались в предыдущем разделе, за исключением того, что теперь он находится в файле test.log.

Давайте закроем файл с помощью CTRL + x и вернемся обратно в файл pizza.py, чтобы мы могли изменить код.

Мы оставим большую часть кода без изменений, но изменим параметры в двух экземплярах пиццы, pizza_01 и pizza_02:

import logging

logging.basicConfig(filename="test.log", level=logging.DEBUG)


class Pizza():
    def __init__(self, name, price):
        self.name = name
        self.price = price
        logging.debug("Pizza created: {} (${})".format(self.name, self.price))

    def make(self, quantity=1):
        logging.debug("Made {} {} pizza(s)".format(quantity, self.name))

    def eat(self, quantity=1):
        logging.debug("Ate {} pizza(s)".format(quantity, self.name))

# Изменяем параметры объекта pizza_01
pizza_01 = Pizza("Sicilian", 18)
pizza_01.make(5)
pizza_01.eat(4)

# Изменяем параметры объекта pizza_02
pizza_02 = Pizza("quattro formaggi", 16)
pizza_02.make(2)
pizza_02.eat(2)

После этих изменений давайте снова запустим программу с помощью команды python pizza.py.

После того как программа завершит работу, мы можем снова открыть наш файл test.log с помощью nano:

nano test.log

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

DEBUG:root:Pizza created: artichoke ($15)
DEBUG:root:Made 1 artichoke pizza(s)
DEBUG:root:Ate 1 pizza(s)
DEBUG:root:Pizza created: margherita ($12)
DEBUG:root:Made 2 margherita pizza(s)
DEBUG:root:Ate 1 pizza(s)
DEBUG:root:Pizza created: Sicilian ($18)
DEBUG:root:Made 5 Sicilian pizza(s)
DEBUG:root:Ate 4 pizza(s)
DEBUG:root:Pizza created: quattro formaggi ($16)
DEBUG:root:Made 2 quattro formaggi pizza(s)
DEBUG:root:Ate 2 pizza(s)

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

Мы можем добавить этот атрибут к параметру с именем format, ссылаясь на него, как показано в таблице со строкой %(asctime)s. Кроме того, чтобы сохранить имя уровня DEBUG, нам нужно включить строку %(levelname)s, и чтобы сохранить строковое сообщение, которое мы просим регистратор вывести, мы включим %(message)s. Каждый из этих атрибутов будет разделен двоеточием, как показано в добавленном коде:

import logging

logging.basicConfig(
    filename="test.log",
    level=logging.DEBUG,
    format="%(asctime)s:%(levelname)s:%(message)s"
    )


class Pizza():
    def __init__(self, name, price):
        self.name = name
        self.price = price
        logging.debug("Pizza created: {} (${})".format(self.name, self.price))

    def make(self, quantity=1):
        logging.debug("Made {} {} pizza(s)".format(quantity, self.name))

    def eat(self, quantity=1):
        logging.debug("Ate {} pizza(s)".format(quantity, self.name))

pizza_01 = Pizza("Sicilian", 18)
pizza_01.make(5)
pizza_01.eat(4)

pizza_02 = Pizza("quattro formaggi", 16)
pizza_02.make(2)
pizza_02.eat(2)

Когда мы запускаем приведенный выше код с добавленными атрибутами с помощью команды python pizza.py, мы получаем новые строки, добавленные в наш файл test.log, которые включают удобочитаемый временной штамп в дополнение к имени уровня DEBUG и связанным с ним сообщениям, переданным в регистратор в виде строк.

DEBUG:root:Pizza created: Sicilian ($18)
DEBUG:root:Made 5 Sicilian pizza(s)
DEBUG:root:Ate 4 pizza(s)
DEBUG:root:Pizza created: quattro formaggi ($16)
DEBUG:root:Made 2 quattro formaggi pizza(s)
DEBUG:root:Ate 2 pizza(s)
2021-08-19 23:31:34,484:DEBUG:Pizza created: Sicilian ($18)
2021-08-19 23:31:34,484:DEBUG:Made 5 Sicilian pizza(s)
2021-08-19 23:31:34,484:DEBUG:Ate 4 pizza(s)
2021-08-19 23:31:34,484:DEBUG:Pizza created: quattro formaggi ($16)
2021-08-19 23:31:34,484:DEBUG:Made 2 quattro formaggi pizza(s)
2021-08-19 23:31:34,484:DEBUG:Ate 2 pizza(s)

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

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

Таблица уровней регистрации

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

Уровни регистрации технически представляют собой целые числа (константы), и все они увеличиваются на 10, начиная с NOTSET, который инициализирует регистратор числовым значением 0.

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

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

Модуль logging устанавливает уровень по умолчанию на WARNING, поэтому WARNING, ERROR и CRITICAL будут записаны по умолчанию. В приведенном выше примере мы изменили конфигурацию, чтобы включить уровень DEBUG с помощью следующего кода:

logging.basicConfig(level=logging.DEBUG)

Вы можете узнать больше о командах и работе с отладчиком из официальной документации по logging.

Вывод

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