Как сохранить лог в переменную python
Перейти к содержимому

Как сохранить лог в переменную python

  • автор:

Логирование в Python: руководство разработчика

Сталкивались ли вы с трудностями при отладке Python-кода? Если это так — то изучение того, как наладить логирование (журналирование, logging) в Python, способно помочь вам упростить задачи, решаемые при отладке.

Если вы — новичок, то вы, наверняка, привыкли пользоваться командой print() , выводя с её помощью определённые значения в ходе работы программы, проверяя, работает ли код так, как от него ожидается. Использование print() вполне может оправдать себя при отладке маленьких Python-программ. Но, когда вы перейдёте к более крупным и сложным проектам, вам понадобится постоянный журнал, содержащий больше информации о поведении вашего кода, помогающий вам планомерно отлаживать и отслеживать ошибки.

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

Вы, кроме того, узнаете о том, как Sentry Python SDK способен помочь вам в мониторинге приложений и в упрощении рабочих процессов, связанных с отладкой кода. Платформа Sentry обладает нативной интеграцией со встроенным Python-модулем logging , и, кроме того, предоставляет подробную информацию об ошибках приложения и о проблемах с производительностью, которые в нём возникают.

Начало работы с Python-модулем logging

В Python имеется встроенный модуль logging , применяемый для решения задач логирования. Им мы будем пользоваться в этом руководстве. Первый шаг к профессиональному логированию вы можете выполнить прямо сейчас, импортировав этот модуль в своё рабочее окружение.

import logging

Встроенный модуль логирования Python даёт нам простой в использовании функционал и предусматривает пять уровней логирования. Чем выше уровень — тем серьёзнее неприятность, о которой сообщает соответствующая запись. Самый низкий уровень логирования — это debug (10) , а самый высокий — это critical (50) .

Дадим краткие характеристики уровней логирования:

  • Debug (10) : самый низкий уровень логирования, предназначенный для отладочных сообщений, для вывода диагностической информации о приложении.
  • Info (20) : этот уровень предназначен для вывода данных о фрагментах кода, работающих так, как ожидается.
  • Warning (30) : этот уровень логирования предусматривает вывод предупреждений, он применяется для записи сведений о событиях, на которые программист обычно обращает внимание. Такие события вполне могут привести к проблемам при работе приложения. Если явно не задать уровень логирования — по умолчанию используется именно warning .
  • Error (40) : этот уровень логирования предусматривает вывод сведений об ошибках — о том, что часть приложения работает не так как ожидается, о том, что программа не смогла правильно выполниться.
  • Critical (50) : этот уровень используется для вывода сведений об очень серьёзных ошибках, наличие которых угрожает нормальному функционированию всего приложения. Если не исправить такую ошибку — это может привести к тому, что приложение прекратит работу.

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

logging.debug("A DEBUG Message") logging.info("An INFO") logging.warning("A WARNING") logging.error("An ERROR") logging.critical("A message of CRITICAL severity")

Ниже приведён результат выполнения этого кода. Как видите, сообщения, выведенные с уровнями логирования warning , error и critical , попадают в консоль. А сообщения с уровнями debug и info — не попадают.

WARNING:root:A WARNING ERROR:root:An ERROR CRITICAL:root:A message of CRITICAL severity

Это так из-за того, что в консоль выводятся лишь сообщения с уровнями от warning и выше. Но это можно изменить, настроив логгер и указав ему, что в консоль надо выводить сообщения, начиная с некоего, заданного вами, уровня логирования.

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

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

Логирование в файл

Для того чтобы настроить простую систему логирования в файл — можно воспользоваться конструктором basicConfig() . Вот как это выглядит:

logging.basicConfig(level=logging.INFO, filename="py_log.log",filemode="w") logging.debug("A DEBUG Message") logging.info("An INFO") logging.warning("A WARNING") logging.error("An ERROR") logging.critical("A message of CRITICAL severity")

Поговорим о логгере root , рассмотрим параметры basicConfig() :

  • level : это — уровень, на котором нужно начинать логирование. Если он установлен в info — это значит, что все сообщения с уровнем debug игнорируются.
  • filename : этот параметр указывает на объект обработчика файла. Тут можно указать имя файла, в который нужно осуществлять логирование.
  • filemode : это — необязательный параметр, указывающий режим, в котором предполагается работать с файлом журнала, заданным параметром filename . Установка filemode в значение w (write, запись) приводит к тому, что логи перезаписываются при каждом запуске модуля. По умолчанию параметр filemode установлен в значение a (append, присоединение), то есть — в файл будут попадать записи из всех сеансов работы программы.

После выполнения модуля main можно будет увидеть, что в текущей рабочей директории был создан файл журнала, py_log.log .

В текущей рабочей директории был создан файл журнала py_log.log

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

Так как уровень логирования установлен в info, в файл, помимо сообщений уровня warning, error и critical, попадут и записи уровня info

Записи в лог-файле имеют формат :: . По умолчанию , имя логгера, установлено в root , так как мы пока не настраивали пользовательские логгеры.

В записи лог-файла закодированы уровень логирования, имя логгера и сообщение

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

logging.basicConfig(level=logging.INFO, filename="py_log.log",filemode="w", format="%(asctime)s %(levelname)s %(message)s") logging.debug("A DEBUG Message") logging.info("An INFO") logging.warning("A WARNING") logging.error("An ERROR") logging.critical("A message of CRITICAL severity")

Благодаря настройке параметра format к записям добавлены временные метки, представленные в виде, удобном для восприятия

Существуют и многие другие атрибуты записи лога, которыми можно воспользоваться для того чтобы настроить внешний вид сообщений в лог-файле. Настраивая поведение логгера root — так, как это показано выше, проследите за тем, чтобы конструктор logging.basicConfig() вызывался бы лишь один раз. Обычно это делается в начале программы, до использования команд логирования. Последующие вызовы конструктора ничего не изменят — если только не установить параметр force в значение True .

Логирование значений переменных и исключений

Модифицируем файл main.py . Скажем — тут будут две переменных — x и y , и нам нужно вычислить значение выражения x/y . Мы знаем о том, что при y=0 мы столкнёмся с ошибкой ZeroDivisionError . Обработать эту ошибку можно в виде исключения с использованием блока try/except .

Далее — нужно залогировать исключение вместе с данными трассировки стека. Чтобы это сделать — можно воспользоваться logging.error(message, exc_info=True) . Запустите следующий код и посмотрите на то, как в файл попадают записи с уровнем логирования info , указывающие на то, что код работает так, как ожидается.

x = 3 y = 4 logging.info(f"The values of x and y are and .") try: x/y logging.info(f"x/y successful with result: .") except ZeroDivisionError as err: logging.error("ZeroDivisionError",exc_info=True)

В файл журнала попали записи с уровнем логирования info

Теперь установите значение y в 0 и снова запустите модуль.

Исследуя лог-файл py_log.log , вы увидите, что сведения об исключении были записаны в него вместе со стек-трейсом.

x = 4 y = 0 logging.info(f"The values of x and y are and .") try: x/y logging.info(f"x/y successful with result: .") except ZeroDivisionError as err: logging.error("ZeroDivisionError",exc_info=True)

В журнале появилась запись об ошибке вместе с результатами трассировки стека

Теперь модифицируем код так, чтобы в нём имелись бы списки значений x и y , для которых нужно вычислить коэффициенты x/y . Для логирования исключений ещё можно воспользоваться конструкцией logging.exception() .

x_vals = [2,3,6,4,10] y_vals = [5,7,12,0,1] for x_val,y_val in zip(x_vals,y_vals): x,y = x_val,y_val logging.info(f"The values of x and y are and .") try: x/y logging.info(f"x/y successful with result: .") except ZeroDivisionError as err: logging.exception("ZeroDivisionError")

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

Записи об успешных попытках вычисления коэффициента и об исключении

Настройка логирования с помощью пользовательских логгеров, обработчиков и форматировщиков

Отрефакторим код, который у нас уже есть. Объявим функцию test_division .

def test_division(x,y): try: x/y logger2.info(f"x/y successful with result: .") except ZeroDivisionError as err: logger2.exception("ZeroDivisionError")

Объявление этой функции находится в модуле test_div . В модуле main будут лишь вызовы функций. Настроим пользовательские логгеры в модулях main и test_div , проиллюстрировав это примерами кода.

Настройка пользовательского логгера для модуля test_div
import logging logger2 = logging.getLogger(__name__) logger2.setLevel(logging.INFO) # настройка обработчика и форматировщика для logger2 handler2 = logging.FileHandler(f".log", mode='w') formatter2 = logging.Formatter("%(name)s %(asctime)s %(levelname)s %(message)s") # добавление форматировщика к обработчику handler2.setFormatter(formatter2) # добавление обработчика к логгеру logger2.addHandler(handler2) logger2.info(f"Testing the custom logger for module . ") def test_division(x,y): try: x/y logger2.info(f"x/y successful with result: .") except ZeroDivisionError as err: logger2.exception("ZeroDivisionError")
Настройка пользовательского логгера для модуля main
import logging from test_div import test_division # получение пользовательского логгера и установка уровня логирования py_logger = logging.getLogger(__name__) py_logger.setLevel(logging.INFO) # настройка обработчика и форматировщика в соответствии с нашими нуждами py_handler = logging.FileHandler(f".log", mode='w') py_formatter = logging.Formatter("%(name)s %(asctime)s %(levelname)s %(message)s") # добавление форматировщика к обработчику py_handler.setFormatter(py_formatter) # добавление обработчика к логгеру py_logger.addHandler(py_handler) py_logger.info(f"Testing the custom logger for module . ") x_vals = [2,3,6,4,10] y_vals = [5,7,12,0,1] for x_val,y_val in zip(x_vals,y_vals): x,y = x_val, y_val # вызов test_division test_division(x,y) py_logger.info(f"Call test_division with args and ") 

Разберёмся с тем, что происходит коде, где настраиваются пользовательские логгеры.

Сначала мы получаем логгер и задаём уровень логирования. Команда logging.getLogger(name) возвращает логгер с заданным именем в том случае, если он существует. В противном случае она создаёт логгер с заданным именем. На практике имя логгера устанавливают с использованием специальной переменной name , которая соответствует имени модуля. Мы назначаем объект логгера переменной. Затем мы, используя команду logging.setLevel(level) , устанавливаем нужный нам уровень логирования.

Далее мы настраиваем обработчик. Так как мы хотим записывать сведения о событиях в файл, мы пользуемся FileHandler . Конструкция logging.FileHandler(filename) возвращает объект обработчика файла. Помимо имени лог-файла, можно, что необязательно, задать режим работы с этим файлом. В данном примере режим ( mode ) установлен в значение write . Есть и другие обработчики, например — StreamHandler , HTTPHandler , SMTPHandler .

Затем мы создаём объект форматировщика, используя конструкцию logging.Formatter(format) . В этом примере мы помещаем имя логгера (строку) в начале форматной строки, а потом идёт то, чем мы уже пользовались ранее при оформлении сообщений.

Потом мы добавляем форматировщик к обработчику, пользуясь конструкцией вида .setFormatter() . А в итоге добавляем обработчик к объекту логгера, пользуясь конструкцией .addHandler() .

Теперь можно запустить модуль main и исследовать сгенерированные лог-файлы.

Лог-файл main.logЛог-файл test_div.log

Рекомендации по организации логирования в Python

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

  • Устанавливайте оптимальный уровень логирования. Логи полезны лишь тогда, когда их можно использовать для отслеживания важных ошибок, которые нужно исправлять. Подберите такой уровень логирования, который соответствует специфике конкретного приложения. Вывод в лог сообщений о слишком большом количестве событий может быть, с точки зрения отладки, не самой удачной стратегией. Дело в том, что при таком подходе возникнут сложности с фильтрацией логов при поиске ошибок, которым нужно немедленно уделить внимание.
  • Конфигурируйте логгеры на уровне модуля. Когда вы работаете над приложением, состоящим из множества модулей — вам стоит задуматься о том, чтобы настроить свой логгер для каждого модуля. Установка имени логгера в name помогает идентифицировать модуль приложения, в котором имеются проблемы, нуждающиеся в решении.
  • Включайте в состав сообщений логов отметку времени и обеспечьте единообразное форматирование сообщений. Всегда включайте в сообщения логов отметки времени, так как они полезны в деле поиска того момента, когда произошла ошибка. Единообразно форматируйте сообщения логов, придерживаясь одного и того же подхода в разных модулях.
  • Применяйте ротацию лог-файлов ради упрощения отладки. При работе над большим приложением, в состав которого входит несколько модулей, вы, вполне вероятно, столкнётесь с тем, что размер ваших лог-файлов окажется очень большим. Очень длинные логи сложно просматривать в поисках ошибок. Поэтому стоит подумать о ротации лог-файлов. Сделать это можно, воспользовавшись обработчиком RotatingFileHandler , применив конструкцию, которая строится по следующей схеме: logging.handlers.RotatingFileHandler(filename, maxBytes, backupCount) . Когда размер текущего лог-файла достигнет размера maxBytes , следующие записи будут попадать в другие файлы, количество которых зависит от значения параметра backupCount . Если установить этот параметр в значение K — у вас будет K файлов журнала.

Сильные и слабые стороны логирования

Теперь, когда мы разобрались с основами логирования в Python, поговорим о сильных и слабых сторонах этого механизма.

Мы уже видели, как логирование позволяет поддерживать файлы журналов для различных модулей, из которых состоит приложение. Мы, кроме того, можем конфигурировать подсистему логирования и подстраивать её под свои нужды. Но эта система не лишена недостатков. Даже когда уровень логирования устанавливают в значение warning , или в любое значение, которое выше warning , размеры лог-файлов способны быстро увеличиваться. Происходит это в том случае, когда в один и тот же журнал пишут данные, полученные после нескольких сеансов работы с приложением. В результате использование лог-файлов для отладки программ превращается в нетривиальную задачу.

Кроме того, исследование логов ошибок — это сложно, особенно в том случае, если сообщения об ошибках не содержат достаточных сведений о контекстах, в которых происходят ошибки. Когда выполняют команду logging.error(message) , не устанавливая при этом exc_info в True , сложно обнаружить и исследовать первопричину ошибки в том случае, если сообщение об ошибке не слишком информативно.

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

В следующем разделе мы поговорим о том, как интегрировать в Python-проект поддержку Sentry, что позволит упростить процесс отладки кода.

Интеграция Sentry в Python-проект

Установить Sentry Python SDK можно, воспользовавшись менеджером пакетов pip .

pip install sentry-sdk

После установки SDK для настройки мониторинга приложения нужно воспользоваться таким кодом:

sentry_sdk.init( dsn , traces_sample_rate=0.85, )

Как можно видеть — вам, для настройки мониторинга, понадобится ключ dsn . DSN расшифровывается как Data Source Name (имя источника данных). Найти этот ключ можно, перейдя в Your-Project > Settings > Client Keys (DSN) .

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

Логи в интерфейсе Sentry.io

Изучая подробности об ошибке, вы можете увидеть, что Sentry предоставляет подробную информацию о том, где именно произошла ошибка, а так же — об аргументах x и y , работа с которыми привела к появлению исключения.

Подробные сведения об исключении

Продолжая изучение логов, можно увидеть, помимо записей уровня error , записи уровня info . Налаживая мониторинг приложения с использованием Sentry, нужно учитывать, что эта платформа интегрирована с модулем logging . Вспомните — в нашем экспериментальном проекте уровень логирования был установлен в значение info . В результате Sentry записывает все события, уровень которых соответствует info и более высоким уровням, делая это в стиле «навигационной цепочки», что упрощает отслеживание ошибок.

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

Фильтрация записей по уровням логирования

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

Сведения о проекте

Код, использованный в данном руководстве, можно найти в этом GitHub-репозитории.

Итоги

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

Когда вы будете работать над своим следующим Python-проектом — не забудьте реализовать в нём механизмы логирования. И можете испытать бесплатную пробную версию Sentry.

О, а приходите к нам работать? �� ��

Мы в wunderfund.io занимаемся высокочастотной алготорговлей с 2014 года. Высокочастотная торговля — это непрерывное соревнование лучших программистов и математиков всего мира. Присоединившись к нам, вы станете частью этой увлекательной схватки.

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

Сейчас мы ищем плюсовиков, питонистов, дата-инженеров и мл-рисерчеров.

chud0 / logging.md

В Python есть отличная встроенная библиотека — logging. Часто ее противопоставляют print-ам, однако на мой взгляд это гораздо более весомый инструмент. Разобравшись с некотрыми приемами в работе, хочу поделиться с сообществом наиболее, на мой взгляд, интересными вещами. Данная заметка основана на официальной документации, и по сути является частичным вольным переводом.

Когда использовать logging

Для самого простого использования, модуль предоставляет функции debug(), info(), warning(), error() и critical(). Название функций соответствует названию уровней или серьезности логируемых событий. Рекомендации по использованию стандартных уровней сведены в таблицу (в порядке возрастания серьезности).

Уровень сообщений Когда использовать
CRITICAL Критическая ошибка, выполнение программы невозможно
ERROR Из-за серьезной ошибки программа не смогла выполнить какую-либо функцию
WARNING Индикация того что произошло что-то неожиданное или указывающее на проблемы в ближайшем будущем, программа все еще работает так как ожидается
INFO Подтверждения, когда программа работает так ожидается
DEBUG Вывод детальной информации при поиске проблем в программе

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

Simple example. (или В Бой!)

Самый простой пример использования модуля выглядит так:

import logging logging.warning("Warning message") logging.info("Info message") 

если запустить скрипт с этим кодом, то в консоли будет выведено:

WARNING:root:Warning message 

что мы видим: WARNING это индикация уровня события, root — имя логгера, Warning message сообщение. Пока не обращайте внимание на имя логгера, это будет объяснено позже. Строка logging.info(«Info message») была проигнорирована т.к. уровень INFO ниже уровня WARNING (который был установлен по умолчанию).

Модуль logging имеет модульный подход и предлагает несколько категорий компонентов: логгеры (loggers), обработчики (handlers), фильтры (filters) и объекты форматирования (formatters).

  • logger содержит интерфейс для логирования. Это основной объект, именно он создает записи в лог.
  • handler обработчик, который направляет созданные логгером записи в пункт назначения. Например вывод в консоль, запись в файл, отправка письма и т.д.
  • filter позволяет получить больший контроль над фильтрацией записей чем стандартные уровни логирования.

Базовый класс реализует только одно поведение: выстраивание иерархии логгеров при помощи имени логгера и точки. Например инициализирован логгер с именем A.B , тогда записи логгеров с именами A.B.C , A.B.C.D , A.B.D будут обработаны, а логгеров с именами A.BB или B.B.C отброшены.

  • formatter является шаблоном для форматирования записи. Возможные атрибуты для заполнения шаблона здесь

Способы конфигурации модуля.

Это базовый, простой способ. Рассмотрим его, на примере чтобы погрузится удивительнйый мир логирования (смайлик):

import logging logging.basicConfig( format='%(asctime)s - %(name)s - %(levelname)s - %(message)s', filename='example.log', filemode='w', level=logging.DEBUG, ) logging.debug('This message should go to the log file') logging.info('So should this') logging.warning('And this, too') 

Рассмотрим параметры переданные в baseConfig: format — преобразует вывод логера по переданному шаблону, filename — сообщает логгеру что необходимо логи заносить в файл с переданным названием example.log , filemod : w — перезаписывать файл при каждом запуске файла, a — дописывать в конец файла и наконец level устанавливает уровень логирования DEBUG . В результате выполнения будет создан файл filemod.log в котором окажутся записи:

2018-05-13 23:41:47,769 - root - DEBUG - This message should go to the log file 2018-05-13 23:41:47,769 - root - INFO - So should this 2018-05-13 23:41:47,769 - root - WARNING - And this, too 

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

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

import logging # создание логгера с именем "main" (может быть любым) logger = logging.getLogger('main') # установка уровня логирования logger.setLevel(logging.DEBUG) # создание обработчика с логированием в консоль cons_handler = logging.StreamHandler() # установка уровня логирования конкретно этого обработчика cons_handler.setLevel(logging.DEBUG) # создание обработчика с логированием в файл "2_example.log" file_handler = logging.FileHandler("3_example.log", mode="a") file_handler.setLevel(logging.WARNING) # создание шаблона отображения formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s') # связвание обработчиков с шаблоном форматирования cons_handler.setFormatter(formatter) file_handler.setFormatter(formatter) # добавление обработчиков логгеру logger.addHandler(cons_handler) logger.addHandler(file_handler) # использование логгера logger.debug('debug message') logger.info('info message') logger.warn('warn message') logger.error('error message') logger.critical('critical message') 

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

2018-05-15 22:40:07,974 - main - DEBUG - debug message 2018-05-15 22:40:07,974 - main - INFO - info message 2018-05-15 22:40:07,974 - main - WARNING - warn message 2018-05-15 22:40:07,975 - main - ERROR - error message 2018-05-15 22:40:07,975 - main - CRITICAL - critical message 

и файл с именем 3_example.log с содержимым:

2018-05-15 22:40:07,974 - main - WARNING - warn message 2018-05-15 22:40:07,975 - main - ERROR - error message 2018-05-15 22:40:07,975 - main - CRITICAL - critical message 

Хочу пояснить следующие моменты:

  • Первым делом получаем логгер — экземпляр класса Logger с именем main . Причем действует правило: одно имя — один экземпляр. Это означает что при первом вызове метода логгер создается, а при последующих передается уже созданный экземпляр логгера. На практике это означает что достаточно вызвать и настроить логгер в одном месте (модуле), выполнить этот код (импортировать модуль), во всех последующих местах вызывать настроеный логгер и. просто логировать.
  • Далее получаем обработчики. Полный список с описанием здесь их много и они разные: вывод в консоль, запись в файл (возможно с ротацией логов), отправка через сокет, http, UDP, отправка письмом, чтение/запись в очередь и т.д. Далее в приимерах будут те что пользовался я сам.
  • Нужно четко понимать что у логгера может быть множество обработчиков, каждый обработчик может иметь свой шаблон сообщения, уровень логирования и фильтрацию. Поэтому в консоль попали все сообщения логгера, а в файл с уровнем WARNING и выше.
  • И наконец получаем шаблоны сообщений. Параметры для шаблонов здесь, основные параметры далее в примерах примерах.

Оптимизация. Процесс подстановки аргументов в шаблон ленивый, и произойдет только если запись действительно будет обрабатываться, поэтому в функцию логирования нужно передавать шаблон строки с аргументами, например logger.debug(«received params %s», a) . Если же передавать заранее сформированную строку, то ресурсы системы будут потрачены независимо от того будет запись занесена в лог или нет.

Оптимизация. Вычисление аргуменов для логирования может быть долгим. Для того чтобы не терять время можно воспользоваться методом isEnabledFor логгера, который принимает уровень логирования, проверяет будет ли производится запись и возвращает ответ в True или False . Например:

if logger.isEnabledFor(logging.DEBUG): logger.debug('Message with %s', expensive_func()) 

Мой любимый способ. Сразу к примеру:

import logging import logging.config DEBUG = True LOGGING_CONF = < "disable_existing_loggers": True, "version": 1, "formatters": < "verbose": < "format": "%(levelname)-8s %(asctime)s [%(filename)s:%(lineno)d] %(message)s", "datefmt": "%Y-%m-%d %H:%M:%S", >, "brief": < "format": "%(levelname)-8s %(asctime)s %(name)-16s %(message)s", >>, "handlers": < "console": < "level": "DEBUG", "class": "logging.StreamHandler", "formatter": "verbose", >, "other_cons": < "level": "DEBUG", "class": "logging.StreamHandler", "formatter": "brief", >, >, "loggers": < "main": < "level": "INFO", "handlers": ["console"], >, "slave": < "level": "DEBUG" if DEBUG else "INFO", "handlers": ["other_cons"], >, >, > logging.config.dictConfig(LOGGING_CONF) logger = logging.getLogger("main") logger.info("loggers %s configured", ", ".join(LOGGING_CONF["loggers"])) 

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

В примере, переменная DEBUG как раз для такого контроля, эта переменная может импортироваться из настроек проекта и определять поведение целевых логгеров. Это может помочь выводить проект в production — не придется ходить по модулям и править все DEBUG = True на False .

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

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

INFO 2018-05-20 22:43:12 [4_dictConfig.py:45] loggers main, slave configured 

Загружает конфигурацию из файла, файл должен быть в формате библиотеки configparser. Мехнизм описания конфигурации в файле очень похож на словарь dictConfig -а. Сама конфигурация чуть более многословна, так же предоставляет полный контроль над логгерами.

По умолчанию disable_existing_loggers = True Вместо непосредственно файла может принимать экземпляр класса RawConfigParser, что позволяет хранить конфигурацию проекта в одном файле.

import logging import logging.config logging.config.fileConfig("5_logging.conf") logger = logging.getLogger("simpleExample") logger.debug("debug message") logger.info("info message") logger.warn("warn message") logger.error("error message") logger.critical("critical message") 
[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 datefmt= 
2018-05-20 23:31:29,215 - simpleExample - DEBUG - debug message 2018-05-20 23:31:29,216 - simpleExample - INFO - info message 2018-05-20 23:31:29,216 - simpleExample - WARNING - warn message 2018-05-20 23:31:29,216 - simpleExample - ERROR - error message 2018-05-20 23:31:29,217 - simpleExample - CRITICAL - critical message 

Код думаю понятен, переходим к седующему способу конфигурации.

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

Некоторые варианты использования

Как я уже упоминал, в логгерах, через имена, реализовано наследование. Рассмотрим пример:

import sys import logging # этот ужас из-за первой цифры в названии файла log_dict_conf = __import__("4_dictConfig") slave = __import__("6_inh_slave") logger = logging.getLogger("slave." + __name__) logger.debug("logger with name: %s created", logger.name) def simple_func(a, b, c): s = slave.sum(a, b) m = slave.mult(s, c) logger.debug("received params %s, %s, %s; return %s", a, b, c, m) return m if __name__ == "__main__": args = sys.argv[1:4] if len(args) == 3: logger.debug("received params from sys.argv") args = list(map(int, args)) else: args = [4, 5, 6] logger.debug("load default params") logger.info("received params %s, %s, %s", *args) logger.info(simple_func(*args)) 
import logging logger = logging.getLogger("slave." + __name__) logger.debug("logger with name: %s created", logger.name) def sum(a, b): s = a + b logger.debug("received params %s, %s; sum %s", a, b, s) return s def mult(a, b): m = a * b logger.debug("received params %s, %s; multiply %s", a, b, m) return m 

выполнив python 6_inh_main.py 1 2 3 в консоли получим:

INFO 2018-05-24 00:54:14 [4_dictConfig.py:45] loggers main, slave configured DEBUG 2018-05-24 00:54:14,411 slave.6_inh_slave logger with name: slave.6_inh_slave created DEBUG 2018-05-24 00:54:14,412 slave.__main__ logger with name: slave.__main__ created DEBUG 2018-05-24 00:54:14,412 slave.__main__ received params from sys.argv INFO 2018-05-24 00:54:14,412 slave.__main__ received params 1, 2, 3 DEBUG 2018-05-24 00:54:14,412 slave.6_inh_slave received params 1, 2; sum 3 DEBUG 2018-05-24 00:54:14,412 slave.6_inh_slave received params 3, 3; multiply 9 DEBUG 2018-05-24 00:54:14,412 slave.__main__ received params 1, 2, 3; return 9 INFO 2018-05-24 00:54:14,412 slave.__main__ 9 

Пройдем по порядку. Для начала имортируем модуль 4_dictConfig в котором инициализируем логгеры, это он в первой строке сообщает какие логгеры были настроены. Мне нравится подход, при котром логгеры инициализируюися в одном модуле, и затем получаются getLogger -ом по необходимости.

Затем имортируется модуль 6_inh_slave , и в нем, при вызове getLogger -а к имени инициализированного логгера slave через точку добавлен __name__ (вернет имя модуля если модуль импортируется), что определяет логгер-потомок slave -а с именем slave.6_inh_slave. Логгер-потомок наследует поведение логгера-родителя, однако теперь понятно из логгера какого модуля была сделана запись. Можно в наследовании подставлять имя пакета, название функционального блока или класса, здесь как душе угодно.

Логирование в Python

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

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

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

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

Модуль Logging

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

Добавить logging в вашу программу на Python так же просто, как написать эту строчку:

import logging

С импортированным модулем logging вы можете использовать то, что называется «logger», для логирования сообщений, которые вы хотите видеть. По умолчанию существует 5 стандартных уровней severity, указывающих на важность событий. У каждого есть соответствующий метод, который можно использовать для логирования событий на выбранном уровне severity. Список уровней в порядке увеличения важности:

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

import logging logging.debug('This is a debug message') logging.info('This is an info message') logging.warning('This is a warning message') logging.error('This is an error message') logging.critical('This is a critical message')

Вывод вышеупомянутой программы будет выглядеть так:

WARNING:root:This is a warning message ERROR:root:This is an error message CRITICAL:root:This is a critical message

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

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

Базовая конфигурация

Вы можете использовать метод basicConfig (**kwargs) для настройки ведения логов:

«Вы можете заметить, что модуль logging нарушает руководство по стилю PEP8 и использует соглашения camelCase в именнование переменных. Это потому, что он был адоптирован из пакета Log4j (утилиты ведения логов в Java). Это известная проблема в пакете, но к тому времени, когда было решено добавить ее в стандартную библиотеку, она уже была принята пользователями, и изменение ее в соответствии с требованиями PEP8 вызовет проблемы обратной совместимости ». (Источник)

Вот некоторые из часто используемых параметров для basicConfig():

  • level : Корневой логер с установленным указанным уровнем важности (severity).
  • filename : Указание файла логов
  • filemode : Режим открытия файла. По умолчанию это a, что означает добавление.
  • format : Формат сообщений.

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

import logging logging.basicConfig(level=logging.DEBUG) logging.debug('This will get logged')
DEBUG:root:This will get logged

Теперь будут регистрироваться все события на уровне DEBUG или выше.

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

import logging logging.basicConfig(filename='app.log', filemode='w', format='%(name)s - %(levelname)s - %(message)s') logging.warning('This will get logged to a file')
root - ERROR - This will get logged to a file

Сообщение будет записано в файл с именем app.log вместо вывода в консоль. Для filemode значение w означает, что файл журнала открывается в «режиме записи» каждый раз, когда вызывается basicConfig(), и при каждом запуске программы файл перезаписывается. Конфигурацией по умолчанию для filemode является a, которое является добавлением.

Вы можете настроить корневой logger еще больше, используя дополнительные параметры для basicConfig(), которые можно найти здесь.

Следует отметить, что вызов basicConfig() для настройки корневого logger работает, только если корневой logger не был настроен ранее. По сути, эта функция может быть вызвана только один раз.

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

Формат вывода

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

import logging logging.basicConfig(format='%(process)d-%(levelname)s-%(message)s') logging.warning('This is a Warning')
18472-WARNING-This is a Warning

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

Вот еще один пример, где вы можете добавить информацию о дате и времени:

import logging logging.basicConfig(format='%(asctime)s - %(message)s', level=logging.INFO) logging.info('Admin logged in')
2018-07-11 20:12:06,288 - Admin logged in

%(asctime)s добавляет время создания LogRecord. Формат можно изменить с помощью атрибута datefmt, который использует тот же язык форматирования, что и функции форматирования в модуле datetime, например time.strftime():

import logging logging.basicConfig(format='%(asctime)s - %(message)s', datefmt='%d-%b-%y %H:%M:%S') logging.warning('Admin logged out')
12-Jul-18 20:53:19 - Admin logged out

Вы можете найти больше информации о формате datetime в этом руководстве.

Логирование переменных

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

import logging name = 'John' logging.error('%s raised an error', name)
ERROR:root:John raised an error

Аргументы, передаваемые методу, будут включены в сообщение в качестве переменных.

Хотя вы можете использовать любой стиль форматирования, f-строки, представленные в Python 3.6, являются лучшим способом форматирования строк, поскольку они могут помочь сделать форматирование коротким и легким для чтения:

import logging name = 'John' logging.error(f' raised an error')
ERROR:root:John raised an error

Вывод стека

Модуль регистрации также позволяет вам захватывать стек выполнения в приложении. Информация об исключении может быть получена, если параметр exc_info передан как True, а функции ведения журнала вызываются таким образом:

import logging a = 5 b = 0 try: c = a / b except Exception as e: logging.error("Exception occurred", exc_info=True)
ERROR:root:Exception occurred Traceback (most recent call last): File "exceptions.py", line 6, in c = a / b ZeroDivisionError: division by zero [Finished in 0.2s]

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

ERROR:root:Exception occurred

Совет: если вы логируете в обработчике исключений (try..except…), используйте метод logging.exception(), который регистрирует сообщение с уровнем ERROR и добавляет в сообщение информацию об исключении. Проще говоря, вызов logging.exception() похож на вызов logging.error (exc_info = True). Но поскольку этот метод всегда выводит информацию об исключении, его следует вызывать только в обработчике исключений. Взгляните на этот пример:

import logging a = 5 b = 0 try: c = a / b except Exception as e: logging.exception("Exception occurred")
ERROR:root:Exception occurred Traceback (most recent call last): File "exceptions.py", line 6, in c = a / b ZeroDivisionError: division by zero [Finished in 0.2s]

Использование logging.exception() покажет лог на уровне ERROR. Если вы не хотите этого, вы можете вызвать любой из других методов ведения журнала от debug() до critical() и передать параметр exc_info как True.

Классы и функции

До сих пор мы видели logger по умолчанию с именем root, который используется модулем logging всякий раз, когда его функции вызываются непосредственно таким образом: logging.debug(). Вы можете (и должны) определить свой собственный logger, создав объект класса Logger, особенно если ваше приложение имеет несколько модулей. Давайте посмотрим на некоторые классы и функции в модуле.

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

  • Logger : Это класс, чьи объекты будут использоваться в коде приложения напрямую для вызова функций.
  • LogRecord : Logger автоматически создает объект LogRecord, в котором находиться вся информация, относящаяся к регистрируемому событию, например, имя логера, функции, номер строки, сообщение и т. д.
  • Handler : Обработчики отправляют LogRecord в требуемое место назначения вывода, такое как консоль или файл. Обработчик является основой для подклассов, таких как StreamHandler, FileHandler, SMTPHandler, HTTPHandler и других. Эти подклассы отправляют выходные данные журнала соответствующим адресатам, таким как sys.stdout или файл на диске.
  • Formatter : Здесь вы указываете формат вывода, задавая строковый формат, в котором перечислены атрибуты, которые должны содержать выходные данные.

Из всего перечисленного мы в основном имеем дело с объектами класса Logger, которые создаются с помощью функции уровня модуля logging.getLogger(name). Многократные вызовы getLogger() с одним и тем же именем возвращают ссылку на один и тот же объект Logger, что избавляет нас от передачи объектов logger в каждую часть, где это необходимо. Вот пример:

import logging logger = logging.getLogger('example_logger') logger.warning('This is a warning')
This is a warning

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

WARNING:example_logger:This is a warning

Опять же, в отличие от корневого logger, пользовательский logger нельзя настроить с помощью basicConfig(). Вы должны настроить его с помощью Handlers и Formatters:

Использование Handlers

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

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

Подобно logger, вы также можете установить уровень severity в обработчиках. Это полезно, если вы хотите установить несколько обработчиков для одного и того же logger, но хотите иметь разные уровни severity для каждого из них. Например, вы можете захотеть, чтобы журналы с уровнем WARNING и выше регистрировались на консоли, но все с уровнем ERROR и выше также должно быть сохранены в файл. Вот пример кода, который делает это:

# logging_example.py import logging # Create a custom logger logger = logging.getLogger(__name__) # Create handlers c_handler = logging.StreamHandler() f_handler = logging.FileHandler('file.log') c_handler.setLevel(logging.WARNING) f_handler.setLevel(logging.ERROR) # Create formatters and add it to handlers c_format = logging.Formatter('%(name)s - %(levelname)s - %(message)s') f_format = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s') c_handler.setFormatter(c_format) f_handler.setFormatter(f_format) # Add handlers to the logger logger.addHandler(c_handler) logger.addHandler(f_handler) logger.warning('This is a warning') logger.error('This is an error')
__main__ - WARNING - This is a warning __main__ - ERROR - This is an error

Здесь logger.warning() создает LogRecord, который содержит всю информацию о событии, и передает ее всем имеющимся обработчикам: c_handler и f_handler.

c_handler является StreamHandler с уровнем WARNING и берет информацию из LogRecord для генерации вывода в указанном формате и выводит его на консоль. f_handler – это FileHandler с уровнем ERROR, и он игнорирует LogRecord, так как его уровень – WARNING.

Когда вызывается logger.error(), c_handler ведет себя точно так же, как и раньше, а f_handler получает LogRecord на уровне ERROR, поэтому он продолжает генерировать вывод точно так же, как c_handler, но вместо вывода на консоль, он записывает сообщение в указанный файл в этом формате:

2018-08-03 16:12:21,723 - __main__ - ERROR - This is an error

Имя logger, соответствующее переменной __name__, записывается как __main__, то есть имя, которое Python присваивает модулю, с которого начинается выполнение. Если этот файл импортируется каким-либо другим модулем, то переменная __name__ будет соответствовать его имени logging_example. Вот как это будет выглядеть:

# run.py import logging_example
logging_example - WARNING - This is a warning logging_example - ERROR - This is an error

Другие методы настройки

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

Вот пример файла конфигурации:

[loggers] keys=root,sampleLogger [handlers] keys=consoleHandler [formatters] keys=sampleFormatter [logger_root] level=DEBUG handlers=consoleHandler [logger_sampleLogger] level=DEBUG handlers=consoleHandler qualname=sampleLogger propagate=0 [handler_consoleHandler] class=StreamHandler level=DEBUG formatter=sampleFormatter args=(sys.stdout,) [formatter_sampleFormatter] format=%(asctime)s - %(name)s - %(levelname)s - %(message)s

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

Чтобы загрузить этот файл конфигурации, вы должны использовать fileConfig():

import logging import logging.config logging.config.fileConfig(fname='file.conf', disable_existing_loggers=False) # Get the logger specified in the file logger = logging.getLogger(__name__) logger.debug('This is a debug message')
2018-07-13 13:57:45,467 - __main__ - DEBUG - This is a debug message

Путь к файлу конфигурации передается в качестве параметра методу fileConfig(), а параметр disable_existing_loggers используется для сохранения или отключения logger, которые присутствуют при вызове функции. По умолчанию установлено значение True, если не упомянуто.

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

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: sampleLogger: level: DEBUG handlers: [console] propagate: no root: level: DEBUG handlers: [console]

Пример, который показывает, как загрузить конфигурацию из файла yaml:

import logging import logging.config import yaml with open('config.yaml', 'r') as f: config = yaml.safe_load(f.read()) logging.config.dictConfig(config) logger = logging.getLogger(__name__) logger.debug('This is a debug message')
2018-07-13 14:05:03,766 - __main__ - DEBUG - This is a debug message

Заключение

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

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

Выбираем логирование в Python: logging vs loguru

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

Пример куска лога обучения модели

logging vs loguru

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

Loguru же наоборот, позиционирует себя как максимально простая библиотека для логирования в Python.

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

Базовое применение

Сравним код для самого базового логирования. Будем записывать лог в файл.

import logging logging.basicConfig(filename='logs/logs.log', level=logging.DEBUG) logging.debug('Error') logging.info('Information message') logging.warning('Warning')

Разберем немножко код. basicConfig — создаёт базовую конфигурацию для нашего логирования, filename — путь к файлу лога, level — уровень логирования. При logging.DEBUG он будет пропускать все записи в лог.

from loguru import logger logger.add('logs/logs.log', level='DEBUG') logger.debug('Error') logger.info('Information message') logger.warning('Warning')

Думаю тут всё понятно и код выглядит весьма похоже. Но посмотрим на результат в файле и консоли.

DEBUG:root:Error INFO:root:Information message WARNING:root:Warning 2021-02-04 17:44:10.914 | DEBUG | main::14 - Error 2021-02-04 17:44:10.915 | INFO | main::15 - Information message 2021-02-04 17:44:10.915 | WARNING | main::16 - Warning

Результат Loguru

И в консоли и в файле Loguru выглядит поинформативней сразу по умолчанию.

Форматирование

Давайте теперь попробуем сделать форматирование в Logger. Для этого есть метод .setFormatter Будем выводить время события, тип и само событие как в Loguru.

import logging import sys logger = logging.getLogger() logger.setLevel(logging.DEBUG) fileHandler = logging.FileHandler('logs/logs.log') fileHandler.setFormatter(logging.Formatter(fmt='[%(asctime)s: %(levelname)s] %(message)s')) logger.addHandler(fileHandler) streamHandler = logging.StreamHandler(stream=sys.stdout) streamHandler.setFormatter(logging.Formatter(fmt='[%(asctime)s: %(levelname)s] %(message)s')) logger.addHandler(streamHandler) logging.debug('Error') logging.info('Information message') logging.warning('Warning')

Ох ты ж! Кода стало гораздо больше. Давайте разберем новые классы и методы. Для начала у нас есть класс Handler . FileHandler для записи в файл и StreamHandler для запись в консоль. Затем нужно с помощью метода addHandler передать их в наш logger. В документации вы найдете еще несколько Handler .

Теперь разберемся с классом Formatter . Из названия понятно, что этот класс отвечает за формат записи нашего лога. В нашем примере мы добавили помимо самого сообщения время записи и его тип. Теперь наш лог выглядит так:

[2021-02-04 21:28:28,283: DEBUG] Error [2021-02-04 21:28:28,283: INFO] Information message [2021-02-04 21:28:28,283: WARNING] Warning

В Loguru тоже есть форматирование. Делается это так: logger.add(‘logs/logs.log’, level=’DEBUG’, format=» «)

Ротация / очистка / архивирование

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

import logging import time from logging.handlers import RotatingFileHandler def create_rotating_log(path): logger = logging.getLogger("Rotating Log") logger.setLevel(logging.INFO) handler = RotatingFileHandler(path, maxBytes=20, backupCount=5) logger.addHandler(handler) for i in range(10): logger.info("This is test log line %s" % i) time.sleep(1.5) if name = : log_file = "test.log" create_rotating_log(log_file)

Тут используется RotatingFileHandler . maxBytes — максимальный размер файла, backupCount — сколько файлов хранить.

Посмотрим как это можно сделать в Loguru:

logger.add("file_1.log", rotation="500 MB") # Пишет в новый файл после достижения размера лога 500 MB logger.add("file_2.log", rotation="12:00") # В 12:00 создаёт новый файл logger.add("file_X.log", retention="10 days") # Очищает наш лог после 10 дней logger.add("file_Y.log", compression="zip") # Архивирует наши логи

Опять всё выглядит попроще и удобнее.

Обработка исключений

В Logging есть отдельный метод — exception . Это достаточно удобно и нужно применять его в блоке try except.

import logging def my_function(x, y, z): return x / (y * z) try: my_function(1, 2, 0) except ZeroDivisionError: logging.exception("message")

Лог будет выгледеть так:

ERROR:root:message Traceback (most recent call last): File "logs.py", line 5, in my_function(1, 2, 0) File "logs.py", line 3, in my_function return x / (y * z) ZeroDivisionError: division by zero

В Loguru нам будет нужно использовать декоратор @logger.catch :

from loguru import logger @logger.catch def my_function(x, y, z): return x / (y * z) my_function(1, 2, 0)

Вау! Лог выглядит круто. Даже показывает значение переменных:

Loguru обработка исключений

Заключение

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

Добавить комментарий

Ваш адрес email не будет опубликован. Обязательные поля помечены *