Что такое логирование в python
Логирование в Python
Python предлагает весьма сильную библиотеку логирования в стандартной библиотеке. Многие программисты используют оператор print для лечения багов (в том числе и я), но вы можете использовать логирование для этих целей. Использование лога также более чистый метод, если вы не хотите просматривать весь свой код, чтобы удалить все операторы print. В данном разделе мы рассмотрим следующее:
К концу данного раздела вы сможете уверенно создавать логи для своих приложений. Приступим!
Создаем простой логгер
Создание лога при помощи модуля logging это очень просто. Для начала, будет проще взглянуть на часть кода и объяснить его:
Как и ожидалось, чтобы получит доступ к модулю logging, для начала нужно импортировать модуль. Простейший способ создания лога – это использовать функцию basicConfig модуля logging и передать ей несколько ключевых аргументов. Функция принимает следующее: filename, filemode, format, datefmt, level и stream. В нашем примере, мы передадим её названию файла и уровню логирования, что мы и настроим в INFO.
Существует пять уровней логирования (в порядке возрастания): DEBUG, INFO, WARNING, ERROR и CRITICAL. По умолчанию, если вы запустите этот код несколько раз, он добавится в лог, если он существует. Если вы хотите, чтобы ваш логгер перезаписывал лог, передайте его filemode=”w”, как было указано в комментарии к коду. Говоря о запуске кода, вы должны получить следующий результат, после запуска:
Python: Логируем как профессионалы
Часто вижу, что помимо обработки исключений, люди мучаются кое с чем еще, а именно с логированием.
Большинство людей не знают, что писать в логи, поэтому решают логировать все, что угодно, думая, что все подряд – это в любом случае лучше, чем ничего, и, в конечном итоге, просто создают шум. А шум – это информация, которая никак не помогает вашей команде понять, в чем дело и как решить проблему.
Более того, я не думаю, что эти люди могут уверенно пользоваться уровнями логирования, поэтому используют по умолчанию logger.info везде (если не пишут print ).
Наконец, люди, похоже, не знают, как сконфигурировать логирование в Python, понятия не имеют, что такое обработчики, фильтры, методы форматирования (форматтеры) и т.д.
Цель этой статьи – разъяснить, что такое логирование и как вы должны его реализовывать. Я постараюсь привести содержательные примеры и обеспечить вас гибкими эмпирическими приемами, которые следует использовать при логировании в любом приложении, которое вы когда-либо будете создавать.
Введение
Примеры облегчают визуальное восприятие, поэтому мы будем рассматривать следующую систему:
Пользователи могут подключать несколько интеграций к ресурсам (например, GitHub, Slack, AWS и т.д.)
Ресурсы уникальны в зависимости от интеграции (например, репозитории списков с GitHub, диалоги из Slack, экземпляры списков EC2 из AWS и т.д.)
Каждая интеграция уникальна, имеет свой набор сложностей, конечных точек, шагов и т.д.
Каждая интеграция может привести к различным ошибкам, которые могут возникнуть в любое время (например, неверная аутентификация, ресурс не существует и т.д.)
Я не буду сосредотачиваться на проблемах поддержки таких интеграций, просто пронаблюдаем за тем, как это работает.
Природа логирования: хорошее логирование имеет значение
Для начала давайте проанализируем характеристики логов.
«Наглядными» мы их называем потому, что они предоставляют вам какую-то информацию, «контекстными», потому что они дают вам общее представление о том, как обстоят дела на данный момент времени. И наконец, «реактивными» они являются потому, что они позволяют вам предпринимать действия только после того, как что-то произошло (даже если ваши логи отправляются/получаются в режиме реального времени, на самом деле вы не можете изменить то, что произошло только что).
Если вы не будете учитывать природу логов, то будете производить только шум, что снизит вашу производительность.
Дальше я приведу несколько примеров, основанных на системе, которую мы определили выше:
Если вы зададите описание, к примеру «operation connect failed», но не добавите контекст, трудно будет понять, какая из интеграций не отработала, кто пострадал, на каком этапе подключения произошел сбой, поэтому и среагировать вы не можете. В конечном итоге вы будете копаться в тонне логов без малейшего представления о том, где может быть проблема.
О, а еще не стоит недооценивать способность разработчика испортить описание. Сделать это легко, просто отправив поверхностные сообщения без какого-либо контекста, например «An error happened» или «An unexpected exception was raised». Если я прочту такое, то даже не пойму, на что повлияла ошибка, потому что не буду знать, ЧТО конкретно произошло. Так что да, можно сломать даже основной смысл логов.
Логи – это конфиденциальная информация из вашего программного обеспечения, нужная чтобы вы оставались в курсе происходящего и могли реагировать на ситуации. Любые логи, которые не дают вам такой информации – это шум.
Когда нужно логировать?
Чтобы логи оставались реактивными, вам нужно логировать «события». Сделайте их такими же понятными и удобными для чтения, как эта статья. Возможно, вы не прочитали каждую строку, которую я написал выше, но вы все равно можете продолжить дальше, пропустить ненужные разделы и сосредоточиться на том, что привлекло ваше внимание. Логи должны быть такими же.
Есть эмпирическое правило построение логов:
В начале соответствующих операций или потоков (например, при подключении к сторонним сервисам и т.д.);
При любом достигнутом прогрессе (например, успешная аутентификация, получен валидный код ответа и т.д.);
При завершении операции (успешном или неудачном).
Логи должны рассказывать вам историю, у каждой истории есть начало, середина и конец.
Будьте осторожны с релевантностью, добавлять логи проще, чем удалять их, ведь все, что нерелевантно – шум.
Что логировать?
Чтобы логи были наглядными и контекстными, нужно предоставлять правильный набор информации, и я не могу сказать, какая информация будет являться таковой, не зная вашего случая. Давайте вместо этого воспользуемся нашим примером.
Рассмотрим интеграцию с AWS в качестве примера. Было бы круто иметь следующие сообщения:
Хороший пример логов
Сообщение
Понимание картины
Контекст
Началась операция с AWS
Атрибуты лога должны позволить мне выяснить, кто его вызвал
Retrieved instances from all regions
Был достигнут существенный прогресс
Connection to AWS has been successful
Операция с AWS завершилась
Атрибуты лога должны позволить мне найти сущности, на которые операция произвела положительный эффект
Пример логов об ошибках
Допустим, что извлечь экземпляры из региона af-south-1 не удалось из-за какой-то внезапной ошибки в этом регионе.
Сообщение
Понимание картины
Контекст
Началась операция с AWS
Атрибуты лога должны позволить мне выяснить, кто его вызвал
Failed to retrieve instances from regions af-south-1 when connecting to AWS for user X
Операция AWS не завершена, произошел сбой в регионе af-south-1, пострадал пользователь X
Я должен иметь возможность увидеть трассировку стека ошибки, чтобы понять, почему извлечение не удалось
В обоих случаях, я могу отследить, когда произошло какое-то событие (в логах есть отметки о времени), что именно произошло и кто от этого пострадал.
Я решил не указывать пользователя при начале и успешном завершении операции, потому что это не имеет значения (ведь это шум), поскольку:
Если я знаю, что что-то запустилось, но не знаю результата выполнения, то что я могу сделать?
Если все хорошо, то зачем беспокоиться?
Добавление таких данных делает логи шумными, потому что на них невозможно реагировать, делать-то с этим ничего не надо! Но я все еще должен быть в состоянии собрать детальную информацию из атрибутов (кто, когда, почему и т.д.). Если вы хотите что-то измерить, вам следует воспользоваться метриками, а не логами.
С другой стороны, логи об ошибках кажутся более подробными, и так и должно быть! Чтение таких логов дает достаточно уверенности, чтобы немедленно перейти к действиям:
Свяжитесь с пользователем Х и сообщите ему, что вам известно о проблеме в этом регионе.
Ключевой момент следующий: вы можете отреагировать сразу и для этого вам не требуется более глубокого изучения ситуации. Вы знаете все, что вам нужно, и можете немедленно принять меры для уменьшения ущерба. Разработчикам, возможно, потребуется углубиться в трассировку стека, чтобы собрать больше контекста (в случае с ошибкой), но общая картина уже становится ясна.
Любое сообщение об ошибке, в котором отсутствует эта минимальная информация, становится шумом, поскольку у вас появляется беспокойство, но вы все еще не можете действовать. Сначала нужно углубиться в ситуацию, чтобы понять, насколько проблема серьезна.
Если вы все еще не поняли, как писать полезные сообщения, я поделюсь с вами очень простым лайфхаком:
Всегда спрашивайте себя: Что я хочу уяснить для себя, после получения такого лога?
Предоставление контекста с помощью Python
В Python атрибуты логов можно добавить с помощью дополнительного поля, например:
Контекст не отменяет необходимости в содержательных сообщениях! Поэтому я бы так не делал:
Сообщения должны быть четкими и не оставлять места вопросам о том, что же вообще происходит. Контекст должен обогащать ваш опыт, предоставив информацию о более глубоких деталях, и давать вам понимание, по какой причине что-то произошло.
Нечто большее, чем logger.info и logger.error
Не так-то просто понять, что происходит, когда тысячи клиентов выдают логи «Connecting to Slack». Поскольку вы выдаете логи, а вашим приложением пользуются несколько клиентов, нужно иметь возможность фильтровать информацию по релевантности.
Чтобы упростить ситуацию, вот вам новое эмпирическое правило (будьте гибкими):
Уровень
Когда используется
Для какой-то действительно повторяющейся информации. Возможно, было бы полезно выдавать весь контекст информации, но порой этого не нужно.
Когда происходит что-то важное, достойное того, чтобы о нем было известно большую часть времени.
Случилось что-то странное (но не прервало поток/операцию). Если проблема возникнет на более поздних этапах, такой лог может дать вам подсказку.
Произошла ошибка, ее следует устранить как можно быстрее.
Произошла очень серьезная ошибка, она требует немедленного вмешательства. Если не уверены в критичности ошибки, применяйте ERROR .
Для описанной системы/потоков, я бы использовал уровни логов, как определено:
Что делать с logger.critical и logger.warning ?
WARNING – недостаточно веская причина для остановки потока, однако это предупреждение на будущее, если возникнет какая-то проблема.
CRITICAL – самый тревожный предупреждающий лог, который вы когда-либо получите. По сути, он должен быть той самой причиной встать в три часа ночи и пойти что-то чинить.
Для этих случаев мы рассмотрим:
Для AWS: если какой-то регион AWS недоступен, мы можем предположить, что у пользователя там нет никаких ресурсов, поэтому можно двигаться дальше.
Для Slack: если OAuth завершится неудачно из-за невалидного id клиента, значит остальные пользователи столкнутся с той же проблемой, интеграция не отработает, пока мы вручную не сгенерируем новый id. Это дело кажется достаточно критичным.
Непопулярное мнение: использование DEBUG -уровня на продакшене
Да, я считаю, что логи DEBUG нужно использовать на продакшене.
Другой вариант – включить дебаг после того, как странная ошибка потребует более детального разбирательства.
Простите, но для меня такой вариант недопустим.
В реальном мире клиентам нужна быстрая реакция, командам нужно выполнять свою работу и постоянно поддерживать системы в рабочем состоянии. У меня нет времени и пропускной способности для нового деплоя или включения флага и ожидания повторения проблемы. Я должен реагировать на неожиданные проблемы в считанные секунды, а не минуты.
Правильно настройте логгер
Еще я замечаю, что люди испытывают трудности при настройке логгера (или вообще его не настраивают). Конечно, документация в Python не очень дружелюбная, но это не оправдание, чтобы вообще ее не трогать.
Использование ручных команд непросто поддерживать и понимать;
fileConfig – негибкая история, у вас не бывает динамических значений (без дополнительных фокусов);
dictConfig – простая история в запуске и настройке.
Я поделюсь несколькими советами и определениями, которые вам надо знать, а затем мы создадим окончательную конфигурацию на реальных примерах из проектов, над которыми я работаю.
Вот кусочек того, о чем мы будем говорить дальше:
Что такое логгеры?
В любом случае, придерживайтесь:
Форматируйте логи
Форматтеры вызываются для вывода конечного сообщения и отвечают за него преобразование в конечную строку.
Когда я работал в Zak (бывшем Mimic), и даже сегодня в Lumos мы форматировали логи как JSON. Он является хорошим стандартом для систем, работающих на продакшене, поскольку содержит множество атрибутов. Проще визуализировать JSON, чем обычную длинную строку, и для этого вам не нужно создавать свой собственный форматтер (ознакомьтесь с python-json-logger).
Для локальной разработки я рекомендую использовать форматирование по умолчанию для простоты.
Ваше решение будет зависеть от вида проекта. Для Tryceratops я решил использовать обычный форматтер, поскольку он проще и работает локально, там нет нужды в JSON.
Фильтруйте логи
Фильтры можно использовать либо для фильтрации логов (внезапно), либо для добавления дополнительного контекста в запись лога. Рассматривайте фильтры, как хуки, вызываемые до обработки итогового лога.
Их можно определить следующим образом:
Или их можно добавить прямо в логгер или обработчик для упрощения фильтрации по уровням (скоро будут примеры).
Обрабатывайте логи и то, как все связано
Обработчики представляют из себя комбинации форматтеров, выходных данных (потоков) и фильтров.
С ними вы можете создавать следующие комбинации:
Выводить все логи из info (фильтр), а потом выводить JSON в консоль.
Выводить все логи, начиная с error (фильтр) в файл, содержащий только сообщение и трассировку стека (форматтер).
Наконец логгеры указывают обработчикам.
Пример logging.dictConfig
Теперь, когда вы понимаете, что делают все эти объекты, давайте писать собственные! Как всегда, я постараюсь показать вам примеры из реальной жизни. Я буду использовать конфигурацию Tryceratops. Вы можете открыть ссылку и посмотреть самостоятельно окончательную конфигурацию.
Шаблон конфигурации логирования
Начнем с такого каркаса, создадим константу LOGGING_CONFIG :
Version всегда будет 1. Это плейсхолдер для возможных следующих релизов. На данный момент версия всего одна.
Я рекомендую оставить значение disable_existing_loggers в False, чтобы ваша система не поглощала другие неожиданные проблемы, которые могут возникнуть. Если вы хотите изменить другие логгеры, я бы порекомендовал их явно переписать (хоть это и скучно).
Корневой логгер можно определить тремя разными способами, что сбивает с толку:
Выбирайте любой! Мне нравится оставлять его снаружи, поскольку так он выглядит очевиднее и подробнее говорит о том, чего я хочу, ведь корневой логгер влияет на все другие определенные логгеры.
Конфигурация логирования: форматтеры
Я дополню пример из Tryceratops примером с JSON из Lumos.
Конфигурация логирования: обработчики
Конфигурация логирования: логгеры и root
Давайте разберемся, что происходит:
Кроме того, обратите внимание, что я могу переписать правила по умолчанию. Через настройки или позже динамически. Например, каждый раз, когда triceratops получает подобный флаг от CLI, он обновляет конфигурацию logging чтобы включить дебаг.
Логирование – это важно, но наличие хорошо структурированных исключений и блоков try/except также важно, поэтому вы можете также прочитать, как профессионально обрабатывать и структурировать исключения в Python.
Всех желающих приглашаем на demo-занятие «Основы ООП». Цели занятия: научиться работать с классами и познакомиться с наследованием.
Краткое содержание:
— мутабельность экземпляров класса
— передача аргументов в инициализатор
— наследование
— переопределение методов
— обращение к методам суперкласса
>> РЕГИСТРАЦИЯ
Логирование в Python – основы работы и примеры
В этом руководстве мы изучим основы стандартного модуля логирования в Python.
Что такое логирование в Python?
Logging в Python- это модуль в стандартной библиотеке, который обеспечивает возможность работы со средой для выпуска сообщений журнала из программ Python. Логирование используется для отслеживания событий, происходящих при запуске программного обеспечения.
Этот модуль широко используется разработчиками при работе с логами. Это очень важный инструмент, который используется при разработке, запуске и отладке программного обеспечения. Логирование полезно для хранения записей журнала. Предположим, что запись в журнале отсутствует, а программа прерывается во время своего выполнения, мы не сможем найти истинную причину проблемы.
Каким-то образом мы обнаруживаем причину сбоя, но на ее устранение уйдет много времени. Используя ведение журнала, мы можем оставить “следы”, чтобы, если проблема возникла в программе, мы могли легко найти причину проблемы.
Как работает регистрация
Logging – мощный модуль, используемый как новичками, так и профессионалами. Этот модуль обеспечивает навыки для организации различных обработчиков элементов управления и передачи сообщений журнала этим обработчикам.
Чтобы выпустить сообщение журнала, нам нужно импортировать модуль ведения журнала следующим образом.
Теперь мы вызовем средство логирования, чтобы записывать сообщения, которые мы хотим видеть. Модуль регистрации предлагает пять уровней, определяющих серьезность событий. Каждое событие содержит параллельные методы, которые можно использовать для регистрации событий на уровне серьезности. Давайте разберемся в следующих событиях и их работе.
Вышеуказанных уровней достаточно для решения любых проблем. Соответствующие числовые значения уровней приведены ниже.
Уровень | Числовые значения |
---|---|
NOTSET | 0 |
DEBUG | 10 |
INFO | 20 |
WARNING | 30 |
ERROR | 40 |
CRITICAL | 50 |
Модуль регистрации предлагает множество функций. Он состоит из нескольких констант, классов и методов. Константы представлены последними заглавными буквами; классы обозначаются заглавными буквами. Элементы в нижнем регистре представляют методы.
Давайте посмотрим на несколько объектов регистратора, предлагаемых самим модулем.
Давайте разберемся в следующем примере.
Как видно из вышеприведенного вывода, каждое сообщение отображается вместе с корнем, который представляет собой имя модуля ведения журнала, присвоенное его регистратору по умолчанию. Сообщение и имя уровня разделяются двоеточием(:) и печатают сообщения в формате вывода по умолчанию.
Мы можем заметить, что сообщения debug() и info() не отображали сообщения, потому что по умолчанию модуль журнала регистрирует сообщения с уровнем серьезности WARNING, ERROR и CRITICAL.
Базовые конфигурации
Основная задача логирования – хранить записи событий в файле. Модуль предоставляет basicConfig(** kwarg), используемый для настройки ведения журнала.
Он принимает некоторые из наиболее часто используемых аргументов следующим образом:
Мы можем установить уровень сообщений журнала, используя параметр уровня, который мы хотим записывать. Нам нужно передать одну константу в класс, которая разрешила бы все вызовы логирования.
Точно так же мы можем записывать сообщение в файл вместо отображения на консоли, имя файла и режим файла могут использоваться в функции basicConfig(), и мы можем определять формат сообщения с помощью атрибутов формата. Давайте разберемся в следующем примере.
Приведенный выше вывод будет отображаться в файле msg.log вместо консоли. Мы открыли файл в w, что означает, что файл открыт в «режиме записи». Если basicConfig() вызывается несколько раз, то каждый запуск программы будет перезаписывать вывод файла журнала. Функцию basicConfig() можно изменить, передав дополнительные аргументы https://docs.python.org/3/library/logging.html#logging.basicConfig.
Приведенный выше код сгенерирует файл, и мы сможем увидеть результат при открытии файла.
Форматирование вывода
Строка, переданная в программе как сообщение для журнала, может быть изменена в соответствии с нашими требованиями. В данной строке и части Logrecord есть несколько основных элементов. Давайте разберемся в следующем примере.
Аргумент формата может принимать строку с атрибутами Logrecord в любой форме, которая нам требуется.
Атрибуты%(asctime) добавляют время создания записи журнала. Мы также можем настроить формат с помощью атрибутов datefmt, которые предоставляют ту же функцию, что и модуль datetime.
Регистрация переменных данных
Иногда мы хотим включить динамическую информацию из приложения в журнал. Методы ведения журнала принимают строку в качестве аргумента, и рекомендуется отформатировать строку с помощью переменных данных и передать ее методу журнала.
Но вместо этого мы также можем использовать строку формата для сообщения и добавлять данные переменной в качестве аргумента.
Давайте разберемся в следующем примере –
Аргументы, переданные методу, будут свернуты как переменные данные в сообщении.
Мы можем использовать f
Отслеживание трассировки стека
Мы можем фиксировать полные стеки трассировок в приложении с помощью модуля регистрации. В функции ведения журнала есть параметр exc_info; если мы установим его как True, он может захватывать информацию об исключении.
Если мы не установим значение exc_info в true, выходные данные не будут сообщать нам об исключении. Было бы сложно отладить ошибку в тысячах строк кода, если она отображает только следующий вывод.
Есть также другой способ получить полную информацию об исключении. Модуль регистрации предоставляет метод exception(), который регистрирует сообщение с ERROR и прикрепляет информацию об исключении. Чтобы использовать его, вызовите метод logging.exception() так же, как вызов logging.error(exc_info = True).
Мы можем использовать любую из опций в методах error(), debug() или critical(), чтобы получить информацию об исключении.
Классы и функции
До сих пор мы видели регистратор по умолчанию с именем root. Модуль ведения журнала используется всякий раз, когда вызываются его функции, такие как logging.debug(), logging.error() и т. д. Мы также можем определить собственное средство ведения журнала, создав объект класса Logger. Здесь мы определяем обычно используемые классы и функции.
Ниже приведены классы и функции, определенные в модуле logging.
Если у нас нет сообщения для форматирования, по умолчанию используется необработанное сообщение. Формат даты по умолчанию –
Следующий формат используется для создания сообщения журнала в удобочитаемом формате.
Обычно мы работаем с объектами класса Logger, которые создаются с помощью функции logging.getLogger(name). Если метод getLogger() вызывается несколько раз с одним и тем же именем, он вернет ссылку на один и тот же объект регистратора.
Давайте разберемся в следующем примере:
Мы создали собственное имя регистратора first_logger, но, в отличие от корневого регистратора, first_logger не является частью выходного формата. Чтобы отобразить его, передайте его в функцию конфигурации. Тогда результат будет выглядеть следующим образом.
Работа с обработчиками
Обработчики обычно используются для настройки регистратора и передачи журналов во многие места одновременно. Он отправляет сообщения журнала в стандартный поток вывода или файл через HTTP или по электронной почте.
Давайте разберемся в следующем примере создания обработчиков.
В следующей программе мы создали настраиваемый регистратор с именем logger_obj и создали LogRecord, который хранит всю запись событий регистрации и передает ее всем имеющимся обработчикам: w_handlers и e_handlers.
W_handlers – это обработчик потока с уровнем WARNING. Он принимает журнал из LogRecord для генерации вывода в строке формата и вывода его на экран.
E_handler – это обработчик файлов с уровнем ERROR. Он игнорирует LogRecord как его уровень ПРЕДУПРЕЖДЕНИЕ.
Заключение
Модуль logging гибок и прост в использовании. Это очень полезно для отслеживания записей журнала и отображения соответствующего сообщения пользователю. Он обеспечивает гибкость для создания настраиваемых уровней журналов, классов обработчиков и многих других полезных методов.
Он также обеспечивает базовое ведение журнала для небольших проектов. В этом руководстве мы обсудили все основные концепции модуля logging. Мы рассмотрели создание сообщений с разными уровнями.