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

Merged
aep merged 1 commits from feat/63-logger-diagnose into main 2026-10-08 15:47:36 +03:00
Owner

Closes #63

Что было

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-full зелёный: unit 1262 passed; integration 825 passed; e2e 1 passed; dbml-check, docker-build и web-check прошли.

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

🤖 Generated with Claude Code

https://claude.ai/code/session_012vJkmBGKKqMoEMzvsXG3y2

Closes #63 ## Что было `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-full` зелёный: unit 1262 passed; integration 825 passed; e2e 1 passed; dbml-check, docker-build и web-check прошли. ## 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 | 🤖 Generated with [Claude Code](https://claude.com/claude-code) https://claude.ai/code/session_012vJkmBGKKqMoEMzvsXG3y2
aep added 1 commit 2026-10-08 15:42:27 +03:00
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 631a80d533 into main 2026-10-08 15:47:36 +03:00
Sign in to join this conversation.
No Reviewers
No Label
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: RSHB/arm-core#65
No description provided.