4 подписчика

Логгирование с модулем logging, настройка через конфиг файл. Лог-сообщения в Telegram.

1 июля 20221 июл 2022

336

10 мин

Оглавление

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

Это статья возникла из моей компиляции информации по работе модуля logging.

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

В первую очередь, сформулирую, для чего я использую логгирование.

В процессе написания кода

Это очень удобная замена принтам.

logger.debug(f'сообщение {value=}')

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

Отладка программы и поиск багов.

Ну тут все понятно. Если что-то произошло, лезем в лог-файл и смотрим ошибку.

Оперативное информирование о сбоях в работе программы.

Настраиваем удобный способ получения сообщения. Например, email или Telegram.

Основные моменты для понимания работы модуля logging.

Вы можете отправлять сообщения разных видов(отладка, информирование, предупреждение, ошибка, критическая ошибка и исключение).
В проекте может быть несколько логгеров, которые следят за разными частями проекта.
Каждый из этих логгеров может выводить сообщение одновременно несколькими способами(в консоль, в лог-файл, информирование на email, в Telegram и т.д.). Например, логгер модуля для работы с базой данных пишет ошибки только в лог-файл.
А вот логгер модуля для обработки информации выводит все сообщения в консоль, сообщения с ошибками пишет в лог, и в случае, если выскочит исключение, отправит сообщение в телеграм.
К вашему сообщению, логгер может добавлять дополнительную информацию(время, модуль, номер строки и т.д.). При этом для каждого канала информации, формат сообщения и набор параметров может быть разным. Например, в консоли не нужна дата и время, если работаем с отладкой прямо сейчас. А вот в лог-файле без них не обойтись.

Теперь попробуем на примере немного разобраться, как это работает.

Уровни в logging

В модуле logging есть понятие уровня и каждому уровню соответсвует определенное число.

CRITICAL 50

ERROR 40

WARNING 30

INFO 20

DEBUG 10

NOTSET 0

Вокруг этого уровня и строится все взаимодействие:

- У сообщения, которое мы отправляем есть уровень.

- У каждого логгера есть свой уровень.

- У каждого канала передачи информации есть свой уровень.

Теперь небольшой пример для понимания.

У нас в программе есть два сообщения: уровня debug и error

logger.debug('сообщение 1')

logger.error('сообщение 2')

У нас есть логгер, которому мы задали уровень 'DEBUG'

И мы настроили этот логгер так, что у него есть два канала вывода информации со своими обработчиками:

- обработчик вывода в консоль, которой мы задали уровень 'DEBUG'
- обработчик записи в лог-файл, с уровнем 'INFO'

Происходит вызов сообщений:

сообщение 1: "я сообщение уровня DEBUG со значением 10"

сообщение 2: "я сообщение уровня ERROR со значением 40"

логгер: " получаю сообщение 1 и сообщение 2

мой уровень DEBUG со значением 10. Я буду обрабатывать только сообщения с уровнем не меньше чем мой.

10 >= 10. Сообщение 1 проходит. Отправляю сообщение 1 в обработчики

40 >= 10. Сообщение 2 проходит. Отправляю сообщение 2 в обработчики

обработчик вывода в консоль: "Получаю сообщение 1 и сообщение 2."

Мой уровень DEBUG со значением 10. Я буду обрабатывать только сообщения с уровнем не меньше чем мой.

10 >= 10. Сообщение 1 проходит - вывожу в консоль сообщение 1

40 >= 10. Сообщение 2 проходит - вывожу в консоль сообщение 2"

обработчик записи в лог-файл: "Получаю сообщение 1 и сообщение 2

Мой уровень INFO со значением 20. Я буду обрабатывать только сообщения с уровнем не меньше чем мой.

10 <= 20. Сообщение 1 не проходит - игнорирую сообщение 1

40 >= 20. Сообщение 2 проходит - записываю сообщение 2 в лог-файл"

В результате мы имеем на экране: соощение 1 и сообщение 2. А в лог-файле только сообщение 1.

Теперь можно начинать работать с logging.

1. Вам нужно разделить свою программу на блоки, за которыми вы хотите следить по отдельности. Т.е. выбирать сообщения из какого блока, где хотите видеть.
Каждому блоку - назначаете свой логгер. В проекте может быть сколько угодно логгеров.
Лично я делаю так: на каждый модуль(отдельный *.py-файл) свой логгер.
Логгеры идентифицирются по имени. Т.к. у меня логгер привязан к модулю, я в качестве имени использую имя этого модуля, а именно переменную `__name__`.

logger = logging.getLogger(__name__)

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

2. Для каждого отдельного блока нужно определить, как он будет выводить информацию.

Я использую вывод в консоль, лог-файл и Telegram.

3. Определить формат вывода информации.

Каждый из каналов может иметь свой вариант форматирования сообщений и набор параметров с дополнительной информацией.

В модуле logging много параметров, которые вы можете вывести(полный список в документации:

дата и время
имя модуля
уровень сообщения
номер строки в коде

Ну и теперь приступаем к реализации в коде.

Начнем с конфиг файла.

Создадим файл `settings.py`

Настройки хранятся в виде словаря:

В нем в свою очередь находятся еще три словаря:

loggers - словарь с логгерами. Формирование этого словаря я вынес в начало файла.
handlers - словарь с обработчиками, т.е. с каналами вывода информации
formatters - в нем прописаны виды форматирования сообщения

formatters

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

в словаре 'formatters', в хранятся словари с настройками отдельных форматтеров.

Я использую два вида форматирования с датой и без. Вы можете форматировать сообщение под себя.

formatters = {

'file_formatter': {

'format': '[{levelname}: {asctime}] [{filename}:{funcName}:{lineno}]: "{message}"',

'style': '{'

},

'debug_formatter': {

'format': '[{levelname}] [{filename}:{funcName}:{lineno}]: "{message}"',

'style': '{'

},

}

здесь:

`levelname` - уровень сообщения('DEBUG', 'INFO', 'WARNING', 'ERROR', 'CRITICAL')
`filename` - имя файла откуда вызвано сообщение
`funcName` - имя функции. Речь идет о вашей функции, которую вы определили `def func():`
`lineno` - номер строчки в коде
`message` - ну и собственно само сообщение, которое вы написали.
Для вывода в лог файл и Telegram добавляются дата и время - `asctime`
Параметр 'style': '{' указывает, что форматирование вывода идет как f-строка. Если не указать, придется параметры задавать через устаревший вариант с `%`.

handlers

Теперь перейдем к обработчикам.

Я использую три вида обработчиков: два стандартных('logging.StreamHandler', 'logging.FileHandler') и третий Telegram

'console_handler' - вместо принтов, для текущего написания кода и отладки.
'file_handler' - пишет информационные сообщения и сообщения об ошибках в лог-файл. Сообщения 'DEBUG' в него не попадают.
c обработчиком Telegram немного посложнее. Его нужно прописать.

Для отправки телеграм-сообщения я делаю POST-запрос через встроенный модуль `urllib3` к TelegramAPI. Я видел в интернете релизацию через библиотеку `telebot`, но тогда придется устанавливать ее в каждый проект. Я считаю, что лучше обойтись встроенными библиотеками.

class TelegramBotHandler(Handler):

def __init__(self, token: str, chat_id: str):

super().__init__()

self.token = token

self.chat_id = chat_id

def emit(self, record: LogRecord) -> None:

url = f'https://api.telegram.org/bot{self.token}/sendMessage'

post_data = {'chat_id': self.chat_id,

'text': self.format(record)}

http = urllib3.PoolManager()

http.request(method='POST', url=url, fields=post_data)

Конфигурируем обработчики:

'handlers': {

'console_handler': { # имя обработчика

'level': 'DEBUG', # уровень сообщений на который начнет реагировать обработчик

'class': 'logging.StreamHandler',

'formatter': 'debug_formatter', # указываем как форматировать сообщение

'stream': 'ext://sys.stdout' # По умолчанию stderr. Этот параметр указан, чтобы в консоли вывод был простым белым шрифтом, как в print, а не красным, как будто это ошибки.

},

'file_handler': {

'level': 'INFO',

'class': 'logging.FileHandler',

'formatter': 'file_formatter',

'filename': 'temp/logs/debug.log', # путь до лог файла. Без разницы какая ОС: Windows, Linux записываем через '/'

'mode': 'a', # По умолчанию 'a'. Режим записи, все как у обычногого файла. 'a' дозапись в текущий файл. 'w' новый файл, предыдущие записи стираются

'encoding': 'utf-8', # кодировка

},

'telegram_handler': {

'class': 'settings.TelegramBotHandler', # здесь указываем созданный нами обработчик Telegram

'level': 'INFO',

'token': TELEGRAM_BOT_TOKEN,

'chat_id': TELEGRAM_CHAT_ID

}

`class` - это выбор канала информации: консоль, лог-файл и т.д. Обработчиков много и опять же ссылка на них в документации [logging.handlers — Logging handlers — Python 3.10.5 documentation](https://docs.python.org/3/library/logging.handlers.html).
`level` в настройках обработчика указывает нижний уровень сообщения, с которого обработчик начинает на него реагировать. Т.е. если в настройках поставить 'WARNING', то в сообщениях от этого обработчика вы не увидите сообщения уровня 'DEBUG', 'INFO', но увидите все с большим номером.
Если вы хотите ограничить верхнюю границу, нужно будет использовать такую вещь как фильтры, но я с ними подробно не разбирался, для моих задач этого не требовалось.
Именно здесь мы указываем, какие сообщения мы хотим видеть в консоли, а какие нужно писать в лог-файл.
В параметре `formatter` мы указываем имя конкретного форматтера, который мы прописали в предыдущем пункте.

loggers.

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

В самом начале файла кортеж с именами модулей и их уровнем сообщений.

Именно здесь я меняю настройки, что мне выводить в консоль, а что нет. Т.е. закончил отладку определенного модуля, поменял 'DEBUG' на 'INFO'. И больше в консоли я не вижу от него отладочных сообщений. Поэтому эта часть у меня в начале файла.

modules_and_level = (

('__main__', 'DEBUG'),

('db_modules.db_common', 'INFO'),

('epub.epub', 'INFO'),

('common.utils', 'DEBUG'),

('common.common', 'INFO'),

('execute', 'DEBUG')

)

loggers = {}

for logger in modules_and_level:

loggers[logger[0]] = {

'handlers': ['console_handler', 'file_handler'],

'level': logger[1],

'propagate': False}

Обратите внимание, как записывается имя модуля(как в import) - с учетом пути через точку, без расширения. Т.е. файл 'db_common.py' в папке 'db_modules' записывается как 'db_modules.db_common'

В `handlers` указываем список обработчиков, в которые отправляет информацию этот логгер. У меня все логгеры работают с одинаковым набором обработчиков. Но вы можете настраивать под свой проект.
`propagate` ставим в `False`. Этот параметр относится к иерархии логгеров и отвечает за передачу сообщений к логгерам родителям. Если `True`, то при определенных настройках может быть дублирование сообщений.

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