Python: от основ до собеседования и работы / Исключения, логирование и отладка / урок 46 из 99

Логирование и отладка

⏱ 35 мин · 🧩 заданий: 5

print — не логирование

print подходит для учебных скриптов. В реальном сервисе нужны:

  • уровни важности — в продакшене не нужны отладочные сообщения, а ошибки нужны всегда;
  • время, модуль, строка в каждой записи;
  • вывод в разные места — консоль, файл, системы сбора логов (ELK, Loki, Sentry);
  • настройка без правки кода.

Всё это даёт стандартный модуль logging.

Быстрый старт

import logging, sys

logging.basicConfig(
    level=logging.DEBUG,
    format="%(asctime)s %(levelname)-8s %(name)s: %(message)s",
    datefmt="%H:%M:%S",
    stream=sys.stdout,
    force=True,
)

log = logging.getLogger("orders")

log.debug("Детали для отладки: корзина=%s", ["чай", "кофе"])
log.info("Заказ %d создан", 42)
log.warning("Склад почти пуст: осталось %d шт.", 3)
log.error("Не удалось списать оплату")
log.critical("База данных недоступна")

Уровни

Уровень Число Когда
DEBUG 10 детали для разработчика
INFO 20 штатные события: запуск, обработан запрос
WARNING 30 что-то странное, но работаем (уровень по умолчанию)
ERROR 40 операция не удалась
CRITICAL 50 приложение не может продолжать работу

Сообщения ниже установленного уровня отбрасываются.

Логгеры, обработчики, форматтеры

log.info("...") → Logger("app.db") → уровень прошёл? → Handler(s) → Formatter → вывод │ propagate=True ├─ StreamHandler → консоль ▼ ├─ FileHandler → файл Logger("app") → root logger └─ HTTP/Syslog/Sentry ...
  • Logger — точка входа, имеет имя. Имена образуют иерархию по точкам: app.db — потомок app.
  • Handler — куда писать. У одного логгера может быть несколько обработчиков со своими уровнями.
  • Formatter — как выглядит строка.
  • Запись всплывает к родительским логгерам (propagate) — поэтому обычно обработчики настраивают только у корневого логгера.
import logging, sys

app = logging.getLogger("app")
app.setLevel(logging.DEBUG)
app.propagate = False                        # чтобы не дублировать в root в этом примере

console = logging.StreamHandler(sys.stdout)
console.setLevel(logging.INFO)               # в консоль — от INFO
console.setFormatter(logging.Formatter("[%(levelname)s] %(name)s: %(message)s"))
app.addHandler(console)

errors_only = logging.StreamHandler(sys.stdout)
errors_only.setLevel(logging.ERROR)          # отдельный обработчик для ошибок
errors_only.setFormatter(logging.Formatter("  !!! АЛЕРТ: %(message)s (%(funcName)s:%(lineno)d)"))
app.addHandler(errors_only)

db = logging.getLogger("app.db")             # дочерний логгер
db.debug("не попадёт: консоль начинает с INFO")
db.info("подключение установлено")
db.error("таймаут запроса")

Правило для модулей

В каждом модуле: logger = logging.getLogger(__name__). Имя совпадёт с путём модуля (shop.payments), и логами можно управлять по пакетам. Настраивать обработчики (basicConfig, dictConfig) — только в точке входа приложения, не в библиотеке.

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

import logging, sys

logging.basicConfig(stream=sys.stdout, level=logging.INFO, format="%(levelname)s %(message)s", force=True)
log = logging.getLogger("payments")

def charge(amount):
    return 100 / amount

try:
    charge(0)
except ZeroDivisionError:
    log.exception("Ошибка оплаты, amount=%s", 0)     # ERROR + полный traceback

log.exception(...) = log.error(..., exc_info=True). Вызывайте его внутри except.

Конфигурация словарём

В реальных проектах (Django LOGGING, FastAPI/uvicorn) конфигурацию описывают словарём:

import logging.config

LOGGING = {
    "version": 1,
    "disable_existing_loggers": False,
    "formatters": {
        "default": {"format": "%(asctime)s %(levelname)s %(name)s: %(message)s"},
    },
    "handlers": {
        "console": {"class": "logging.StreamHandler", "formatter": "default"},
        "file": {
            "class": "logging.handlers.RotatingFileHandler",
            "filename": "app.log", "maxBytes": 10_000_000, "backupCount": 5,
            "formatter": "default",
        },
    },
    "loggers": {
        "shop": {"level": "DEBUG"},
        "urllib3": {"level": "WARNING"},       # приглушить болтливую библиотеку
    },
    "root": {"level": "INFO", "handlers": ["console", "file"]},
}

logging.config.dictConfig(LOGGING)

Структурные логи

Системы сбора логов лучше понимают JSON. Дополнительные поля передают через extra:

import json, logging, sys

class JsonFormatter(logging.Formatter):
    def format(self, record):
        data = {"level": record.levelname, "logger": record.name, "msg": record.getMessage()}
        data.update(getattr(record, "ctx", {}))
        return json.dumps(data, ensure_ascii=False)

handler = logging.StreamHandler(sys.stdout)
handler.setFormatter(JsonFormatter())
log = logging.getLogger("api")
log.handlers[:] = [handler]
log.propagate = False
log.setLevel(logging.INFO)

log.info("Запрос обработан", extra={"ctx": {"path": "/orders", "status": 200, "ms": 37}})

В продакшене для этого часто берут библиотеку structlog или python-json-logger.

Отладка

1. Прочитайте traceback

Последняя строка — тип и сообщение. Выше — путь вызовов. Python 3.11+ ещё и подчёркивает ^^^^ точное выражение, которое упало.

2. pdb и breakpoint()

Вставьте breakpoint() в код — выполнение остановится, и откроется интерактивный отладчик:

def total(prices, discount):
    subtotal = sum(prices)
    breakpoint()                  # остановка здесь
    return subtotal * (1 - discount)
Команда Действие
p expr / pp expr напечатать значение (красиво)
n (next) следующая строка, не заходя в функции
s (step) зайти внутрь вызова
c (continue) продолжить до следующей точки останова
l / ll показать код вокруг / всю функцию
w (where) стек вызовов
u / d подняться / спуститься по стеку
b 42 точка останова на строке 42
q выйти
  • python -m pdb script.py — запустить скрипт под отладчиком.
  • PYTHONBREAKPOINT=0 — отключить все breakpoint().
  • pytest --pdb — открыть отладчик в месте упавшего теста.
  • В VS Code и PyCharm то же самое делается кликом по полю слева от строки.

Визуализатор в этом курсе

Кнопка 👣 Пошагово у примеров — тот же отладчик, только наглядный: шаги, переменные и объекты в памяти.

3. Полезные модули

import traceback, warnings

def risky():
    return {}["нет"]

try:
    risky()
except KeyError:
    text = traceback.format_exc()          # traceback как строка — например, отправить в лог
    print(text.strip().splitlines()[-1])

warnings.simplefilter("always")
def old_api():
    warnings.warn("old_api устарел, используйте new_api", DeprecationWarning, stacklevel=2)
    return 1

with warnings.catch_warnings(record=True) as caught:
    old_api()
print(caught[0].category.__name__, caught[0].message)
  • faulthandler.enable() — печатает стек даже при падении интерпретатора (segfault) или по таймауту зависания.
  • python -X dev — режим разработки: больше предупреждений и проверок.

Вопрос на собеседовании

«Как вы отлаживаете проблему в продакшене?» — Сначала логи и метрики (что, когда, с какими данными; трассировка в Sentry), воспроизведение локально или тестом, затем отладчик или дополнительное логирование. Важно: структурные логи с идентификатором запроса, правильные уровни и logger.exception в обработчиках ошибок.

Итог

  • logging.getLogger(__name__) в каждом модуле, настройка — один раз в точке входа.
  • Уровни: DEBUG < INFO < WARNING < ERROR < CRITICAL.
  • Logger → Handler → Formatter; записи всплывают к родителям.
  • Ленивое форматирование %s, logger.exception в except, JSON-логи для продакшена.
  • Отладка: traceback снизу вверх, breakpoint() и команды pdb, pytest --pdb.

Практика решено 0 из 5

Вы не вошли — ответы проверяются, но прогресс не сохранится. Войти или зарегистрироваться.
Задание 1 Программа на Python

Создайте логгер log = logging.getLogger("shop") и функцию buy(item, qty): - при qty <= 0 пишет в лог WARNING с сообщением "Некорректное количество: <qty>" и возвращает False; - иначе пишет INFO "Покупка: <item> x<qty>" и возвращает True. Используйте ленивое форматирование log.info("...%s", value), а не f-строки.

Какие тесты проверяют код (1) 
import logging
records = []
class H(logging.Handler):
    def emit(self, record):
        records.append((record.levelname, record.getMessage()))
log.addHandler(H()); log.setLevel(logging.DEBUG)
assert buy("чай", 2) is True and buy("кофе", 0) is False
assert records == [("INFO", "Покупка: чай x2"), ("WARNING", "Некорректное количество: 0")], records
Задание 2 Заполнить таблицу

Какой уровень логирования подходит?

DEBUGINFOWARNINGERRORCRITICAL
Значения переменных внутри алгоритма при поиске бага
Сервис запущен на порту 8000
Диск заполнен на 90%, но работа продолжается
Не удалось отправить письмо клиенту (исключение)
База данных недоступна, приложение не может работать
Отметьте ячейку — «+», пустая — «−».
Задание 3 Один вариант ответа

Почему пишут log.debug("Данные: %s", data), а не log.debug(f"Данные: {data}")?

Задание 4 Один вариант ответа

Что делает log.exception("Ошибка оплаты") внутри блока except?

Задание 5 Один вариант ответа

Что делает встроенная функция breakpoint()?

Войдите, чтобы отмечать пройденные уроки.