refactor(app_controller): migrate 2 timeline event sink sites to Result (Phase 6 Group 6.2)

Replaces logging.debug bodies in mark_first_frame_rendered (L1355) and _on_warmup_complete_for_timeline (L1451) with proper Result[T] propagation: - _write_first_frame_timeline_result() -> Result[None] - _write_warmup_complete_timeline_result() -> Result[None] - _record_startup_timeline_error(op_name, result): stderr write + append to self._startup_timeline_errors for sub-track 4 GUI The instance list is the durable data plane; the stderr write is the best-effort visible drain (user-confirmed acceptable terminal sink until sub-track 4 lands GUI-side error display). Audit: INTERNAL_SILENT_SWALLOW for src/app_controller.py: 28 -> 26.
2026-06-19 15:52:20 -04:00
parent 108e77e11d
commit d794a5888b
2 changed files with 120 additions and 2 deletions
@@ -831,6 +831,12 @@ class AppController:
  # inside the signal handler IS the drain (Pattern 3: intentional
  # termination). Stored for sub-track 4 GUI to display in degraded mode.
  self._signal_handler_error:          Optional[ErrorInfo] = None
+  # --- Startup timeline event-sink state (Phase 6: Group 6.2) ---
+  # One entry per failed timeline-event stderr write. The stderr write
+  # IS the visible drain (user-confirmed acceptable terminal sink until
+  # sub-track 4 lands GUI-side error display); the instance list is
+  # the durable data plane for sub-track 4 to drain.
+  self._startup_timeline_errors:        List[Tuple[str, ErrorInfo]] = []  # (op_name, error)
  # --- Shared background pool + proactive warmup (startup_speedup_20260606) ---
  self._io_pool = make_io_pool()
  _install_sigint_exit_handler(self)
@@ -1330,6 +1336,13 @@ class AppController:
  """Called by the App on the first frame render. Stamps first_frame_ts and logs the timeline to stderr. [SDM: src/app_controller.py:mark_first_frame_rendered] [C: src/gui_2.py:render_main_interface]"""
  if self._first_frame_ts is not None: return
  self._first_frame_ts = ts if ts is not None else time.time()
+  result = self._write_first_frame_timeline_result()
+  self._record_startup_timeline_error("first_frame_timeline", result)
+
+ def _write_first_frame_timeline_result(self) -> "Result[None]":
+  """Build the first-frame timeline line and write to stderr. Returns Result[None] (Phase 6 Group 6.2).
+  On failure: OSError/ValueError/TypeError -> ErrorInfo(original=e).
+  Caller (`mark_first_frame_rendered`) records via `_record_startup_timeline_error`."""
  try:
   warmup_ms           = (self._warmup_done_ts - self._init_start_ts) * 1000 if self._warmup_done_ts is not None else 0.0
   frame_after_init_ms = (self._first_frame_ts - self._init_start_ts) * 1000
@@ -1352,8 +1365,28 @@ class AppController:
     gap_str = f" (rendered {delta_ms:.1f}ms AFTER warmup done)"
   sys.stderr.write(f"[startup] first frame at {frame_after_init_ms:.1f}ms after init (warmup took {warmup_ms:.1f}ms){phase_str}{gap_str}\n")
   sys.stderr.flush()
+   return OK
  except (OSError, ValueError, TypeError) as e:
-   logging.getLogger(__name__).debug("first frame timeline write failed: %s", e, extra={"source": "app_controller.mark_first_frame_rendered"})
+   return Result(data=None, errors=[ErrorInfo(
+    kind=ErrorKind.INTERNAL,
+    message=str(e),
+    source="app_controller._write_first_frame_timeline_result",
+    original=e,
+   )])
+
+ def _record_startup_timeline_error(self, op_name: str, result: "Result[None]") -> None:
+  """Drain a startup-timeline error (Phase 6 Group 6.2): stderr write +
+  append to self._startup_timeline_errors for sub-track 4 GUI.
+
+  The instance list is the durable data plane; the stderr write is the
+  best-effort visible drain. If stderr itself is broken, the OSError
+  propagates up to the caller (the timeline event sink); the appended
+  entry on the list remains as the durable record."""
+  if not result.ok:
+   err = result.errors[0]
+   self._startup_timeline_errors.append((op_name, err))
+   sys.stderr.write(f"[startup-timeline-error] {op_name}: {err.ui_message()}\n")
+   sys.stderr.flush()

 def mark_gui_run_started(self, ts: "Optional[float]" = None) -> None:
  """Called by App.run() before the heavy imgui bundle setup. Captures
@@ -1436,6 +1469,13 @@ class AppController:
 def _on_warmup_complete_for_timeline(self, snap: dict) -> None:
  """Callback registered with the WarmupManager. Stamps warmup_done_ts and logs the timeline to stderr. [C: src/app_controller.py:startup_timeline]"""
  self._warmup_done_ts = time.time()
+  result = self._write_warmup_complete_timeline_result()
+  self._record_startup_timeline_error("warmup_complete_timeline", result)
+
+ def _write_warmup_complete_timeline_result(self) -> "Result[None]":
+  """Build the warmup-complete timeline line and write to stderr. Returns Result[None] (Phase 6 Group 6.2).
+  On failure: OSError/ValueError/TypeError -> ErrorInfo(original=e).
+  Caller (`_on_warmup_complete_for_timeline`) records via `_record_startup_timeline_error`."""
  try:
   warmup_ms = (self._warmup_done_ts - self._init_start_ts) * 1000
   if self._first_frame_ts is None:
@@ -1448,8 +1488,14 @@ class AppController:
     gap_str = f" (first frame rendered {delta_ms:.1f}ms after warmup done)"
   sys.stderr.write(f"[startup] warmup done in {warmup_ms:.1f}ms{gap_str}\n")
   sys.stderr.flush()
+   return OK
  except (OSError, ValueError, TypeError) as e:
-   logging.getLogger(__name__).debug("warmup timeline write failed: %s", e, extra={"source": "app_controller._on_warmup_complete_for_timeline"})
+   return Result(data=None, errors=[ErrorInfo(
+    kind=ErrorKind.INTERNAL,
+    message=str(e),
+    source="app_controller._write_warmup_complete_timeline_result",
+    original=e,
+   )])

 @property
 def perf_profiling_enabled(self) -> bool:
@@ -206,3 +206,75 @@ def test_install_sigint_exit_handler_no_error_when_signal_install_succeeds():
 with patch("src.app_controller.signal.signal"):
  _install_sigint_exit_handler(ctrl)
 assert ctrl._signal_handler_error is None
+
+
+# --- Phase 6: Group 6.2 (timeline event sinks; stderr + instance state carry) ---
+
+def test_first_frame_timeline_returns_ok_in_normal_path():
+ """
+ Event sink (drain: stderr + instance state): mark_first_frame_rendered
+ extracts timeline-write logic into a Result-returning helper.
+ On the happy path, no error is recorded.
+ """
+ from src.app_controller import AppController
+ ctrl = AppController()
+ ctrl._warmup_done_ts = ctrl._init_start_ts + 0.5
+ ctrl.mark_first_frame_rendered(ts=ctrl._init_start_ts + 1.0)
+ # The first frame was logged; any error would be appended to the
+ # timeline-errors list. The list starts empty on a fresh controller.
+ assert all(op != "first_frame_timeline" for op, _ in ctrl._startup_timeline_errors)
+
+
+def test_warmup_complete_timeline_returns_ok_in_normal_path():
+ """
+ Event sink (drain: stderr + instance state): _on_warmup_complete_for_timeline
+ extracts timeline-write logic into a Result-returning helper.
+ On the happy path, no error is recorded.
+ """
+ from src.app_controller import AppController
+ ctrl = AppController()
+ ctrl._first_frame_ts = None
+ ctrl._on_warmup_complete_for_timeline({})
+ assert all(op != "warmup_complete_timeline" for op, _ in ctrl._startup_timeline_errors)
+
+
+def test_first_frame_timeline_records_error_on_stderr_failure():
+ """
+ When the stderr write fails inside the helper, the timeline event sink
+ records the error in self._startup_timeline_errors for sub-track 4 GUI to drain.
+ The OSError from the helper propagates up; we catch it here so the test
+ only verifies the durable append.
+ """
+ from src.app_controller import AppController
+ ctrl = AppController()
+ # Force the stderr write to fail by patching write on sys.stderr.
+ with patch("src.app_controller.sys.stderr") as mock_stderr:
+  mock_stderr.write = MagicMock(side_effect=OSError("stderr closed"))
+  try:
+   ctrl.mark_first_frame_rendered(ts=ctrl._init_start_ts + 0.1)
+  except OSError:
+   pass  # the helper propagates the stderr failure; the append still happened
+ first_frame_errors = [(op, e) for op, e in ctrl._startup_timeline_errors if op == "first_frame_timeline"]
+ assert len(first_frame_errors) >= 1
+ assert isinstance(first_frame_errors[0][1], ErrorInfo)
+ assert "stderr closed" in first_frame_errors[0][1].message
+
+
+def test_warmup_complete_timeline_records_error_on_stderr_failure():
+ """
+ When the stderr write fails, the warmup-complete timeline sink records
+ the error in self._startup_timeline_errors.
+ """
+ from src.app_controller import AppController
+ ctrl = AppController()
+ ctrl._first_frame_ts = None
+ with patch("src.app_controller.sys.stderr") as mock_stderr:
+  mock_stderr.write = MagicMock(side_effect=OSError("stderr closed"))
+  try:
+   ctrl._on_warmup_complete_for_timeline({})
+  except OSError:
+   pass
+ warmup_errors = [(op, e) for op, e in ctrl._startup_timeline_errors if op == "warmup_complete_timeline"]
+ assert len(warmup_errors) >= 1
+ assert isinstance(warmup_errors[0][1], ErrorInfo)
+ assert "stderr closed" in warmup_errors[0][1].message