From eab7e3b9f37bd4d7713a48898a185cc8a7519dc3 Mon Sep 17 00:00:00 2001 From: Light1YT Date: Sat, 27 Jun 2026 07:43:49 +0500 Subject: [PATCH] fix(backend): emit app.* INFO logs to stdout on the API process (#1926) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit App-level logs (logging.getLogger("app.*")) had no StreamHandler, so their INFO was lost — `docker logs gendesign-backend-1` showed only uvicorn loggers. Useful lines (e.g. "OSRM road-distance applied", RBAC, analyze) were invisible when debugging on the VPS (only Sentry/GlitchTip received them as breadcrumbs). main.py now attaches one StreamHandler to the root "app" logger at APP_LOG_LEVEL (default INFO), idempotent (marker guard), propagate=True so the Sentry LoggingIntegration on root still gets breadcrumbs/events and there's no stdout double (root has no stdout handler). API process only — celery worker (celery_app.py) untouched, since its loaders log per-sync and would be noisy. Flood-safe on the API: the analyze hot path logs INFO per-request (parcels.py has 3 logger.info), not per-row. Adds tests/test_app_logging.py (handler present, level INFO, propagate intact). Refs #1926 --- backend/app/main.py | 18 ++++++++++++++++++ backend/tests/test_app_logging.py | 30 ++++++++++++++++++++++++++++++ 2 files changed, 48 insertions(+) create mode 100644 backend/tests/test_app_logging.py diff --git a/backend/app/main.py b/backend/app/main.py index 296ab9a2..a13903ed 100644 --- a/backend/app/main.py +++ b/backend/app/main.py @@ -48,6 +48,24 @@ from app.observability.sentry_scrub import scrub_sensitive_query logger = logging.getLogger(__name__) +# App-level логи в stdout контейнера (#1926 observability). По умолчанию у app.* +# логгеров нет StreamHandler → их INFO теряется (в `docker logs` видны только +# uvicorn-логгеры), поэтому полезные строки (напр. "OSRM road-distance applied", +# RBAC, analyze) невидимы при отладке на VPS. Вешаем один StreamHandler на корневой +# "app" логгер на уровне APP_LOG_LEVEL (default INFO). propagate оставляем True → +# Sentry/GlitchTip LoggingIntegration (хендлер на root) продолжает получать +# breadcrumbs/events. Двойного stdout нет: у root своего stdout-хендлера нет. +# Идемпотентно (маркер _gd_app_stream — guard против дубля при reload/повторном +# импорте). Только API-процесс (main.py); worker (celery_app.py) НЕ трогаем — +# там loader'ы чатятся per-sync, INFO бы зашумил. +_app_logger = logging.getLogger("app") +_app_logger.setLevel(getattr(logging, os.getenv("APP_LOG_LEVEL", "INFO").upper(), logging.INFO)) +if not any(getattr(_h, "_gd_app_stream", False) for _h in _app_logger.handlers): + _stream = logging.StreamHandler() + _stream.setFormatter(logging.Formatter("%(asctime)s %(levelname)s %(name)s %(message)s")) + _stream._gd_app_stream = True # type: ignore[attr-defined] # idempotency marker + _app_logger.addHandler(_stream) + # Инициализируем SDK до создания FastAPI app, чтобы все инструменты # (middleware, маршруты) видели активный client с самого старта процесса. # GlitchTip не поддерживает profiling — profiles_sample_rate=0.0. diff --git a/backend/tests/test_app_logging.py b/backend/tests/test_app_logging.py new file mode 100644 index 00000000..386334a5 --- /dev/null +++ b/backend/tests/test_app_logging.py @@ -0,0 +1,30 @@ +"""#1926 observability: app-logger StreamHandler в main.py (логи app.* в stdout). + +Без него INFO от `logging.getLogger("app.*")` терялся (в `docker logs` видны были +только uvicorn-логгеры), и полезные строки (OSRM road-distance applied, RBAC, +analyze) были невидимы при отладке на VPS. +""" + +from __future__ import annotations + +import logging + + +def test_app_logger_has_stdout_handler() -> None: + import app.main # noqa: F401 — module-level logging setup выполняется на импорте + + app_logger = logging.getLogger("app") + + # Уровень INFO (default APP_LOG_LEVEL). + assert app_logger.level == logging.INFO + + # Ровно один маркированный StreamHandler — идемпотентность (повторный импорт + # не плодит дубли). + marked = [h for h in app_logger.handlers if getattr(h, "_gd_app_stream", False)] + assert len(marked) == 1 + assert isinstance(marked[0], logging.StreamHandler) + + # propagate=True → Sentry/GlitchTip LoggingIntegration (хендлер на root) + # продолжает получать breadcrumbs/events; stdout-дубля нет (у root своего + # stdout-хендлера нет). + assert app_logger.propagate is True