feat: unified logging with logging_kit.py

1 files changed, 102 insertions, 22 deletions

diff --git a/app/ui/taskview.py b/app/ui/taskview.py
index d7aed96..3831ceb 100644
--- a/app/ui/taskview.py
+++ b/app/ui/taskview.py
@@ -7,8 +7,11 @@ dumped the user into plain console output. This widget keeps them inside the
 hub's curses session: a worker thread runs an ordered list of ``TaskStep``s
 while the main thread redraws a DOS-style frame showing each step's state
 (pending / running with a spinner and elapsed clock / [OK] / [FAIL]), an
-optional progress bar for the current step, and a dim scrolling log tail of
-the step's output.
+optional progress bar for the current step, and a dim log tail of the step's
+output filling the remaining screen height. Every line the view shows is also
+mirrored to the ``tui_YYYYMMDD.log`` day stream under app/logs (see
+``_ConsoleLog``), so console output survives the curses session even when the
+step itself keeps no log.
 
 Steps stream their output by calling ``emit(line)`` (or simply printing to
 stdout/stderr, which the view captures). The view turns output into progress
@@ -43,17 +46,22 @@ import sys
 import threading
 import time
 from dataclasses import dataclass
+from datetime import datetime
 from queue import Empty, Queue
 from typing import Callable, List, Optional, Tuple
 
+import logging_kit
+
 from ui import tui
 from ui.viewkit import (TERMINAL_PHASES as _TERMINAL,
-                       DRAW_TIMEOUT_MS as _DRAW_TIMEOUT_MS,
-                       ScreenView, _box, _fit, _format_elapsed, _sep,
-                       _text)
+                        DRAW_TIMEOUT_MS as _DRAW_TIMEOUT_MS,
+                        ScreenView, _box, _fit, _format_elapsed, _sep,
+                        _text)
 
-# How many recent output lines the log tail keeps.
-_LOG_TAIL = 10
+# How many recent output lines the tail keeps in memory. The on-screen tail
+# draws as many as fit (see render); the full run is also mirrored to the
+# ``tui_`` day stream under app/logs (see _ConsoleLog).
+_LOG_KEEP = 1000
 
 # Progress-line matchers, in order of precedence.
 _PROGRESS_BYTES = re.compile(r"AUDIOCPP_PROGRESS downloaded=(\d+) total=(\d+)")
@@ -143,6 +151,43 @@ def _silence_cue_text(silent: float) -> str:
     return f"(no output {int(silent // 60)}m)"
 
 
+class _ConsoleLog:
+    """Mirrors a task view's console output into the ``tui_`` day stream.
+
+    Every line the view shows (minus machine-readable progress lines) is
+    appended to ``app/logs/tui_YYYYMMDD.log``, with a separator header per
+    run and step start/finish markers, so no in-TUI console output is lost.
+    The file is opened lazily on the first line — a run with no output
+    creates nothing — and every write is best-effort: an unwritable
+    app/logs simply disables the mirror. One instance per view run; both
+    lanes of a LanesView share theirs (ingestion runs on the main thread).
+    """
+
+    def __init__(self, title: str):
+        self._title = title
+        self._handle = None
+        self._started = False
+
+    def line(self, text: str) -> None:
+        """Append TEXT (and, once, the run's separator header)."""
+        if not self._started:
+            self._started = True
+            self._handle = logging_kit.day_stream("tui")
+            logging_kit.write_line(self._handle, "")
+            logging_kit.write_line(
+                self._handle, f"=== {self._title} — "
+                              f"{datetime.now():%Y-%m-%d %H:%M:%S} ===")
+        logging_kit.write_line(self._handle, text)
+
+    def close(self) -> None:
+        if self._handle is not None:
+            try:
+                self._handle.close()
+            except OSError:
+                pass
+            self._handle = None
+
+
 def _lane_step_mark(current: Optional[int],
                     results: List[Optional[int]],
                     cancelled_step: Optional[int],
@@ -238,6 +283,8 @@ class TaskView(ScreenView):
         self.finished_at: Optional[float] = None
         self.cancelled = False
         self.cancelling = False
+        # -- console mirror (app/logs/tui_YYYYMMDD.log) ----------------
+        self._console_log = _ConsoleLog(title)
         # -- threads ---------------------------------------------------
         self._queue: Queue = Queue()
         self._cancel = threading.Event()
@@ -295,27 +342,37 @@ class TaskView(ScreenView):
             self.last_line_at = self._now()
             self._progress = None
             self._progress_kind = ""
+            self._console_log.line(f"--- {event.get('title') or ''} ---")
         elif kind == "line":
             text = event.get("text") or ""
             self._ingest_line(text)
         elif kind == "step_done":
             index = event["index"]
-            self.results[index] = event.get("rc") or 0
+            rc = event.get("rc") or 0
+            self.results[index] = rc
             self.current = None
             self.last_line_at = None
             self._progress = None
             self._progress_kind = ""
+            self._console_log.line(
+                f"[{'OK' if rc == 0 else 'FAIL'}] "
+                f"{self.steps[index].title} (exit {rc})")
         elif kind == "step_cancelled":
-            self.cancelled_step = event["index"]
+            index = event["index"]
+            self.cancelled_step = index
             self.current = None
             self.last_line_at = None
             self._progress = None
             self._progress_kind = ""
+            self._console_log.line(
+                f"[x] {self.steps[index].title} (cancelled)")
         elif kind == "finish":
             self.phase = event.get("phase") or "done"
             self.cancelled = self.phase == "cancelled"
             self.finished_at = self._now()
             self.current = None
+            self._console_log.line(
+                f"=== {self.phase} (exit {event.get('rc') or 0}) ===")
 
     def _ingest_line(self, text: str) -> None:
         """Fold one output line into the log tail and progress bar."""
@@ -333,8 +390,9 @@ class TaskView(ScreenView):
             # Percent/count lines stay in the log (the tail already
             # collapses rapid \r updates to the last full line).
         self.log_tail.append(line)
-        if len(self.log_tail) > _LOG_TAIL:
-            del self.log_tail[: len(self.log_tail) - _LOG_TAIL]
+        if len(self.log_tail) > _LOG_KEEP:
+            del self.log_tail[: len(self.log_tail) - _LOG_KEEP]
+        self._console_log.line(line)
 
     # ScreenView hooks ------------------------------------------------
 
@@ -358,6 +416,10 @@ class TaskView(ScreenView):
             return 1
         return next((rc for rc in self.results if rc), 0)
 
+    def _on_stop(self) -> None:
+        self._console_log.close()
+        super()._on_stop()
+
     def _prompt_cancel(self) -> bool:
         """Esc/q: confirm cancel, then wait for the worker to wind down."""
         self._blocking()
@@ -439,12 +501,14 @@ class TaskView(ScreenView):
             y += 1
 
         # -- log tail --------------------------------------------------
-        for line in self.log_tail[-_LOG_TAIL:]:
-            _text(scr, theme, y, inner_x, _fit(line, width - inner_x - 2),
-                  theme["dim"])
-            y += 1
-            if y >= height - 3:
-                break
+        # Every recent line that fits between here and the footer; the
+        # full run lives in the tui_ day stream (see _ConsoleLog).
+        room = (height - 3) - y
+        if room > 0:
+            for line in self.log_tail[-room:]:
+                _text(scr, theme, y, inner_x, _fit(line, width - inner_x - 2),
+                      theme["dim"])
+                y += 1
 
         # -- footer ----------------------------------------------------
         suffix = "" if not self.wait_on_finish else " — press any key to return"
@@ -659,6 +723,7 @@ class LanesView(_GetchModes):
         self.theme = tui._ensure_theme(curses)
         self._clock = clock
         self._lanes = [_LaneState(lane.title, lane.steps) for lane in lanes]
+        self._console_log = _ConsoleLog(title)   # shared by both lanes
         self.phase = "running"   # running | done | error | cancelled
         self.cancelled = False
         self.cancelling = False
@@ -704,23 +769,35 @@ class LanesView(_GetchModes):
             lane.last_line_at = self._now()
             lane.progress = None
             lane.progress_kind = ""
+            self._console_log.line(
+                f"--- [{lane.title}] {event.get('title') or ''} ---")
         elif kind == "line":
             self._ingest_lane_line(lane, event.get("text") or "")
         elif kind == "step_done":
-            lane.results[event["index"]] = event.get("rc") or 0
+            index = event["index"]
+            rc = event.get("rc") or 0
+            lane.results[index] = rc
             lane.current = None
             lane.last_line_at = None
             lane.progress = None
             lane.progress_kind = ""
+            self._console_log.line(
+                f"[{'OK' if rc == 0 else 'FAIL'}] [{lane.title}] "
+                f"{lane.steps[index].title} (exit {rc})")
         elif kind == "step_cancelled":
-            lane.cancelled_step = event["index"]
+            index = event["index"]
+            lane.cancelled_step = index
             lane.current = None
             lane.last_line_at = None
             lane.progress = None
             lane.progress_kind = ""
+            self._console_log.line(
+                f"[x] [{lane.title}] {lane.steps[index].title} (cancelled)")
         elif kind == "lane_finish":
             lane.rc = event.get("rc") or 0
             lane.finished = True
+            self._console_log.line(
+                f"=== [{lane.title}] finished (exit {lane.rc}) ===")
 
     def _ingest_lane_line(self, lane: _LaneState, text: str) -> None:
         """Fold one output line into LANE's log tail and progress bar."""
@@ -736,8 +813,9 @@ class LanesView(_GetchModes):
             if kind == "bytes":
                 return
         lane.log_tail.append(line)
-        if len(lane.log_tail) > _LOG_TAIL:
-            del lane.log_tail[: len(lane.log_tail) - _LOG_TAIL]
+        if len(lane.log_tail) > _LOG_KEEP:
+            del lane.log_tail[: len(lane.log_tail) - _LOG_KEEP]
+        self._console_log.line(line)
 
     def _drain(self) -> None:
         for lane in self._lanes:
@@ -762,6 +840,7 @@ class LanesView(_GetchModes):
                     self.phase = "error"
                     break
         self.finished_at = self._now()
+        self._console_log.line(f"=== {self.phase} ===")
 
     def _now(self) -> float:
         return self._clock()
@@ -814,6 +893,7 @@ class LanesView(_GetchModes):
                 # must not make later hub dialogs dismiss themselves.
                 self._blocking()
         finally:
+            self._console_log.close()
             sys.stdout, sys.stderr = saved_out, saved_err
 
     def _get_key(self) -> Optional[int]:
@@ -935,7 +1015,7 @@ class LanesView(_GetchModes):
                   theme["accent"])
             row += 1
 
-        for line in lane.log_tail[-_LOG_TAIL:]:
+        for line in lane.log_tail:
             if row >= y + h - 1:
                 break
             _text(scr, theme, row, x + 1, _fit(line, w - 3), theme["dim"])