Логирование A: почему print — это не логирование, и уровни лога

Что мы изучим?#

• Что такое лог (Log) и почему настоящие системы его пишут.
• Почему print — это не логирование.
• Модуль Python logging.
• Пять уровней лога: debug, info, warning, error, critical.

Зачем это нужно?#

Сервер, который вы напишете в темах бэкенда и баз данных, будет работать без присмотра, возможно, на компьютере в облаке, посреди ночи. Завтра утром клиент скажет: «мой заказ ночью пропал». Как узнать, что произошло?

• print печатал на экран, который никто не видел, и всё уже исчезло.
• Отладчик не поможет, потому что баг произошёл вчера, а не сейчас.

Лог — это «чёрный ящик», как в самолёте: запись того, что произошло, когда и насколько серьёзно. Каждая профессиональная система пишет логи, и разработчики читают их каждый день.

Объяснение с основ#

Что такое лог?#

Лог (Log) — последовательность записей. Каждая запись описывает одно событие: когда оно произошло, насколько серьёзно и что произошло.

2026-10-06 09:14:02 INFO     User dana logged in
2026-10-06 09:14:30 WARNING  Login attempt with wrong password for avi
2026-10-06 09:15:11 ERROR    Payment failed for order 1042: card declined

Почему print — это не логирование#

Правило: print — для общения с пользователем (вывод программы). logging — для общения с разработчиками и эксплуатацией (что происходило внутри программы).

Пять уровней#

Минимальный уровень — фильтрация#

Вы задаёте минимальный уровень, и показываются только сообщения этого уровня и выше:

• Во время разработки: DEBUG. Видно всё.
• На настоящем сервере (Production): INFO или WARNING. Только важное, без «шума».

По умолчанию в Python — WARNING. Поэтому если ничего не настраивать, сообщения debug и info вообще не показываются.

Синтаксис#

import logging

# configure once, at the start of the program
logging.basicConfig(
    level=logging.INFO,                                  # minimum level to show
    format="%(asctime)s %(levelname)s %(message)s",      # how each record looks
)

# write log records
logging.debug("technical details")
logging.info("normal important event")
logging.warning("something unusual")
logging.error("an operation failed")
logging.critical("the whole system is in danger")

Распространённые поля в format:

Первый пример кода#

week-2/log_levels.py:

import logging

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

logging.debug("This is a debug message")
logging.info("Application started")
logging.warning("Config file not found, using defaults")
logging.error("Could not connect to the payment service")
logging.critical("Out of memory - shutting down")

Вывод:

2026-10-06 09:30:12,481 INFO Application started
2026-10-06 09:30:12,481 WARNING Config file not found, using defaults
2026-10-06 09:30:12,482 ERROR Could not connect to the payment service
2026-10-06 09:30:12,482 CRITICAL Out of memory - shutting down

Разбор кода построчно#

Попробуйте: поменяйте на level=logging.DEBUG и запустите снова. Теперь появится 5 строк. С level=logging.ERROR появятся только 2. Вы изменили одну строку и не трогали сами сообщения. В этом сила уровней.

Ещё один пример#

Логи внутри настоящей программы в сочетании с исключениями из предыдущих уроков. week-2/orders.py:

import logging

logging.basicConfig(
    level=logging.DEBUG,
    format="%(asctime)s %(levelname)-8s %(funcName)s: %(message)s",
)

STOCK = {"bread": 5, "milk": 0, "eggs": 12}

def place_order(product, quantity):
    logging.debug("place_order called with product=%s quantity=%s", product, quantity)

    if product not in STOCK:
        logging.error("Unknown product requested: %s", product)
        return False

    available = STOCK[product]
    if available == 0:
        logging.warning("Product out of stock: %s", product)
        return False

    if quantity > available:
        logging.warning("Not enough %s: requested %s, available %s", product, quantity, available)
        return False

    STOCK[product] = available - quantity
    logging.info("Order placed: %s x%s (left in stock: %s)", product, quantity, STOCK[product])
    return True

place_order("bread", 2)
place_order("milk", 1)
place_order("cake", 1)
place_order("eggs", 20)

Вывод:

2026-10-06 09:41:03,115 DEBUG    place_order: place_order called with product=bread quantity=2
2026-10-06 09:41:03,115 INFO     place_order: Order placed: bread x2 (left in stock: 3)
2026-10-06 09:41:03,116 DEBUG    place_order: place_order called with product=milk quantity=1
2026-10-06 09:41:03,116 WARNING  place_order: Product out of stock: milk
2026-10-06 09:41:03,116 DEBUG    place_order: place_order called with product=cake quantity=1
2026-10-06 09:41:03,116 ERROR    place_order: Unknown product requested: cake
2026-10-06 09:41:03,117 DEBUG    place_order: place_order called with product=eggs quantity=20
2026-10-06 09:41:03,117 WARNING  place_order: Not enough eggs: requested 20, available 12

Разбор:

• %(levelname)-8s — -8 дополняет название уровня до 8 символов, чтобы сообщения выстраивались в столбец. Легко читать.
• %(funcName)s — видно, из какой функции пришла каждая запись.
• logging.info("... %s ...", product, quantity) — %s — заполнитель (placeholder) для значения, а значения передаются дополнительными аргументами. Это рекомендуемый способ в логировании: текст собирается, только если сообщение действительно будет показано, поэтому отфильтрованные сообщения DEBUG почти ничего не стоят.
• Выбор уровней: «заказано» — INFO (обычное важное событие). «Нет в наличии» — WARNING (бизнес работает, но об этом стоит знать). «Товара не существует» — ERROR (что-то не так в запросе, возможно, баг на стороне клиента). Детали вызова — DEBUG.
• if product not in STOCK — in для словаря проверяет, существует ли ключ.

Теперь поменяйте на level=logging.WARNING: в логе останутся только 3 проблемы. Так это будет выглядеть на настоящем сервере, где интересны только сбои.

Типичная ошибка#

Ошибка 1: вызывать basicConfig после того, как сообщение уже записано, или дважды.

import logging
logging.info("starting")                     # uses the default config!
logging.basicConfig(level=logging.INFO)      # ignored - already configured
logging.info("now?")                         # still not shown

Первый вызов logging.info автоматически устанавливает настройку по умолчанию (WARNING), а поздний basicConfig молча игнорируется. basicConfig — всегда первым и один раз, сразу после import.

Ошибка 2: «я не вижу свой info». Причина почти всегда в уровне по умолчанию WARNING. Исправление: level=logging.INFO (или DEBUG).

Ошибка 3: неправильный уровень.

logging.error("User dana logged in")       # not an error!
logging.info("Payment failed!")            # this IS an error

Неправильный уровень делает фильтрацию бесполезной: тот, кто смотрит только на ERROR, пропустит неудавшийся платёж и утонет в обычных входах в систему.

Ошибка 4: записывать в лог чувствительную информацию. logging.info("login: user=dana password=1234") — никогда не пишите пароли, номера кредитных карт или токены. Логи читают многие люди, и хранятся они долго.

Практика#

Упражнения опираются только на то, что пройдено в этом уроке и в предыдущих. Сначала попробуйте сами, и только потом открывайте решение.

Упражнение 1: Какой уровень?#

Для каждого события — на каком уровне лога вы бы его записали: DEBUG, INFO, WARNING, ERROR или CRITICAL?

1. Пользователь успешно вошёл в систему.
2. Значение переменной внутри цикла во время поиска бага.
3. Пользователь ввёл неверный пароль.
4. Платёж не прошёл.
5. Нет соединения с базой данных, и сервер вообще не может работать.

Упражнение 2: Минимальный уровень#

import logging

logging.basicConfig(level=logging.WARNING)

logging.debug("checking item 3")
logging.info("order 17 created")
logging.warning("stock is low: 2 left")
logging.error("payment failed for order 17")

Какие из сообщений появятся и почему? Что нужно изменить, чтобы увидеть все?

WARNING:root:stock is low: 2 left
ERROR:root:payment failed for order 17

Упражнение 3: От print к logging#

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

def withdraw(balance, amount):
    print("withdraw called with", amount)
    if amount > balance:
        print("not enough money, balance is", balance)
        return balance
    print("withdrew", amount)
    return balance - amount

import logging

logging.basicConfig(
    level=logging.DEBUG,
    format="%(asctime)s %(levelname)-8s %(message)s",
)


def withdraw(balance, amount):
    logging.debug("withdraw called with %s", amount)
    if amount > balance:
        logging.error("not enough money, balance is %s", balance)
        return balance
    logging.info("withdrew %s", amount)
    return balance - amount


withdraw(100, 30)
withdraw(100, 500)

Упражнение 4: Читаем строку лога#

2026-11-01 09:14:30 WARNING  Wrong password for avi

1. Что представляет собой каждая часть строки и какая часть настройки format её создаёт?
2. Почему важно, что в строке есть время?

Упражнение 5: print или logging?#

Для каждого случая — print или logging? Объясните.

1. Программа, которая спрашивает у пользователя имя и приветствует его.
2. Сервер, который работает всю ночь, а утром вы хотите знать, какие заказы не прошли.
3. Временная проверка значения переменной во время разработки, которую хочется выключить, не удаляя.

Итоги#

• Лог = запись событий: когда, насколько серьёзно и что произошло. «Чёрный ящик» программы.
• print = вывод для пользователя. logging = запись для разработчиков: время, уровень, фильтрация и назначения.
• 5 уровней: DEBUG < INFO < WARNING < ERROR < CRITICAL. Показываются только сообщения минимального уровня и выше.
• По умолчанию — WARNING. basicConfig вызывается один раз, первым.
• logging.info("x=%s", x) — рекомендуемая форма. И никогда не логируйте пароли.

Официальная документация#

• Logging HOWTO — When to use logging
• logging — Logging Levels