fix: book generation logging

4 files changed, 106 insertions, 5 deletions

diff --git a/app/tests/test_hub.py b/app/tests/test_hub.py
index 3feaa05..3547ba8 100644
--- a/app/tests/test_hub.py
+++ b/app/tests/test_hub.py
@@ -1246,6 +1246,33 @@ class PrepareRunConfigTests(unittest.TestCase):
         self.assertEqual(cfg.server_url, spec.url)
         self.assertIsNone(cfg.autostart_spec)
 
+    def test_book_files_travel_on_the_config_not_the_kwargs(self):
+        # _preflight stashes the plan in the form kwargs; keeping it there
+        # collided with convert()'s named book_files/planned parameters.
+        spec = self._spec()
+        status = BackendStatus("qwen", "qwen-tts", installed=True,
+                               configured=True, servers=[spec])
+        kwargs = {"book_files": ["b.txt"], "planned": ["b.txt"]}
+        with tempfile.TemporaryDirectory() as tmp, \
+                patch.object(hub, "LOGS_FOLDER", Path(tmp)), \
+                patch.object(hub, "detect_all", return_value=[status]), \
+                patch("backends.common.server_running", return_value=False):
+            cfg = hub._prepare_run_config("qwen", kwargs)
+        self.assertNotIn("book_files", kwargs)
+        self.assertNotIn("planned", kwargs)
+        self.assertEqual(cfg.book_files, ["b.txt"])
+        self.assertEqual(cfg.planned, ["b.txt"])
+
+    def test_the_dated_log_file_exists_once_a_run_is_prepared(self):
+        # The run view advertises this file on failures; create it up front
+        # so a crash before setup_logging still points somewhere real.
+        with tempfile.TemporaryDirectory() as tmp:
+            with patch.object(hub, "LOGS_FOLDER", Path(tmp)), \
+                    patch.object(hub, "detect_all", return_value=[]):
+                cfg = hub._prepare_run_config(
+                    "audiocpp", {"api_url": "http://10.0.0.5:8080"})
+            self.assertTrue(Path(cfg.log_path).exists())
+
 
 class PreflightTests(unittest.TestCase):
     """_preflight: overwrite prompts run in the TUI, plan stashed in kwargs."""
diff --git a/app/tests/test_runview.py b/app/tests/test_runview.py
index 7006427..556cb52 100644
--- a/app/tests/test_runview.py
+++ b/app/tests/test_runview.py
@@ -7,8 +7,11 @@ own queue to exercise state transitions, rendering, and the Esc/q
 cancel → stop-server flow.
 """
 
+import os
 import sys
+import tempfile
 import unittest
+from queue import Empty
 from unittest.mock import patch
 
 from tests.test_tui import FakeCurses, FakeScreen
@@ -234,5 +237,51 @@ class RunLoopTests(_FakeTui, unittest.TestCase):
         mk_stop.assert_not_called()
 
 
+class WorkerTests(_FakeTui, unittest.TestCase):
+    """The worker thread's handoff into audiobook.convert."""
+
+    def make_view(self, **cfg):
+        screen = FakeScreen()
+        return runview.RunView(screen, _config(**cfg), clock=lambda: 1000.0)
+
+    def _drain(self, view):
+        events = []
+        while True:
+            try:
+                events.append(view._queue.get_nowait())
+            except Empty:
+                return events
+
+    def test_book_files_reach_convert_once(self):
+        # Regression: _preflight stashes book_files/planned in the form
+        # kwargs and RunConfig carries them as fields too; passing both to
+        # convert() raised "got multiple values for keyword argument".
+        view = self.make_view(
+            kwargs={"voice": "alloy", "book_files": ["b.txt"],
+                    "planned": ["b.txt"]},
+            book_files=["b.txt"], planned=["b.txt"])
+        with patch("audiobook.convert") as mk_convert:
+            view._worker_main()
+        _, kw = mk_convert.call_args
+        self.assertEqual(kw["book_files"], ["b.txt"])
+        self.assertEqual(kw["planned"], ["b.txt"])
+        self.assertEqual(kw["voice"], "alloy")
+        self.assertNotIn("error", [e["kind"] for e in self._drain(view)])
+
+    def test_worker_error_is_appended_to_the_dated_log(self):
+        # A crash before convert() configures logging must still leave its
+        # trace in the file the failure screen points at.
+        with tempfile.TemporaryDirectory() as tmp:
+            log_path = os.path.join(tmp, "audiobook_20260825.log")
+            view = self.make_view(log_path=log_path)
+            with patch("audiobook.convert",
+                       side_effect=TypeError("boom")):
+                view._worker_main()
+            with open(log_path, encoding="utf-8") as handle:
+                text = handle.read()
+        self.assertIn("ERROR - boom", text)
+        self.assertIn("error", [e["kind"] for e in self._drain(view)])
+
+
 if __name__ == "__main__":
     unittest.main()
diff --git a/app/ui/hub.py b/app/ui/hub.py
index c1f5dce..9282fa7 100644
--- a/app/ui/hub.py
+++ b/app/ui/hub.py
@@ -1405,15 +1405,24 @@ def _prepare_run_config(backend: str, kwargs: dict
     if info is not None:
         label = info.label
     log_path = str(LOGS_FOLDER / f"audiobook_{datetime.now():%Y%m%d}.log")
+    # The run view points failures at this file, so make sure it exists
+    # from the moment a run starts — even when the run dies before the
+    # converter's setup_logging creates it.
+    LOGS_FOLDER.mkdir(parents=True, exist_ok=True)
+    Path(log_path).touch()
     autostart = kwargs.pop("autostart", None)
+    # book_files/planned travel on the dedicated RunConfig fields; keeping
+    # them in kwargs too would collide with convert()'s named parameters.
+    book_files = kwargs.pop("book_files", None) or []
+    planned = kwargs.pop("planned", None) or []
     api_url = kwargs.get("api_url")
 
     if api_url:
         identity = _remote_identity(backend, kwargs)
         return runview.RunConfig(
             backend=backend, backend_label=f"{label} [remote]",
-            kwargs=kwargs, book_files=kwargs.get("book_files") or [],
-            planned=kwargs.get("planned") or [],
+            kwargs=kwargs, book_files=book_files,
+            planned=planned,
             server_url=api_url, server_identity=identity,
             log_path=log_path)
 
@@ -1434,8 +1443,7 @@ def _prepare_run_config(backend: str, kwargs: dict
         notice = (f"no server named '{autostart}' — starting it was skipped")
     return runview.RunConfig(
         backend=backend, backend_label=label, kwargs=kwargs,
-        book_files=kwargs.get("book_files") or [],
-        planned=kwargs.get("planned") or [],
+        book_files=book_files, planned=planned,
         server_name=spec.name if spec is not None else None,
         server_url=spec.url if spec is not None else None,
         server_identity=spec.identity if spec is not None else None,
diff --git a/app/ui/runview.py b/app/ui/runview.py
index d49d949..7ff7ab1 100644
--- a/app/ui/runview.py
+++ b/app/ui/runview.py
@@ -29,6 +29,7 @@ import io
 import threading
 import time
 from dataclasses import dataclass, field
+from datetime import datetime
 from queue import Empty, Queue
 from typing import Callable, List, Optional
 
@@ -245,14 +246,30 @@ class RunView:
                 if self._cancel.is_set():
                     self._queue.put({"kind": "cancelled"})
                     return
+                # book_files/planned travel on the config fields; dropping
+                # any stray duplicates from kwargs keeps convert()'s call
+                # binding unambiguous.
+                kwargs = {key: value for key, value in config.kwargs.items()
+                          if key not in ("book_files", "planned")}
                 audiobook.convert(backend=config.backend,
                                   progress=self._queue.put,
                                   cancel=self._cancel,
                                   book_files=config.book_files,
                                   planned=config.planned,
-                                  **config.kwargs)
+                                  **kwargs)
         except Exception as exc:  # noqa: BLE001 - reported to the view
             self._queue.put({"kind": "error", "message": f"{exc}"})
+            # The view points failures at the dated log; a crash that
+            # happens before the converter configures logging (e.g. bad
+            # arguments) must still leave its trace there.
+            if self.config.log_path:
+                try:
+                    with open(self.config.log_path, "a",
+                              encoding="utf-8") as logf:
+                        logf.write(f"{datetime.now():%Y-%m-%d %H:%M:%S} - "
+                                   f"ERROR - {exc}\n")
+                except (OSError, ValueError):
+                    pass
         finally:
             self._queue.put({"kind": "worker_exit"})