_wait_ready polled appliance status for 30s inside except ControllerError: pass, so a timeout raised a bare service_ready_timeout that discarded whatever actually blocked readiness — the CLI error that kept failing, or the runtime condition that never cleared. The loop now remembers the last failure: a status call that itself raised (chained onto the timeout via 'raise ... from') or, when status returned but never proved ready, the first unmet condition (overall/state/daemon/instance/revision). Both travel on a new non-secret ControllerError.detail that main.py logs. The frontend-facing error code is unchanged, so the RPC contract holds.
- commit
- c8aee34572b5ba501e832537e5cf12d2c4088daa
- parent
- c8d78469cb8e114f6114b75710769dda07614267
- author
- Dami <dami.etoile@gmail.com>
| M | decky/ | 11 | ++++++- |
| M | decky/ | 48 | ++++++++++++++++++++++++++++-- |
| M | decky/ | 10 | ++++++- |
| M | decky/ | 35 | ++++++++++++++++++++++ |
@@ -20,7 +20,16 @@ class Plugin:
2020 value = await operation(*arguments)2121 return {"ok": True, "value": value}2222 except ControllerError as error:23- decky.logger.warning("Sigil controller operation failed: %s", error.code)23+ if error.detail:24+ decky.logger.warning(25+ "Sigil controller operation failed: %s (%s)",26+ error.code,27+ error.detail,28+ )29+ else:30+ decky.logger.warning(31+ "Sigil controller operation failed: %s", error.code32+ )2433 return {"ok": False, "error": error.code}2534 except Exception:2635 decky.logger.exception("Unexpected Sigil controller failure")@@ -424,6 +424,12 @@ class Controller:
424424 previous_instance: Any = None,425425 ) -> dict[str, Any]:426426 deadline = asyncio.get_running_loop().time() + READY_TIMEOUT_SECONDS427+ # Remember why the last poll fell short so a timeout reports the root428+ # cause instead of swallowing it: a status call that itself failed429+ # (last_error) or a status that came back but never proved ready430+ # (last_gap).431+ last_error: ControllerError | None = None432+ last_gap: str | None = None427433 while asyncio.get_running_loop().time() < deadline:428434 try:429435 status = await self._status()@@ -445,10 +451,46 @@ class Controller:
445451 and instance_ok446452 ):447453 return status448- except ControllerError:449- pass454+ last_error = None455+ last_gap = self._describe_readiness_gap(456+ status, runtime, expected_revision, previous_instance457+ )458+ except ControllerError as error:459+ last_error = error460+ last_gap = None450461 await asyncio.sleep(POLL_SECONDS)451- raise ControllerError("service_ready_timeout")462+ detail = last_error.code if last_error is not None else last_gap463+ raise ControllerError("service_ready_timeout", detail) from last_error464+465+466+ def _describe_readiness_gap(467+ status: dict[str, Any],468+ runtime: dict[str, Any],469+ expected_revision: Any,470+ previous_instance: Any,471+ ) -> str:472+ """Name the first unmet readiness condition, for timeout diagnostics."""473+ overall = status.get("overall")474+ if overall not in {"ready", "active"}:475+ return f"overall={overall!r}"476+ if runtime.get("state") != "fresh":477+ return f"runtime.state={runtime.get('state')!r}"478+ if runtime.get("daemon") != "ready":479+ return f"runtime.daemon={runtime.get('daemon')!r}"480+ instance = runtime.get("instance_id")481+ if not isinstance(instance, str):482+ return "runtime.instance_id missing"483+ if (484+ expected_revision is not None485+ and runtime.get("loaded_config_revision") != expected_revision486+ ):487+ return (488+ f"loaded_config_revision={runtime.get('loaded_config_revision')!r} "489+ f"!= expected {expected_revision!r}"490+ )491+ if isinstance(previous_instance, str) and instance == previous_instance:492+ return "runtime.instance_id unchanged from previous"493+ return "readiness conditions not met"452494 453495 454496 def _revision(value: Any) -> str:@@ -1,9 +1,17 @@
11 """Closed errors safe to return through the Decky RPC bridge."""22 3+from __future__ import annotations4+35 46 class ControllerError(Exception):57 """An expected appliance-controller failure with a non-secret code."""68 7- def __init__(self, code: str):9+ def __init__(self, code: str, detail: str | None = None):810 super().__init__(code)911 self.code = code12+ # A non-secret diagnostic describing *why* this failure occurred, when13+ # the code alone would hide the root cause (e.g. a readiness timeout14+ # that swallowed the last polling error). Never returned across the RPC15+ # bridge — only logged host-side — so it stays independent of the16+ # frontend-facing `code` contract.17+ self.detail = detail@@ -232,6 +232,41 @@ class ControllerTests(unittest.IsolatedAsyncioTestCase):
232232 with self.assertRaisesRegex(ControllerError, "service_ready_timeout"):233233 await self.controller.restart_service()234234 235+ async def test_wait_ready_timeout_reports_last_polling_error(self):236+ controller = Controller(self.runner)237+238+ async def failing_status() -> dict[str, Any]:239+ raise ControllerError("command_timeout")240+241+ controller._status = failing_status242+ with (243+ mock.patch("goq_sigil.controller.READY_TIMEOUT_SECONDS", 0.02),244+ mock.patch("goq_sigil.controller.POLL_SECONDS", 0.0),245+ self.assertRaises(ControllerError) as caught,246+ ):247+ await controller._wait_ready(previous_instance="0" * 32)248+ self.assertEqual(caught.exception.code, "service_ready_timeout")249+ self.assertEqual(caught.exception.detail, "command_timeout")250+ self.assertIsInstance(caught.exception.__cause__, ControllerError)251+ self.assertEqual(caught.exception.__cause__.code, "command_timeout")252+253+ async def test_wait_ready_timeout_reports_unmet_condition(self):254+ controller = Controller(self.runner)255+256+ async def degraded_status() -> dict[str, Any]:257+ return {"overall": "degraded", "runtime": {}}258+259+ controller._status = degraded_status260+ with (261+ mock.patch("goq_sigil.controller.READY_TIMEOUT_SECONDS", 0.02),262+ mock.patch("goq_sigil.controller.POLL_SECONDS", 0.0),263+ self.assertRaises(ControllerError) as caught,264+ ):265+ await controller._wait_ready(previous_instance="0" * 32)266+ self.assertEqual(caught.exception.code, "service_ready_timeout")267+ self.assertEqual(caught.exception.detail, "overall='degraded'")268+ self.assertIsNone(caught.exception.__cause__)269+235270 async def test_restart_from_proven_absent_runtime_accepts_first_instance(self):236271 self.runner.instance = None237272 self.runner.active = False