Logging в Python: как писать логи

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

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

Минимальный пример

import logging

logging.basicConfig(level=logging.INFO)

logging.info('скрипт запущен')
logging.warning('нет необязательного файла')

Примерный вывод:

INFO:root:скрипт запущен
WARNING:root:нет необязательного файла

Если заменить уровень на WARNING, сообщение info пропадет из вывода

Уровни логирования

В Python обычно используют пять уровней:

• DEBUG — подробная диагностика для разработки
• INFO — обычные шаги программы
• WARNING — проблема есть, но программа может продолжать работу
• ERROR — действие не выполнено
• CRITICAL — серьезная авария, после которой работа почти невозможна

Пример:

import logging

logging.basicConfig(level=logging.DEBUG)

logging.debug('подробности для отладки')
logging.info('файл найден')
logging.warning('используется значение по умолчанию')
logging.error('не удалось сохранить результат')

Уровень в basicConfig работает как фильтр. Если поставить INFO, сообщения DEBUG не будут показаны

Формат логов

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

import logging

logging.basicConfig(
    level=logging.INFO,
    format='%(asctime)s %(levelname)s %(message)s'
)

logging.info('начинаем обработку')

Если нужно видеть, из какого файла пришло сообщение:

import logging

logging.basicConfig(
    level=logging.INFO,
    format='%(asctime)s %(levelname)s %(name)s %(message)s'
)

logger = logging.getLogger(__name__)
logger.info('модуль запущен')

__name__ помогает отличать сообщения разных модулей в большом проекте

Логи в файл

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

import logging

logging.basicConfig(
    filename='app.log',
    filemode='a',
    level=logging.INFO,
    format='%(asctime)s %(levelname)s %(message)s',
    encoding='utf-8'
)

logging.info('скрипт запущен')
logging.warning('используется резервная настройка')

filemode='a' дописывает новые строки в конец файла. Если поставить 'w', файл будет перезаписываться при запуске

Логирование ошибки

Когда вы ловите исключение, используйте logging.exception(). Оно добавляет traceback, поэтому потом видно точное место ошибки

import logging

logging.basicConfig(
    level=logging.INFO,
    format='%(asctime)s %(levelname)s %(message)s'
)

try:
    number = int('abc')
except ValueError:
    logging.exception('не удалось преобразовать строку в число')

Не пишите просто logging.error('ошибка'), если нужна причина падения. Без traceback придется гадать, какая строка сломалась

Логгер вместо root

В маленьком скрипте можно писать logging.info(). В проекте лучше создать логгер

import logging

logger = logging.getLogger(__name__)

logging.basicConfig(
    level=logging.INFO,
    format='%(asctime)s %(levelname)s %(name)s %(message)s'
)

logger.info('обработка началась')

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

Пример для обработки файлов

import logging
from pathlib import Path

logging.basicConfig(
    level=logging.INFO,
    format='%(asctime)s %(levelname)s %(message)s'
)

folder = Path('data')

if not folder.exists():
    logging.warning('папка data не найдена')
else:
    for path in folder.glob('*.txt'):
        logging.info('обрабатываем файл %s', path.name)

Обратите внимание на запись logging.info('...', path.name). Так безопаснее, чем собирать строку заранее, и это привычный стиль для logging

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

По этой теме полезно отдельно посмотреть Аннотации типов для декораторов в Python, чтобы расширить контекст и сравнить подходы

Что нельзя логировать

В логи не стоит писать:

• пароли
• токены
• cookies
• полные данные банковских карт
• приватные сообщения пользователей
• персональные данные без необходимости

Логи часто читают администраторы, разработчики, системы мониторинга и резервного копирования. Если секрет попал в лог, его уже трудно считать безопасным

Частые ошибки

• оставлять только print() в долгом рабочем скрипте
• ставить уровень ERROR и не видеть важные INFO-события
• ловить исключение и ничего не писать в лог
• логировать секреты
• вызывать basicConfig() много раз и ждать, что формат всегда поменяется
• писать огромные объекты целиком вместо короткого контекста
• не добавлять время в файл логов

Практика

Сделайте файл practice_logging.py

1. Настройте уровень INFO
2. Выведите сообщение о старте
3. Попробуйте открыть несуществующий файл
4. Запишите ошибку через logging.exception()
5. Переключите вывод в файл app.log

После этого откройте app.log и проверьте, есть ли время, уровень сообщения и traceback ошибки

logging в Python помогает заменить случайные print() на управляемые сообщения с уровнями, временем, контекстом и записью в файл

Для старта достаточно logging.basicConfig(), уровней INFO, WARNING, ERROR, функции logging.exception() и привычки не писать секреты в лог