Логирование в Python: модуль logging от первого лога до конфигурации

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

Ниже — рабочий пример, уровни, устройство модуля, файл с ротацией, dictConfig, исключения и безопасность. Примеры проверены на Python 3.9 и подходят для актуальных версий, включая 3.14.

Мини-словарь: четыре детали модуля

Цепочка: logger.warning(...) -> LogRecord -> подходящие хендлеры -> их форматтеры -> строка в консоли или файле.

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

import logging

logging.basicConfig(level=logging.INFO, format="%(levelname)s:%(name)s:%(message)s")
logger = logging.getLogger("shop.orders")

logger.debug("Детали для отладки")
logger.info("Заказ %s создан", 1024)
logger.warning("Остаток товара %s: %d шт.", "SKU-7", 2)

В консоли (по умолчанию это поток stderr) появятся две строки из трех:

INFO:shop.orders:Заказ 1024 создан
WARNING:shop.orders:Остаток товара SKU-7: 2 шт.

basicConfig настраивает корневой логгер: уровень INFO и хендлер в stderr. В модулях логгер обычно получают как getLogger(__name__). debug не выведен: его уровень ниже INFO.

Аргументы передаются отдельно ("Заказ %s создан", 1024), а не f-строкой. Это ленивое форматирование: строка собирается, только если запись действительно будет выведена.

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

Если уровень не настроен, корневой логгер пропускает записи от WARNING и выше.

Уровень фильтруется дважды: у логгера и у хендлера. Поэтому можно писать в файл все от DEBUG, а в консоль — от WARNING.

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

Имена логгеров образуют дерево по точкам: shop.orders — потомок shop, тот — потомок корневого. По умолчанию запись поднимается вверх по дереву (propagate=True) и обрабатывается хендлерами всех предков.

Поэтому в модулях и библиотеках хендлеры обычно не создают, а пишут в getLogger(__name__); хендлеры настраивают один раз в точке входа программы.

Консоль и файл с ротацией

Задача: в консоль — ошибки и предупреждения, в файл — все, но без бесконечного роста файла.

import logging
from logging.handlers import RotatingFileHandler

logger = logging.getLogger("app")
logger.setLevel(logging.DEBUG)

console = logging.StreamHandler()
console.setLevel(logging.WARNING)
console.setFormatter(logging.Formatter("%(levelname)s %(message)s"))

file_handler = RotatingFileHandler(
    "app.log", maxBytes=1_000_000, backupCount=3, encoding="utf-8"
)
file_handler.setLevel(logging.DEBUG)
file_handler.setFormatter(logging.Formatter(
    "%(asctime)s %(levelname)s %(name)s:%(lineno)d %(message)s"
))

logger.addHandler(console)
logger.addHandler(file_handler)

logger.debug("Подключаемся к базе")
logger.error("Не удалось сохранить отчет")

print(open("app.log", encoding="utf-8").read())

В консоли будет только ERROR Не удалось сохранить отчет, а в файле app.log — обе записи. Дата и время в каждой строке будут вашими, шаблон такой:

ГГГГ-ММ-ДД ЧЧ:ММ:СС,мс DEBUG app:22 Подключаемся к базе
ГГГГ-ММ-ДД ЧЧ:ММ:СС,мс ERROR app:23 Не удалось сохранить отчет

При достижении maxBytes файл переименуется в app.log.1, старых файлов хранится не больше backupCount; ротация по времени — TimedRotatingFileHandler. Граница: ротация средствами Python рассчитана на один процесс; если пишут несколько процессов, надежнее писать в stdout и отдать ротацию внешней системе.

Конфигурация через dictConfig

Настройку удобнее держать словарем — его можно вынести в YAML или JSON.

import logging
import logging.config

LOGGING = {
    "version": 1,
    "disable_existing_loggers": False,
    "formatters": {
        "short": {"format": "%(levelname)s %(name)s: %(message)s"},
    },
    "handlers": {
        "console": {
            "class": "logging.StreamHandler",
            "formatter": "short",
            "level": "INFO",
        },
    },
    "loggers": {
        "payments": {"level": "DEBUG", "handlers": ["console"], "propagate": False},
    },
    "root": {"level": "WARNING", "handlers": ["console"]},
}

logging.config.dictConfig(LOGGING)

logging.getLogger("payments").info("Платеж %s принят", "P-17")
logging.getLogger("payments").debug("Сырой ответ шлюза")
logging.getLogger("other").info("Эта строка не появится")

Вывод:

INFO payments: Платеж P-17 принят

debug отсечен уровнем хендлера (INFO), а info логгера other — уровнем корневого логгера (WARNING). propagate: False не дает записи payments вывестись второй раз через корневой хендлер. disable_existing_loggers: False сохраняет уже созданные логгеры: значение по умолчанию True их отключает.

Логирование исключений

Внутри except используйте logger.exception: запись уровня ERROR плюс traceback.

import logging

logging.basicConfig(format="%(levelname)s %(message)s")
logger = logging.getLogger("calc")

try:
    1 / 0
except ZeroDivisionError:
    logger.exception("Ошибка при расчете скидки")

Вывод (путь к файлу и номер строки будут вашими):

ERROR Ошибка при расчете скидки
Traceback (most recent call last):
  File ".../s.py", line 7, in <module>
    1 / 0
ZeroDivisionError: division by zero

Для другого уровня есть exc_info=True: logger.warning("...", exc_info=True).

Типичная ошибка: basicConfig не срабатывает

import logging

logging.warning("Старт")
logging.basicConfig(level=logging.DEBUG, format="%(levelname)s %(message)s")
logging.debug("Отладка")

Фактический результат — одна строка в формате по умолчанию, отладки нет:

WARNING:root:Старт

Функции уровня модуля (logging.warning и другие) при первом вызове сами настраивают корневой логгер, если у него нет хендлеров. Поэтому последующий basicConfig ничего не делает. Исправление — настроить логирование до первой записи или, начиная с Python 3.8, передать force=True:

import logging

logging.warning("Старт")
logging.basicConfig(level=logging.DEBUG, format="%(levelname)s %(message)s", force=True)
logging.debug("Отладка")

WARNING:root:Старт
DEBUG Отладка

Безопасность: что нельзя писать в лог

• Не логируйте пароли, токены, ключи API, номера карт и заголовки Authorization. Персональные данные (email, телефон, паспорт) — только если это обосновано и разрешено политикой, лучше в маскированном виде.
• Не пишите в лог целиком объекты запроса или конфигурации: секреты попадут вместе с полезным.
• Пользовательский ввод выводите через %r: переводы строк экранируются и не позволяют подделать соседние строки лога.

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

import logging
import re

class MaskSecrets(logging.Filter):
    PATTERN = re.compile(r"(token|password)=\S+", re.IGNORECASE)

    def filter(self, record):
        record.msg = self.PATTERN.sub(r"\1=***", record.getMessage())
        record.args = None
        return True

logging.basicConfig(level=logging.INFO, format="%(levelname)s %(message)s")
handler = logging.getLogger().handlers[0]
handler.addFilter(MaskSecrets())

logging.getLogger("api").info("Запрос к %s?token=%s", "/v1/orders", "abc123")
logging.getLogger("api").info("Логин пользователя %r", "ivan\nINFO fake")

INFO Запрос к /v1/orders?token=***
INFO Логин пользователя 'ivan\nINFO fake'

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

Если не получилось

• logger.info ничего не выводит — не настроен уровень (по умолчанию WARNING) или basicConfig вызван после первой записи.
• Каждая строка печатается дважды — хендлер добавлен и логгеру, и корневому логгеру; поставьте propagate = False или оставьте хендлер в одном месте.
• Логи сторонней библиотеки пропали после dictConfig — не указан "disable_existing_loggers": False.
• В файле кракозябры — не задан encoding="utf-8".

Выводы

• logging разделяет «кто пишет» (логгер), «куда» (хендлер) и «как выглядит» (форматтер): вывод меняется конфигурацией.
• Уровень фильтруется дважды: у логгера и у хендлера; по умолчанию выводится только WARNING и выше.
• В модулях пишут в getLogger(__name__), хендлеры настраивают один раз в точке входа, для сложной схемы — dictConfig.
• Исключения логируют через logger.exception, сообщения форматируют лениво: logger.info("%s", x).
• Секреты и персональные данные в лог не пишут; фильтр маскирования — страховка, а не основная защита.

Где применяется / связь с практикой

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

FAQ

Чем logging лучше print для отладки?
У print нет уровней: отладочные print удаляют вручную, а logger.debug отключается настройкой уровня.

Можно ли писать логи в формате JSON?
Да: через свой форматтер, который собирает словарь из полей LogRecord и вызывает json.dumps, или стороннюю библиотеку.

Логирование замедляет программу?
Немного. Ленивое форматирование и верный уровень снимают основные затраты; перед дорогими вычислениями проверяйте logger.isEnabledFor(logging.DEBUG).