aboutsummaryrefslogtreecommitdiff
path: root/app
diff options
context:
space:
mode:
authorhistoria <historiavg@proton.me>2026-08-28 03:16:14 -0400
committerhistoria <historiavg@proton.me>2026-08-28 03:16:14 -0400
commitd487996281f71ccd3034dd708fa099057e528b42 (patch)
tree989d9f40f5c2dbb03e1cf570f2c463f43cf5ac76 /app
parent5c3db8f500ff206f3a675d8f4184cb0d61f94804 (diff)
downloadtts-audiobook-generator-d487996281f71ccd3034dd708fa099057e528b42.tar.gz
feat: unified logging with logging_kit.py
Diffstat (limited to 'app')
-rw-r--r--app/backends/audiocpp/build.py12
-rw-r--r--app/backends/common.py7
-rw-r--r--app/backends/servers.py4
-rw-r--r--app/converter/converter.py6
-rw-r--r--app/logging_kit.py131
-rw-r--r--app/tests/test_hub.py7
-rw-r--r--app/tests/test_logging_kit.py118
-rw-r--r--app/tests/test_runview.py65
-rw-r--r--app/tests/test_taskview.py140
-rw-r--r--app/ui/hub.py54
-rw-r--r--app/ui/runview.py51
-rw-r--r--app/ui/taskview.py124
12 files changed, 631 insertions, 88 deletions
diff --git a/app/backends/audiocpp/build.py b/app/backends/audiocpp/build.py
index 9ffe429..1ad6018 100644
--- a/app/backends/audiocpp/build.py
+++ b/app/backends/audiocpp/build.py
@@ -6,10 +6,11 @@ import os
import re
import shlex
import shutil
-from datetime import datetime
from pathlib import Path
from typing import List, Optional
+import logging_kit
+
from backends import common, servers
from backends.common import APP_DIR
from .catalog import _BACKEND_TOKEN_RE, detect_backend, load_server_config
@@ -490,14 +491,11 @@ def _build_audiocpp_tui(emit, cancel, argv: List[str], command: str,
cancelled build (CANCEL set) is not reported as a failure, but its
partial output stays in the log file.
"""
- log_path = common.LOG_DIR / (
- f"audiocpp_build_{datetime.now():%Y%m%d_%H%M%S}.log")
- log_path.parent.mkdir(parents=True, exist_ok=True)
- log_handle = log_path.open("w", encoding="utf-8")
+ log_path, log_handle = logging_kit.run_artifact("audiocpp_build",
+ log_dir=common.LOG_DIR)
def tee(line: str) -> None:
- log_handle.write(line + "\n")
- log_handle.flush()
+ logging_kit.write_line(log_handle, line)
emit(line)
class _TeeWriter(io.TextIOBase):
diff --git a/app/backends/common.py b/app/backends/common.py
index 4c768b8..d25a03e 100644
--- a/app/backends/common.py
+++ b/app/backends/common.py
@@ -17,6 +17,8 @@ import urllib.parse
from pathlib import Path
from typing import Dict, List, Optional, Set, Tuple
+import logging_kit
+
# Messages queued while the TUI is on screen, printed to the real console
# after the curses session ends (see ui.hub.run). Build/setup steps that
# fail inside the TUI record here so the user gets a copy-pastable command
@@ -32,8 +34,9 @@ TTS_ROOT = Path(__file__).resolve().parent.parent.parent
# The single "everything else" directory under TTS_ROOT.
APP_DIR = TTS_ROOT / "app"
-# app/logs — build/server/conversion logs (already gitignored).
-LOG_DIR = APP_DIR / "logs"
+# app/logs — build/server/conversion logs (already gitignored). Naming and
+# retention policy lives in logging_kit (streams vs. timestamped artifacts).
+LOG_DIR = logging_kit.LOG_DIR
# The project's sample-voice directory: .wav files dropped here are offered
# as the default source when a setup/configure wizard asks for a wav
diff --git a/app/backends/servers.py b/app/backends/servers.py
index 986d82a..c258398 100644
--- a/app/backends/servers.py
+++ b/app/backends/servers.py
@@ -32,9 +32,7 @@ from pathlib import Path
from typing import Callable, List, Optional
from backends import common, probe
-from backends.common import APP_DIR
-
-LOG_DIR = APP_DIR / "logs"
+from backends.common import LOG_DIR
# How long to wait for a server to accept connections on its URL. First-time
# model loads (especially qwen-tts / faster-qwen3-tts pulling weights into
diff --git a/app/converter/converter.py b/app/converter/converter.py
index e1649c2..405073a 100644
--- a/app/converter/converter.py
+++ b/app/converter/converter.py
@@ -13,6 +13,8 @@ from datetime import datetime
from pathlib import Path
from typing import Callable, Dict, List, Optional, Tuple
+import logging_kit
+
from . import audio, chunking, config, cover, extractors
from .audio import TrackMeta
from .clients import (
@@ -57,7 +59,9 @@ def resolve_dir(value, default: str) -> Path:
BOOKS_FOLDER = resolve_dir(config.INPUT_DIR, "input")
AUDIOBOOKS_FOLDER = resolve_dir(config.OUTPUT_DIR, "output")
CHUNKS_FOLDER = APP_DIR / "chunks" # Per-chunk scratch audio, cleaned per book
-LOGS_FOLDER = APP_DIR / "logs"
+# The converter's log stream (audiobook_YYYYMMDD.log); naming/retention
+# policy lives in logging_kit.
+LOGS_FOLDER = logging_kit.LOG_DIR
DEBUG_FOLDER = APP_DIR / "debug" # --debug dumps, kept across runs
# Output containers and supported input formats.
diff --git a/app/logging_kit.py b/app/logging_kit.py
new file mode 100644
index 0000000..c16b7ed
--- /dev/null
+++ b/app/logging_kit.py
@@ -0,0 +1,131 @@
+"""Ownership of app/logs: naming, handles, and retention.
+
+Every log file this app writes follows one of two conventions, and all of
+them are created through this module so the policy lives in one place:
+
+ * Streams — continuous app activity, appended to across runs:
+ ``<prefix>_YYYYMMDD.log`` (e.g. audiobook_20260828.log, tui_20260828.log)
+ * Artifacts — one discrete operation, kept as its own file and referenced
+ by path afterwards (failure flashes, post-TUI notices):
+ ``<name>_YYYYmmdd_HHMMSS.log`` (e.g. audiocpp_build_..., audiocpp_start_...)
+
+The one exception is ``<name>-server.log``: managed-server processes
+(backends.servers) spawn with their stdout/stderr attached to that file and
+outlive this app's runs, so it stays a per-process append file — and
+prune_logs never deletes it.
+
+Everything here is stdlib-only and best-effort: logging must never break
+the app, so an unwritable directory or a failed write degrades to a no-op.
+"""
+
+import time
+from datetime import datetime
+from pathlib import Path
+
+# The single log directory (app/logs, already gitignored).
+LOG_DIR = Path(__file__).resolve().parent / "logs"
+
+# Stream/artifact files older than this are deleted by prune_logs (called
+# once per app start). Server logs and pid files are never touched.
+RETENTION_DAYS = 30
+
+
+def day_stream(prefix: str, log_dir: Path = None):
+ """Open today's ``<prefix>_YYYYMMDD.log`` stream for appending.
+
+ Returns the open text handle (write through write_line so lines are
+ flushed), or None when the directory/file cannot be opened.
+ """
+ directory = log_dir if log_dir is not None else LOG_DIR
+ try:
+ directory.mkdir(parents=True, exist_ok=True)
+ return (directory / f"{prefix}_{datetime.now():%Y%m%d}.log"
+ ).open("a", encoding="utf-8")
+ except OSError:
+ return None
+
+
+def run_artifact(name: str, log_dir: Path = None):
+ """Create ``<name>_YYYYmmdd_HHMMSS.log``; return ``(path, handle)``.
+
+ The path is always returned so callers can point the user at it even
+ when HANDLE is None (the directory/file could not be created).
+ """
+ directory = log_dir if log_dir is not None else LOG_DIR
+ path = directory / f"{name}_{datetime.now():%Y%m%d_%H%M%S}.log"
+ try:
+ directory.mkdir(parents=True, exist_ok=True)
+ return path, path.open("w", encoding="utf-8")
+ except OSError:
+ return path, None
+
+
+def write_line(handle, text: str) -> None:
+ """Append one line to HANDLE (None-safe), flushed; never raises."""
+ if handle is None:
+ return
+ try:
+ handle.write(f"{text}\n")
+ handle.flush()
+ except (OSError, ValueError):
+ pass
+
+
+class TeeWriter:
+ """A file-like that mirrors writes to a log file and an inner stream.
+
+ Used with ``contextlib.redirect_stdout`` to tee plain-console output
+ into a persistent log without losing the original consumer (e.g. the
+ task view's line writer). Either side may be None, and write errors
+ are swallowed, so logging never breaks the caller.
+ """
+
+ def __init__(self, logf=None, inner=None):
+ self._logf = logf
+ self._inner = inner
+
+ def write(self, text) -> int:
+ if not text:
+ return 0
+ for stream in (self._logf, self._inner):
+ if stream is not None:
+ try:
+ stream.write(text)
+ except (OSError, ValueError):
+ pass
+ return len(text)
+
+ def flush(self) -> None:
+ for stream in (self._logf, self._inner):
+ if stream is not None:
+ try:
+ stream.flush()
+ except (OSError, ValueError, AttributeError):
+ pass
+
+ def isatty(self) -> bool:
+ return False
+
+
+def prune_logs(days: int = RETENTION_DAYS, log_dir: Path = None) -> None:
+ """Delete stream/artifact log files older than DAYS (by mtime).
+
+ ``<name>-server.log`` files are skipped — a managed server may still
+ hold its log open, and its lifetime is not tied to this app's runs.
+ Non-log files (pid files, anything else) are never touched.
+ """
+ directory = log_dir if log_dir is not None else LOG_DIR
+ try:
+ entries = list(directory.iterdir())
+ except OSError:
+ return
+ cutoff = time.time() - days * 86400
+ for entry in entries:
+ if not entry.name.endswith(".log") \
+ or entry.name.endswith("-server.log"):
+ continue
+ try:
+ if entry.stat().st_mtime < cutoff:
+ entry.unlink()
+ except OSError:
+ pass
diff --git a/app/tests/test_hub.py b/app/tests/test_hub.py
index f0af74c..0bdf2d5 100644
--- a/app/tests/test_hub.py
+++ b/app/tests/test_hub.py
@@ -2535,10 +2535,11 @@ class SettingsTests(unittest.TestCase):
# The ports section note hangs off the first port field, the remote
# section note off the first remote URL field.
notes = {f["key"]: f.get("note") for f in captured["fields"]}
- self.assertTrue(notes["input_dir"])
- self.assertTrue(notes["output_dir"])
- self.assertTrue(notes["debug"])
+ self.assertIsNone(notes["input_dir"])
+ self.assertIsNone(notes["output_dir"])
+ self.assertIsNone(notes["debug"])
self.assertTrue(notes["stop_and_exit"])
+ self.assertTrue(notes["unload_models"])
self.assertTrue(notes["audiocpp_port"])
self.assertTrue(notes["audiocpp_remote_url"])
self.assertIsNone(notes["audio_format"])
diff --git a/app/tests/test_logging_kit.py b/app/tests/test_logging_kit.py
new file mode 100644
index 0000000..1945e5e
--- /dev/null
+++ b/app/tests/test_logging_kit.py
@@ -0,0 +1,118 @@
+"""Tests for app/logging_kit.py — log naming, teeing, and retention."""
+
+import io
+import os
+import tempfile
+import time
+import unittest
+from pathlib import Path
+
+import logging_kit
+
+
+class _TempDir(unittest.TestCase):
+ def setUp(self):
+ self.tmp = tempfile.TemporaryDirectory()
+ self.addCleanup(self.tmp.cleanup)
+ self.dir = Path(self.tmp.name)
+
+
+class DayStreamTests(_TempDir):
+ def test_creates_dated_stream_and_appends(self):
+ handle = logging_kit.day_stream("tui", log_dir=self.dir)
+ self.assertIsNotNone(handle)
+ logging_kit.write_line(handle, "first")
+ logging_kit.write_line(handle, "second")
+ handle.close()
+ files = list(self.dir.glob("tui_*.log"))
+ self.assertEqual(len(files), 1)
+ self.assertRegex(files[0].name, r"^tui_\d{8}\.log$")
+ self.assertEqual(files[0].read_text(encoding="utf-8"),
+ "first\nsecond\n")
+
+ def test_unwritable_dir_returns_none(self):
+ blocker = self.dir / "file" # a file where the directory would be
+ blocker.write_text("x", encoding="utf-8")
+ self.assertIsNone(
+ logging_kit.day_stream("tui", log_dir=blocker))
+
+
+class RunArtifactTests(_TempDir):
+ def test_creates_timestamped_artifact(self):
+ path, handle = logging_kit.run_artifact("audiocpp_build",
+ log_dir=self.dir)
+ self.assertIsNotNone(handle)
+ self.assertRegex(path.name, r"^audiocpp_build_\d{8}_\d{6}\.log$")
+ logging_kit.write_line(handle, "out")
+ handle.close()
+ self.assertEqual(path.read_text(encoding="utf-8"), "out\n")
+
+ def test_returns_path_even_when_unwritable(self):
+ blocker = self.dir / "file"
+ blocker.write_text("x", encoding="utf-8")
+ path, handle = logging_kit.run_artifact("x", log_dir=blocker)
+ self.assertIsNone(handle)
+ self.assertEqual(path.parent, blocker)
+
+
+class WriteLineTests(unittest.TestCase):
+ def test_none_handle_is_a_noop(self):
+ logging_kit.write_line(None, "x") # must not raise
+
+ def test_broken_handle_is_swallowed(self):
+ class Broken:
+ def write(self, _):
+ raise OSError("nope")
+
+ def flush(self):
+ raise OSError("nope")
+
+ logging_kit.write_line(Broken(), "x") # must not raise
+
+
+class TeeWriterTests(unittest.TestCase):
+ def test_mirrors_to_both_sides(self):
+ logf, inner = io.StringIO(), io.StringIO()
+ writer = logging_kit.TeeWriter(logf, inner)
+ self.assertEqual(writer.write("hello"), 5)
+ writer.flush()
+ self.assertEqual(logf.getvalue(), "hello")
+ self.assertEqual(inner.getvalue(), "hello")
+
+ def test_empty_write_returns_zero(self):
+ self.assertEqual(logging_kit.TeeWriter(io.StringIO()).write(""), 0)
+
+ def test_none_sides_and_errors_are_swallowed(self):
+ writer = logging_kit.TeeWriter(None, None)
+ self.assertEqual(writer.write("x"), 1) # must not raise
+ writer.flush()
+ self.assertFalse(writer.isatty())
+
+
+class PruneTests(_TempDir):
+ def test_deletes_old_logs_keeps_new_server_logs_and_pid_files(self):
+ old = self.dir / "tui_20200101.log"
+ old.write_text("x", encoding="utf-8")
+ new = self.dir / "audiobook_20990101.log"
+ new.write_text("x", encoding="utf-8")
+ server = self.dir / "audiocpp-server.log"
+ server.write_text("x", encoding="utf-8")
+ pid = self.dir / "audiocpp-server.pid"
+ pid.write_text("1", encoding="utf-8")
+ ancient = time.time() - 100 * 86400
+ os.utime(old, (ancient, ancient))
+ os.utime(server, (ancient, ancient))
+
+ logging_kit.prune_logs(log_dir=self.dir)
+
+ self.assertFalse(old.exists())
+ self.assertTrue(new.exists())
+ self.assertTrue(server.exists()) # owned by a server process
+ self.assertTrue(pid.exists()) # not a log
+
+ def test_missing_dir_is_a_noop(self):
+ logging_kit.prune_logs(log_dir=self.dir / "nope") # must not raise
+
+
+if __name__ == "__main__":
+ unittest.main()
diff --git a/app/tests/test_runview.py b/app/tests/test_runview.py
index f2d5180..8feeee1 100644
--- a/app/tests/test_runview.py
+++ b/app/tests/test_runview.py
@@ -10,6 +10,7 @@ cancel → stop-server flow.
import os
import sys
import tempfile
+import types
import unittest
from queue import Empty
from unittest.mock import patch
@@ -129,6 +130,70 @@ class StateTransitionTests(_FakeTui, unittest.TestCase):
self.assertEqual(view.server, "stopped")
+class LogAppenderTests(_FakeTui, unittest.TestCase):
+ """_LogAppender: stray console output survives in the run's log file."""
+
+ def _appender(self):
+ tmp = tempfile.TemporaryDirectory()
+ self.addCleanup(tmp.cleanup)
+ path = os.path.join(tmp.name, "audiobook_20260828.log")
+ return path, runview._LogAppender(path)
+
+ def test_write_splits_lines_into_the_file(self):
+ path, appender = self._appender()
+ appender.write("one\ntwo\n")
+ appender.write("three")
+ appender.flush()
+ with open(path, encoding="utf-8") as handle:
+ lines = handle.read().splitlines()
+ self.assertEqual(len(lines), 3)
+ self.assertTrue(lines[0].endswith(" - one"))
+ self.assertTrue(lines[2].endswith(" - three"))
+
+ def test_blank_lines_and_empty_path_are_skipped(self):
+ path, appender = self._appender()
+ appender.write("\n\n")
+ appender.flush()
+ appender.write("x")
+ appender.flush()
+ empty = runview._LogAppender("")
+ empty.write("ignored\n") # must not raise
+ with open(path, encoding="utf-8") as handle:
+ self.assertEqual(len(handle.read().splitlines()), 1)
+
+ def test_unwritable_path_never_raises(self):
+ appender = runview._LogAppender("/nonexistent-dir-zz/log.log")
+ appender.write("boom\n") # must not raise
+ appender.flush()
+
+ def test_worker_stdout_is_mirrored_to_the_run_log(self):
+ tmp = tempfile.TemporaryDirectory()
+ self.addCleanup(tmp.cleanup)
+ log_path = os.path.join(tmp.name, "audiobook_20260828.log")
+ view, _ = self.make_view(log_path=log_path)
+
+ fake = types.ModuleType("audiobook")
+
+ def convert(**_kwargs):
+ print("[INFO] stray console output")
+
+ fake.convert = convert
+ with patch.dict(sys.modules, {"audiobook": fake}):
+ view._worker_main()
+
+ with open(log_path, encoding="utf-8") as handle:
+ text = handle.read()
+ self.assertIn("[INFO] stray console output", text)
+ # The worker signed off normally through the event queue.
+ kinds = []
+ while True:
+ try:
+ kinds.append(view._queue.get_nowait()["kind"])
+ except Empty:
+ break
+ self.assertEqual(kinds, ["worker_exit"])
+
+
class RenderTests(_FakeTui, unittest.TestCase):
def _strings(self, screen):
return " ".join(text for _, _, text, _ in screen.strings)
diff --git a/app/tests/test_taskview.py b/app/tests/test_taskview.py
index 646fccb..1db708d 100644
--- a/app/tests/test_taskview.py
+++ b/app/tests/test_taskview.py
@@ -9,8 +9,10 @@ transitions through ``handle_event`` + ``_step_mark`` + ``_result_rc``.
import io
import sys
+import tempfile
import threading
import unittest
+from pathlib import Path
from queue import Empty
from unittest.mock import patch
@@ -30,6 +32,12 @@ class _FakeTui:
patcher = patch.dict(sys.modules, {"curses": self.curses})
patcher.start()
self.addCleanup(patcher.stop)
+ # Console mirroring is disabled by default so tests stay hermetic;
+ # the console-log tests patch day_stream with a real temp file.
+ log_patcher = patch.object(taskview.logging_kit, "day_stream",
+ return_value=None)
+ log_patcher.start()
+ self.addCleanup(log_patcher.stop)
taskview.tui._THEME.clear()
self.addCleanup(taskview.tui._THEME.clear)
@@ -41,6 +49,18 @@ class _FakeTui:
return view, screen
+class _TempLog:
+ """A temp target for the tui_ day stream (patched over day_stream)."""
+
+ def _log_target(self):
+ tmp = tempfile.TemporaryDirectory()
+ self.addCleanup(tmp.cleanup)
+ path = Path(tmp.name) / "tui_20260828.log"
+ handle = path.open("w", encoding="utf-8")
+ self.addCleanup(handle.close)
+ return path, handle
+
+
class RunStepsInlineTests(unittest.TestCase):
def test_runs_steps_in_order_and_returns_zero(self):
order = []
@@ -128,10 +148,100 @@ class ProgressParsingTests(_FakeTui, unittest.TestCase):
def test_log_tail_is_capped(self):
view, _ = self.make_view(steps=[_step("a")])
- for i in range(taskview._LOG_TAIL + 5):
+ for i in range(taskview._LOG_KEEP + 5):
view._ingest_line(f"line {i}")
- self.assertEqual(len(view.log_tail), taskview._LOG_TAIL)
- self.assertEqual(view.log_tail[-1], f"line {taskview._LOG_TAIL + 4}")
+ self.assertEqual(len(view.log_tail), taskview._LOG_KEEP)
+ self.assertEqual(view.log_tail[-1], f"line {taskview._LOG_KEEP + 4}")
+
+
+class ConsoleLogTests(_TempLog, _FakeTui, unittest.TestCase):
+ """The tui_ day-stream mirror: header, lines, markers, exclusions."""
+
+ def test_run_header_lines_and_step_markers_are_written(self):
+ path, handle = self._log_target()
+ with patch.object(taskview.logging_kit, "day_stream",
+ return_value=handle):
+ view, _ = self.make_view(steps=[_step("one")])
+ view.handle_event({"kind": "step_start", "index": 0,
+ "title": "one"})
+ view._ingest_line("cloning into 'audio.cpp'...")
+ view.handle_event({"kind": "step_done", "index": 0, "rc": 0})
+ view.handle_event({"kind": "finish", "phase": "done", "rc": 0})
+ view._on_stop()
+ text = path.read_text(encoding="utf-8")
+ self.assertIn("=== Setup —", text)
+ self.assertIn("--- one ---", text)
+ self.assertIn("cloning into 'audio.cpp'...", text)
+ self.assertIn("[OK] one (exit 0)", text)
+ self.assertIn("=== done (exit 0) ===", text)
+
+ def test_machine_progress_lines_are_not_logged(self):
+ path, handle = self._log_target()
+ with patch.object(taskview.logging_kit, "day_stream",
+ return_value=handle):
+ view, _ = self.make_view(steps=[_step("a")])
+ view._ingest_line("AUDIOCPP_PROGRESS downloaded=1 total=2")
+ view._ingest_line("[ 45%] building")
+ view._on_stop()
+ text = path.read_text(encoding="utf-8")
+ self.assertNotIn("AUDIOCPP_PROGRESS", text)
+ self.assertIn("[ 45%] building", text)
+
+ def test_failed_step_is_marked_in_the_log(self):
+ path, handle = self._log_target()
+ with patch.object(taskview.logging_kit, "day_stream",
+ return_value=handle):
+ view, _ = self.make_view(steps=[_step("one")])
+ view.handle_event({"kind": "step_start", "index": 0,
+ "title": "one"})
+ view.handle_event({"kind": "step_done", "index": 0, "rc": 7})
+ view._on_stop()
+ text = path.read_text(encoding="utf-8")
+ self.assertIn("[FAIL] one (exit 7)", text)
+
+ def test_cancelled_step_is_marked_in_the_log(self):
+ path, handle = self._log_target()
+ with patch.object(taskview.logging_kit, "day_stream",
+ return_value=handle):
+ view, _ = self.make_view(steps=[_step("one")])
+ view.handle_event({"kind": "step_start", "index": 0,
+ "title": "one"})
+ view.handle_event({"kind": "step_cancelled", "index": 0})
+ view.handle_event({"kind": "finish", "phase": "cancelled",
+ "rc": 1})
+ view._on_stop()
+ text = path.read_text(encoding="utf-8")
+ self.assertIn("[x] one (cancelled)", text)
+ self.assertIn("=== cancelled (exit 1) ===", text)
+
+ def test_unwritable_log_disables_the_mirror(self):
+ with patch.object(taskview.logging_kit, "day_stream",
+ return_value=None):
+ view, _ = self.make_view(steps=[_step("a")])
+ view._ingest_line("hello") # must not raise
+ view._on_stop()
+ self.assertEqual(view.log_tail, ["hello"])
+
+ def test_lane_output_is_mirrored_with_lane_markers(self):
+ path, handle = self._log_target()
+ with patch.object(taskview.logging_kit, "day_stream",
+ return_value=handle):
+ screen = FakeScreen(width=80, height=24)
+ view = taskview.LanesView(
+ screen, "Setup",
+ [taskview.TaskLane("Build", [_step("one")])],
+ clock=lambda: 1000.0)
+ lane = view._lanes[0]
+ view._handle_lane_event(lane, {"kind": "step_start",
+ "index": 0, "title": "one"})
+ view._ingest_lane_line(lane, "compiling foo.o")
+ view._handle_lane_event(lane, {"kind": "lane_finish", "rc": 0})
+ view._console_log.close()
+ text = path.read_text(encoding="utf-8")
+ self.assertIn("=== Setup —", text)
+ self.assertIn("--- [Build] one ---", text)
+ self.assertIn("compiling foo.o", text)
+ self.assertIn("=== [Build] finished (exit 0) ===", text)
class StateTransitionTests(_FakeTui, unittest.TestCase):
@@ -193,6 +303,30 @@ class RenderTests(_FakeTui, unittest.TestCase):
self.assertIn("two", text)
self.assertIn("Esc or q: cancel", text)
+ def test_log_tail_fills_the_available_height(self):
+ # A tall terminal shows all 20 lines (the old 10-line cap would
+ # have left the bottom blank).
+ view, screen = self.make_view(steps=[_step("one")], height=30)
+ for i in range(20):
+ view._ingest_line(f"line {i}")
+ view.render()
+ shown = [t for _, _, t, _ in screen.strings if t.startswith("line ")]
+ self.assertEqual(len(shown), 20)
+ self.assertEqual(shown[0], "line 0")
+ self.assertEqual(shown[-1], "line 19")
+
+ def test_log_tail_shows_the_most_recent_lines_that_fit(self):
+ # The tail is anchored to the latest output: on a small screen the
+ # earliest lines scroll off while the newest stay visible.
+ view, screen = self.make_view(steps=[_step("one")], height=24)
+ for i in range(20):
+ view._ingest_line(f"line {i}")
+ view.render()
+ shown = [t for _, _, t, _ in screen.strings if t.startswith("line ")]
+ self.assertGreater(len(shown), 10) # more than the old fixed cap
+ self.assertEqual(shown[-1], "line 19")
+ self.assertNotIn("line 0", shown)
+
def test_done_screen_shows_the_completion_footer(self):
view, screen = self.make_view(steps=[_step("one")])
view.handle_event({"kind": "step_start", "index": 0, "title": "one"})
diff --git a/app/ui/hub.py b/app/ui/hub.py
index a5c3dc4..e17e862 100644
--- a/app/ui/hub.py
+++ b/app/ui/hub.py
@@ -30,6 +30,8 @@ from datetime import datetime
from pathlib import Path
from typing import Callable, Optional, Tuple
+import logging_kit
+
from backends import (
REGISTRY,
BackendStatus,
@@ -561,60 +563,24 @@ class _Hub:
return tui.Wizard.BACK
-class _TeeWriter:
- """A file-like that mirrors writes to a log file and an inner stream.
-
- Used to capture the server module's plain-console output (the task view
- already redirects stdout to its line-writer) into a persistent log file
- under ``servers.LOG_DIR`` without losing the on-screen log tail.
- """
-
- def __init__(self, logf, inner):
- self._logf = logf
- self._inner = inner
-
- def write(self, text):
- if not text:
- return 0
- try:
- self._logf.write(text)
- except OSError:
- pass
- try:
- self._inner.write(text)
- except OSError:
- pass
- return len(text)
-
- def flush(self):
- try:
- self._logf.flush()
- except OSError:
- pass
- try:
- self._inner.flush()
- except OSError:
- pass
-
-
def _server_action_step(spec, action: str):
"""Build a task step that starts/stops SPEC's server, logged to a file.
ACTION is "start" or "stop". The step runs inside the task view (no
- console drop): the server module's output is tee'd to
- ``<servers.LOG_DIR>/<name>-<action>.log`` and to the view's log tail.
- Returns ``(TaskStep, log_path)`` so the caller can point the user at the
- file on failure.
+ console drop): the server module's output is tee'd to a timestamped
+ ``<name>_<action>_*.log`` artifact under ``servers.LOG_DIR`` (see
+ ``logging_kit.run_artifact``) and to the view's log tail. Returns
+ ``(TaskStep, log_path)`` so the caller can point the user at the file
+ on failure.
"""
- log_path = servers.LOG_DIR / f"{spec.name}-{action}.log"
title = (f"Start {spec.name} server" if action == "start"
else f"Stop {spec.name} server")
+ log_path, logf = logging_kit.run_artifact(f"{spec.name}_{action}",
+ log_dir=servers.LOG_DIR)
def work(emit, cancel):
- servers.LOG_DIR.mkdir(parents=True, exist_ok=True)
inner = sys.stdout # the task view's line-writer, when run in TUI
- with log_path.open("w", encoding="utf-8") as logf, \
- contextlib.redirect_stdout(_TeeWriter(logf, inner)):
+ with contextlib.redirect_stdout(logging_kit.TeeWriter(logf, inner)):
if action == "start":
ok = servers.start(spec, cancel=cancel)
else:
diff --git a/app/ui/runview.py b/app/ui/runview.py
index 9448c06..b3a1ab0 100644
--- a/app/ui/runview.py
+++ b/app/ui/runview.py
@@ -29,7 +29,6 @@ so the failure is never scrolled away.
"""
import contextlib
-import io
import threading
import time
from dataclasses import dataclass
@@ -59,6 +58,51 @@ _SERVER_STATES = {
_MONITOR_INTERVAL = 2.0
+class _LogAppender:
+ """A file-like that appends redirected console output to the run's log.
+
+ The run view owns the screen, so anything a conversion prints to
+ stdout/stderr outside the progress events would otherwise be swallowed
+ silently; this mirrors it line by line into the run's dated log file
+ (RunConfig.log_path, the audiobook_ day stream), prefixed with the same
+ timestamp format the converter's log records use. Best-effort: write
+ errors are swallowed, and an empty path disables logging.
+ """
+
+ def __init__(self, path: str):
+ self._path = path
+ self._buffer = ""
+
+ def write(self, text: str) -> int:
+ if not text:
+ return 0
+ self._buffer += text
+ while True:
+ cut = self._buffer.find("\n")
+ if cut < 0:
+ break
+ line, self._buffer = self._buffer[:cut], self._buffer[cut + 1:]
+ self._append(line)
+ return len(text)
+
+ def flush(self) -> None:
+ if self._buffer:
+ self._append(self._buffer)
+ self._buffer = ""
+
+ def isatty(self) -> bool:
+ return False
+
+ def _append(self, line: str) -> None:
+ if not self._path or not line.strip():
+ return
+ try:
+ with open(self._path, "a", encoding="utf-8") as logf:
+ logf.write(f"{datetime.now():%Y-%m-%d %H:%M:%S} - {line}\n")
+ except OSError:
+ pass
+
+
@dataclass
class RunConfig:
"""Everything the run view needs to execute one conversion.
@@ -232,7 +276,7 @@ class RunView(ScreenView):
import audiobook
config = self.config
try:
- with contextlib.redirect_stdout(io.StringIO()):
+ with contextlib.redirect_stdout(_LogAppender(config.log_path)):
if config.autostart_spec is not None:
if config.restart_first:
# The managed qwen server hosts another model than
@@ -401,7 +445,8 @@ class RunView(ScreenView):
def _stop() -> None:
try:
- with contextlib.redirect_stdout(io.StringIO()):
+ with contextlib.redirect_stdout(
+ _LogAppender(self.config.log_path)):
servers.stop(name)
finally:
self._queue.put({"kind": "server_stopped"})
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"])