Логгер: вызывать setup_logger при импорте приложения (#18) #20

aep · 2026-10-08T15:42:29+03:00

aep commented

2026-10-08 15:42:29 +03:00

Closes #18

Что было

src/core/logger.py содержал setup_logger() с diagnose=False, но приложение его не вызывало. Работал обработчик loguru по умолчанию (stderr, diagnose=True), и трейсбек любого залогированного исключения (logger.exception, opt(exception=...)) содержал значения локальных переменных во всех фреймах, в том числе содержимое запросов и секреты из настроек.

Что сделано

src/app.py вызывает setup_logger(level="DEBUG" if settings.DEBUG else "INFO") при импорте модуля, так же как tabular-parser.
Регрессионный тест test_app_import_logs_exceptions_without_local_values: в отдельном процессе импортирует src.app, логирует исключение, у которого в строке raise есть локальная переменная, и проверяет, что трейсбек есть, а значения переменной нет. До исправления тест падал (└ 'local-secret-value' в выводе).

Побочные эффекты (поведение как в tabular-parser):

приложение пишет логи в stdout, а не в stderr, в формате время | уровень | req=… | модуль:функция:строка - сообщение;
stdlib logging перехватывается в loguru. Access-лог uvicorn не пропадает: uvicorn.run() после импорта приложения применяет свой dictConfig и снова включает uvicorn.access (проверено на работающем контейнере tabular-parser: строки "GET /healthcheck HTTP/1.1" 200 есть).

Проверки

make check зелёный: ruff, mypy, unit 993 passed / 35 skipped.
make docker-build прошёл.
make test-integration: 2 failed (test_nats_minio_integration.py: test_subscribe_and_publish_with_msg_id_without_jetstream, test_queue_group_delivers_each_message_to_exactly_one_member). На коде main падают так же (22/40 и 0/1): на общем NATS работает контейнер стенда arm-ka-scan-gateway-1, он стоит в той же queue group и забирает сообщения теста. Изменение тут ни при чём, см. O-3.

Rulings I made

R-1 — setup_logger вызывается на уровне модуля src/app.py, а не внутри create_app(). create_app тесты вызывают многократно, и каждый вызов сбрасывал бы их собственные обработчики loguru; плюс так же сделано в tabular-parser. Цена ошибки: низкая, вызов переносится одной строкой.
R-2 — тест работает в отдельном процессе и со скриптом в файле. В процессе pytest обработчики loguru перенастраивают другие тесты, а без исходного файла (python -c) loguru не аннотирует строки трейсбека, и тест проходил бы даже с diagnose=True. Это проверено: первая версия на -c была зелёной до исправления. Цена ошибки: низкая.

Находки

Маркер	Находка	Статус
O-1	В `logger.py` (во всех трёх сервисах) docstring `is_noise_path` ссылается на `RequestLoggingMiddleware`, которой нет ни в одн��м репозитории; `extra[request_id]` в формате никто не связывает (всегда `req=-`). Остаток шаблона: либо реализовать middleware, либо убрать ссылку и поле	deferred
O-2	В tabular-parser `setup_logger` уже вызывается, но регрессионного теста на отсутствие локальных переменных в логе нет	deferred
O-3	Интеграционные тесты NATS scan-gateway делят subject/queue group с запущенным стендом (`arm-ka-scan-gateway-1`) и при поднятом стенде теряют сообщения. Нужны уникальные subject/группа на прогон или явное требование остановить сервис стенда	deferred
O-4	Фикстура `log_lines` в `tests/conftest.py` после теста возвращает `logger.add(sys.stderr)` с `diagnose=True`, поэтому в выводе pytest видны локальные переменные. Касается только тестов, в прод не попадает	rejected: только тестовый вывод

🤖 Generated with Claude Code

https://claude.ai/code/session_012vJkmBGKKqMoEMzvsXG3y2

Closes #18 ## Что было `src/core/logger.py` содержал `setup_logger()` с `diagnose=False`, но приложение его не вызывало. Работал обработчик loguru по умолчанию (stderr, `diagnose=True`), и трейсбек **любого** залогированного исключения (`logger.exception`, `opt(exception=...)`) содержал значения локальных переменных во всех фреймах, в том числе содержимое запросов и секреты из настроек. ## Что сделано - `src/app.py` вызывает `setup_logger(level="DEBUG" if settings.DEBUG else "INFO")` при импорте модуля, так же как tabular-parser. - Регрессионный тест `test_app_import_logs_exceptions_without_local_values`: в отдельном процессе импортирует `src.app`, логирует исключение, у которого в строке raise есть локальная переменная, и проверяет, что трейсбек есть, а значения переменной нет. До исправления тест падал (`└ 'local-secret-value'` в выводе). Побочные эффекты (поведение как в tabular-parser): - приложение пишет логи в stdout, а не в stderr, в формате `время | уровень | req=… | модуль:функция:строка - сообщение`; - stdlib logging перехватывается в loguru. Access-лог uvicorn **не пропадает**: `uvicorn.run()` после импорта приложения применяет свой `dictConfig` и снова включает `uvicorn.access` (проверено на работающем контейнере tabular-parser: строки `"GET /healthcheck HTTP/1.1" 200` есть). ## Проверки - `make check` зелёный: ruff, mypy, unit 993 passed / 35 skipped. - `make docker-build` прошёл. - `make test-integration`: 2 failed (`test_nats_minio_integration.py`: `test_subscribe_and_publish_with_msg_id_without_jetstream`, `test_queue_group_delivers_each_message_to_exactly_one_member`). **На коде `main` падают так же** (22/40 и 0/1): на общем NATS работает контейнер стенда `arm-ka-scan-gateway-1`, он стоит в той же queue group и забирает сообщения теста. Изменение тут ни при чём, см. O-3. ## Rulings I made - **R-1** — `setup_logger` вызывается на уровне модуля `src/app.py`, а не внутри `create_app()`. `create_app` тесты вызывают многократно, и каждый вызов сбрасывал бы их собственные обработчики loguru; плюс так же сделано в tabular-parser. Цена ошибки: низкая, вызов переносится одной строкой. - **R-2** — тест работает в отдельном процессе и со скриптом в файле. В процессе pytest обработчики loguru перенастраивают другие тесты, а без исходного файла (`python -c`) loguru не аннотирует строки трейсбека, и тест проходил бы даже с `diagnose=True`. Это проверено: первая версия на `-c` была зелёной до исправления. Цена ошибки: низкая. ## Находки | Маркер | Находка | Статус | |---|---|---| | O-1 | В `logger.py` (во всех трёх сервисах) docstring `is_noise_path` ссылается на `RequestLoggingMiddleware`, которой нет ни в одн��м репозитории; `extra[request_id]` в формате никто не связывает (всегда `req=-`). Остаток шаблона: либо реализовать middleware, либо убрать ссылку и поле | deferred | | O-2 | В tabular-parser `setup_logger` уже вызывается, но регрессионного теста на отсутствие локальных переменных в логе нет | deferred | | O-3 | Интеграционные тесты NATS scan-gateway делят subject/queue group с запущенным стендом (`arm-ka-scan-gateway-1`) и при поднятом стенде теряют сообщения. Нужны уникальные subject/группа на прогон или явное требование остановить сервис стенда | deferred | | O-4 | Фикстура `log_lines` в `tests/conftest.py` после теста возвращает `logger.add(sys.stderr)` с `diagnose=True`, поэтому в выводе pytest видны локальные переменные. Касается только тестов, в прод не попадает | rejected: только тестовый вывод | 🤖 Generated with [Claude Code](https://claude.com/claude-code) https://claude.ai/code/session_012vJkmBGKKqMoEMzvsXG3y2

aep added 1 commit 2026-10-08 15:42:31 +03:00

fix(logger): вызывать setup_logger при импорте приложения (#18 ) 3a4b8cc723

setup_logger() с diagnose=False существовал, но не вызывался: работал
обработчик loguru по умолчанию (diagnose=True), и трейсбек любого
залогированного исключения содержал значения локальных переменных.
Теперь src/app.py вызывает setup_logger при импорте, как tabular-parser.

Регрессионный тест в отдельном процессе: исключение с локальной
переменной логируется с трейсбеком, но без её значения.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_012vJkmBGKKqMoEMzvsXG3y2

aep merged commit 1e7027ba73 into main

2026-10-08 15:47:51 +03:00

aep referenced this issue from a commit

2026-10-08 15:47:53 +03:00

Merge pull request 'Логгер: вызывать setup_logger при импорте приложения (#18)' (#20) from feat/18-logger-diagnose into main

aep referenced this pull request

2026-10-08 15:48:34 +03:00

Логгер: setup_logger() не вызывается, loguru выводит локальные переменные в трейсбеках #18

aep referenced this pull request

2026-10-08 15:49:13 +03:00

Follow-ups from #18 #21

Sign in to join this conversation.