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

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

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

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

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

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

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

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

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

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

```text
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` |
|---|---|---|
| **Время** | Нет. Неизвестно, когда это произошло. | Автоматически в каждой записи |
| **Серьёзность** | Все сообщения выглядят одинаково | 5 уровней. Можно фильтровать |
| **Выключить/включить** | Нужно удалять или добавлять строки кода | Изменить **одну настройку**, не трогая код |
| **Назначение** | Только экран | Экран, **файл**, сервер логов... |
| **На сервере** | Теряется | Сохраняется и проверяется потом |

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

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

| Уровень | Число | Когда использовать | Пример |
|---|---|---|---|
| `DEBUG` | 10 | Технические детали для разработчика во время разработки и отладки | `"cart contents: [...]"` |
| `INFO` | 20 | Обычные важные события — «всё в порядке» | `"user dana logged in"` |
| `WARNING` | 30 | Что-то необычное, но система продолжает работу | `"disk 90% full"`, `"retrying request"` |
| `ERROR` | 40 | Действие **не удалось** | `"payment failed for order 1042"` |
| `CRITICAL` | 50 | Вся система в опасности и, возможно, не сможет продолжать | `"database unreachable - shutting down"` |

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

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

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

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

{{< box "analogy" "Аналогия: система оповещения в больнице" >}}
**DEBUG** = полная запись каждого измерения (на неё смотрит только врач-исследователь). **INFO** = «пациент пообедал». **WARNING** = «температура немного повышена, продолжаем наблюдать». **ERROR** = «лекарство не дали вовремя». **CRITICAL** = «код синий!». Ночная медсестра выбирает видеть только WARNING и выше, иначе сообщения её захлестнут.
{{< /box >}}

## Синтаксис

```python
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`:**

| Поле | Что показывается |
|---|---|
| `%(asctime)s` | Дата и время |
| `%(levelname)s` | Название уровня (`INFO`, `ERROR`...) |
| `%(message)s` | Ваше сообщение |
| `%(funcName)s` | Имя функции, которая сделала запись |
| `%(lineno)d` | Номер строки |

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

`week-2/log_levels.py`:

```python
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")
```

**Вывод:**

```text
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
```

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

| Строка | Объяснение |
|---|---|
| `import logging` | Встроенный модуль Python для логов. Установка не нужна. |
| `logging.basicConfig(...)` | **Однократная** настройка в начале программы: какой минимальный уровень и как выглядит каждая запись. |
| `level=logging.INFO` | Показывать только начиная с INFO. |
| `format="..."` | Шаблон записи: время, уровень, сообщение. |
| `logging.debug(...)` | **Не показывается!** DEBUG (10) ниже INFO (20), поэтому отфильтрован. |
| От `logging.info(...)` до `logging.critical(...)` | Показываются, потому что их уровень INFO и выше. |
| `,481` в выводе | Миллисекунды. Полезно, когда много событий происходит в одну секунду. |

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

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

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

```python
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)
```

**Вывод:**

```text
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` после того, как сообщение уже записано, или дважды.**

```python
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: неправильный уровень.**

```python
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")` — **никогда** не пишите пароли, номера кредитных карт или токены. Логи читают многие люди, и хранятся они долго.

<!-- exercises:start — generated by scripts/intro6/sync_site_exercises.py; edit scripts/intro6/exercises/ -->
## Практика

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

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

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

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

{{< solution >}}
1. **INFO** — обычное событие, которое важно записать.
2. **DEBUG** — технические детали, которые важны только во время разработки.
3. **WARNING** — что-то необычное, но система продолжает работу.
4. **ERROR** — действие не удалось.
5. **CRITICAL** — вся система не может работать.
{{< /solution >}}

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

```python
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")
```

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

{{< solution >}}
Появятся только **WARNING** и **ERROR**:

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

`level=logging.WARNING` — это **минимальный уровень**: показываются только сообщения этого уровня и выше. Чтобы увидеть все, поменяйте на `level=logging.DEBUG`. Без изменения остального кода — в этом всё преимущество.
{{< /solution >}}

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

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

```python
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
```

{{< solution >}}
```python
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)
```

- Вход в функцию — **DEBUG**, успешное снятие — **INFO**, неудача — **ERROR**.
- Формат добавляет время и уровень к каждой строке, например: `2026-11-01 10:15:02 ERROR    not enough money, balance is 100`.
{{< /solution >}}

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

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

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

{{< solution >}}
1. Части:
   - `2026-11-01 09:14:30` — время, его создаёт `%(asctime)s`.
   - `WARNING` — уровень, его создаёт `%(levelname)s`.
   - `Wrong password for avi` — сообщение, его создаёт `%(message)s`.
2. Когда что-то происходит на сервере в три часа ночи, время позволяет восстановить, **что произошло и в каком порядке**, и сопоставить это с другими событиями.
{{< /solution >}}

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

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

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

{{< solution >}}
1. **print** — это вывод, который программа показывает **пользователю**.
2. **logging** (ERROR) — информация **для разработчика**, со временем и уровнем, которую можно сохранить и искать.
3. **logging** (DEBUG) — все сообщения DEBUG можно выключить одной строкой (повысив минимальный уровень), не удаляя код.

Правило: **print — для пользователя, logging — для разработчика.**
{{< /solution >}}

<!-- exercises:end -->

## Итоги

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

<!-- docs:start — generated by scripts/intro6/site_docs.py; edit the links there -->

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

- [Logging HOWTO — When to use logging](https://docs.python.org/3/howto/logging.html#when-to-use-logging)
- [logging — Logging Levels](https://docs.python.org/3/library/logging.html#logging-levels)

<!-- docs:end -->