Доработка логирования

pyproject.toml

@@ -4,7 +4,7 @@ build-backend = "setuptools.build_meta"
 
 [project]
 name = "config_manager"
-version = "2.2.1"
+version = "2.2.2"
 description = "Большой рефакторинг, логирование"
 authors = [
     { name = "Aleksei Zosimov", email = "lesha.spb@gmail.com" }

src/config_manager/v2/control/http_channel.py

@@ -169,7 +169,7 @@ class HttpControlChannel(ControlChannel):
             started = time.monotonic()
             response = await call_next(request)
             duration_ms = int((time.monotonic() - started) * 1000)
-            logger.info(
+            logger.debug(
                 "API call: method=%s path=%s status=%s duration_ms=%s",
                 request.method,
                 request.url.path,
@@ -230,6 +230,7 @@ class HttpControlChannel(ControlChannel):
                 "HttpControlChannel._action_response result: action=%s status_code=404 detail=handler not configured",
                 action,
             )
+            logger.warning("control command: action=%s status=handler_not_configured", action)
             return JSONResponse(
                 content={"status": "error", "detail": f"{action} handler is not configured"},
                 status_code=404,
@@ -243,15 +244,18 @@ class HttpControlChannel(ControlChannel):
                 action,
                 detail,
             )
+            logger.warning("control command: action=%s status=ok", action)
             return JSONResponse(content={"status": "ok", "detail": detail}, status_code=200)
         except asyncio.TimeoutError:
-            logger.warning("HttpControlChannel._action_response timeout: action=%s timeout=%s", action, self._timeout)
+            logger.debug("HttpControlChannel._action_response timeout: action=%s timeout=%s", action, self._timeout)
+            logger.warning("control command: action=%s status=timeout", action)
             return JSONResponse(
                 content={"status": "error", "detail": f"{action} handler did not respond within {self._timeout}s"},
                 status_code=504,
             )
         except Exception as exc:  # noqa: BLE001
-            logger.exception("HttpControlChannel._action_response error: action=%s", action)
+            logger.debug("HttpControlChannel._action_response error: action=%s", action, exc_info=True)
+            logger.warning("control command: action=%s status=error", action)
             return JSONResponse(content={"status": "error", "detail": str(exc)}, status_code=500)
 
     async def start(

src/config_manager/v2/control/telegram.py

@@ -62,7 +62,7 @@ class TelegramControlChannel(ControlChannel):
                 for update in updates:
                     await self._process_update(update)
             except Exception as exc:  # noqa: BLE001
-                self._logger.warning("Telegram polling error: %s", exc)
+                self._logger.debug("Telegram polling error: %s", exc, exc_info=True)
 
             try:
                 await asyncio.wait_for(self._stop_event.wait(), timeout=max(self._poll_interval, 0.1))
@@ -94,16 +94,32 @@ class TelegramControlChannel(ControlChannel):
         if chat_id != self._chat_id:
             return
 
-        if text in {"/start", "/run"} and self._on_start is not None:
-            reply = await self._on_start()
-        elif text in {"/stop", "/halt"} and self._on_stop is not None:
-            reply = await self._on_stop()
-        elif text in {"/status", "/health"} and self._on_status is not None:
-            reply = await self._on_status()
+        action: Optional[str]
+        callback: Optional[StartHandler | StopHandler | StatusHandler]
+        if text in {"/start", "/run"}:
+            action = "start"
+            callback = self._on_start
+        elif text in {"/stop", "/halt"}:
+            action = "stop"
+            callback = self._on_stop
+        elif text in {"/status", "/health"}:
+            action = "status"
+            callback = self._on_status
         else:
             return
 
-        await asyncio.to_thread(self._send_message, reply)
+        if callback is None:
+            self._logger.warning("control command: action=%s status=handler_not_configured", action)
+            return
+        try:
+            reply = await callback()
+            await asyncio.to_thread(self._send_message, reply)
+            self._logger.warning("control command: action=%s status=ok", action)
+        except asyncio.TimeoutError:
+            self._logger.warning("control command: action=%s status=timeout", action)
+        except Exception:
+            self._logger.debug("Telegram control command error: action=%s", action, exc_info=True)
+            self._logger.warning("control command: action=%s status=error", action)
 
     def _send_message(self, text: str) -> None:
         """Отправить текстовый ответ в настроенный чат Telegram."""

src/config_manager/v2/core/manager.py

@@ -78,7 +78,7 @@ class _RuntimeController:
 
     def _on_worker_degraded_change(self, degraded: bool) -> None:
         self._worker_degraded = degraded
-        self.logger.warning("ConfigManagerV2._on_worker_degraded_change result: degraded=%s", degraded)
+        self.logger.debug("ConfigManagerV2._on_worker_degraded_change result: degraded=%s", degraded)
 
     def _on_worker_metrics_change(self, inflight_count: int, timed_out_count: int) -> None:
         self._worker_inflight_count = inflight_count
@@ -131,7 +131,7 @@ class _RuntimeController:
             self.logger.warning("ConfigManagerV2._worker_loop result: stopped")
 
     async def _periodic_update_loop(self) -> None:
-        self.logger.warning(
+        self.logger.debug(
             "ConfigManagerV2._periodic_update_loop result: started update_interval=%s",
             self.update_interval,
         )
@@ -144,7 +144,7 @@ class _RuntimeController:
                 except asyncio.TimeoutError:
                     continue
         finally:
-            self.logger.warning("ConfigManagerV2._periodic_update_loop result: stopped")
+            self.logger.debug("ConfigManagerV2._periodic_update_loop result: stopped")
 
     async def _status_text(self) -> str:
         health = await self._health_aggregator.collect()

src/config_manager/v2/core/scheduler.py

@@ -64,7 +64,7 @@ class WorkerLoop:
         self._degraded = value
         if self._on_degraded_change is not None:
             self._on_degraded_change(value)
-        logger.warning("WorkerLoop.run degraded state changed: degraded=%s", value)
+        logger.debug("WorkerLoop.run degraded state changed: degraded=%s", value)
 
     def _start_execute(self) -> None:
         execute_id = next(self._id_seq)
@@ -107,7 +107,7 @@ class WorkerLoop:
                 continue
             execution.timeout_reported = True
             self._notify_error(TimeoutError(f"execute() did not finish within {self._execute_timeout}s"))
-            logger.warning(
+            logger.debug(
                 "WorkerLoop.run execute timeout: id=%s elapsed=%.3fs timeout=%ss",
                 execution.id,
                 elapsed,
@@ -154,7 +154,7 @@ class WorkerLoop:
 
         if self._inflight:
             if self._has_timed_out_inflight():
-                logger.warning("WorkerLoop.run stop: timed-out execute still running; exiting without waiting")
+                logger.debug("WorkerLoop.run stop: timed-out execute still running; exiting without waiting")
             else:
                 await asyncio.gather(*(item.task for item in self._inflight), return_exceptions=True)
                 self._collect_finished()