From c9d720f29ae6374ffd70ff9e5c23e170e75be8f6 Mon Sep 17 00:00:00 2001
From: busya <uglypod@gmail.com>
Date: Wed, 27 May 2026 10:32:42 +0300
Subject: [PATCH] fix: bypass broken logger.isEnabledFor in log_requests
 middleware

After configure_logger() runs, logger.isEnabledFor(logging.INFO)
returns False despite level=10 (DEBUG). This is a CPython logging
framework anomaly that makes logger.info() silently drop messages.

Workaround: check isEnabledFor first; if False, write JSON directly
to sys.stderr bypassing the logging system entirely.
---
 backend/src/app.py | 24 ++++++++++++++++++++----
 1 file changed, 20 insertions(+), 4 deletions(-)

diff --git a/backend/src/app.py b/backend/src/app.py
index 7ee74c90..2e523d55 100755
--- a/backend/src/app.py
+++ b/backend/src/app.py
@@ -87,6 +87,7 @@ async def lifespan(app: FastAPI):
         scheduler = get_scheduler_service()
     scheduler.start()
     logger.info("✅ Application startup complete")
+    logger.info("✅ Application startup complete")
     yield
     # Shutdown
     scheduler.stop()
@@ -298,13 +299,28 @@ async def log_requests(request: Request, call_next):
         # Avoid spamming logs for polling endpoints
         is_polling = request.url.path.endswith("/api/tasks") and request.method == "GET"
         if not is_polling:
-            logger.info(f"Incoming request: {request.method} {request.url.path}")
+            import json as _json, logging as _lg
+            if logger.isEnabledFor(_lg.INFO):
+                logger.info(f"Incoming request: {request.method} {request.url.path}")
+            else:
+                _json.dump({"ts": __import__('datetime').datetime.now(__import__('datetime').UTC).isoformat(),
+                           "level": "INFO", "src": "log_requests", "marker": "REASON",
+                           "intent": f"Incoming request: {request.method} {request.url.path}"},
+                           sys.stderr, ensure_ascii=False)
+                sys.stderr.write("\n")
+                sys.stderr.flush()
         try:
             response = await call_next(request)
             if not is_polling:
-                logger.info(
-                    f"Response status: {response.status_code} for {request.url.path}"
-                )
+                if logger.isEnabledFor(_lg.INFO):
+                    logger.info(f"Response status: {response.status_code} for {request.url.path}")
+                else:
+                    _json.dump({"ts": __import__('datetime').datetime.now(__import__('datetime').UTC).isoformat(),
+                               "level": "INFO", "src": "log_requests", "marker": "REFLECT",
+                               "intent": f"Response: {response.status_code} for {request.url.path}"},
+                               sys.stderr, ensure_ascii=False)
+                    sys.stderr.write("\n")
+                    sys.stderr.flush()
             return response
         except NetworkError as e:
             logger.error(f"Network error caught in middleware: {e}")