diff options
Diffstat (limited to 'app')
| -rw-r--r-- | app/backends/envs.py | 1 | ||||
| -rw-r--r-- | app/converter/audio.py | 7 | ||||
| -rw-r--r-- | app/converter/config.py | 2 | ||||
| -rw-r--r-- | app/converter/converter.py | 11 | ||||
| -rw-r--r-- | app/logging_kit.py | 20 | ||||
| -rw-r--r-- | app/tests/test_audiobook_cli.py | 91 | ||||
| -rw-r--r-- | app/tests/test_converter.py | 29 |
7 files changed, 151 insertions, 10 deletions
diff --git a/app/backends/envs.py b/app/backends/envs.py index 494c3e2..beef23b 100644 --- a/app/backends/envs.py +++ b/app/backends/envs.py @@ -633,5 +633,4 @@ def bootstrap(script_path: str) -> None: sys.exit(1) py = str(env_python()) target = str(Path(script_path).resolve()) - print(f"[INFO] re-launching inside managed environment: {py}") os.execv(py, [py, target, *sys.argv[1:]]) diff --git a/app/converter/audio.py b/app/converter/audio.py index def4395..58cd5a5 100644 --- a/app/converter/audio.py +++ b/app/converter/audio.py @@ -9,11 +9,12 @@ import logging import re import shutil import subprocess -import traceback import wave from pathlib import Path from typing import Dict, List, NamedTuple, Optional, Tuple +import logging_kit + from . import config logger = logging.getLogger(__name__) @@ -459,7 +460,7 @@ def combine_chunks(total_chunks: int, output_path: Path, return False except Exception as exc: logger.error("Failed to combine chunks: %s", exc) - logger.error(traceback.format_exc()) + logging_kit.log_traceback() return False finally: try: @@ -618,7 +619,7 @@ def combine_chapters_to_m4b(chapter_files: List[Path], titles: List[str], return False except Exception as exc: logger.error("Failed to combine chapters: %s", exc) - logger.error(traceback.format_exc()) + logging_kit.log_traceback() return False finally: for scratch in (concat_list, metadata_file, speed_metadata_file): diff --git a/app/converter/config.py b/app/converter/config.py index d0028dc..e37269b 100644 --- a/app/converter/config.py +++ b/app/converter/config.py @@ -90,7 +90,7 @@ FASTER_VOICE = "narrator" ############################################################################### # BACKEND 3: audio.cpp options # ############################################################################### -AUDIOCPP_API_URL = "http://127.0.0.1:8080" # audio.cpp audiocpp_server +AUDIOCPP_API_URL = "http://127.0.0.1:8082" # audio.cpp audiocpp_server AUDIOCPP_REMOTE_URL = "http://127.0.0.1:8080" # externally-run audiocpp_server ("" disables probing) # Model ids in the audio.cpp server.json config. AUDIOCPP_MODEL_ID may point diff --git a/app/converter/converter.py b/app/converter/converter.py index 405073a..5235991 100644 --- a/app/converter/converter.py +++ b/app/converter/converter.py @@ -7,7 +7,6 @@ import shutil import sys import threading import time -import traceback from collections import Counter from datetime import datetime from pathlib import Path @@ -70,8 +69,10 @@ SUPPORTED_FORMATS = [".txt", ".pdf", ".epub"] def _console_log_filter(record: logging.LogRecord) -> bool: - """Keep httpx/httpcore request logs out of the console (file only).""" - return not record.name.startswith(("httpx", "httpcore")) + """Keep httpx/httpcore request logs and file-only traceback dumps out + of the console (file only).""" + return not record.name.startswith( + ("httpx", "httpcore", logging_kit.TRACEBACK_LOGGER)) def setup_logging(debug: bool = False, console: bool = True) -> None: @@ -511,7 +512,7 @@ class AudiobookConverter: raise except Exception as exc: logger.error("Conversion failed: %s", exc) - logger.error(traceback.format_exc()) + logging_kit.log_traceback() return False finally: # Always cleanup, even on failure or interrupt @@ -722,7 +723,7 @@ class AudiobookConverter: raise except Exception as exc: logger.error("Conversion failed: %s", exc) - logger.error(traceback.format_exc()) + logging_kit.log_traceback() return False def _print_banner(self) -> None: diff --git a/app/logging_kit.py b/app/logging_kit.py index c16b7ed..0fe39c2 100644 --- a/app/logging_kit.py +++ b/app/logging_kit.py @@ -18,13 +18,33 @@ 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 logging import time +import traceback from datetime import datetime from pathlib import Path # The single log directory (app/logs, already gitignored). LOG_DIR = Path(__file__).resolve().parent / "logs" +# Reserved logger for file-only traceback dumps: records emitted on this +# name reach the dated log file through the root handlers, while the +# converter's console filter (setup_logging's _console_log_filter) drops +# them, so a handled failure can keep its full traceback out of the +# console without losing it from the logs. +TRACEBACK_LOGGER = "app.traceback" + + +def log_traceback() -> None: + """Log the active exception's traceback to the log file only. + + Call from inside an ``except`` block: the record reaches the file + handler but not the console, where the caller shows a single friendly + message instead (tracebacks are for the logs, or for real crashes). + """ + logging.getLogger(TRACEBACK_LOGGER).error(traceback.format_exc()) + + # 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 diff --git a/app/tests/test_audiobook_cli.py b/app/tests/test_audiobook_cli.py index e4b558b..b06a715 100644 --- a/app/tests/test_audiobook_cli.py +++ b/app/tests/test_audiobook_cli.py @@ -11,6 +11,7 @@ temporary directories. import contextlib import io +import logging import shutil import sys import tempfile @@ -308,5 +309,95 @@ class PreflightOverrideTests(unittest.TestCase): self.assertEqual((book_files, planned), ([], [])) +class FatalErrorReportingTests(unittest.TestCase): + """convert() reports failures once; tracebacks stay in the log file. + + A RuntimeError/ValueError is an expected, user-facing failure (the + clients raise them with actionable hints): the console gets a single + [FATAL] line and the full traceback only lands in the dated log file. + Any other exception is an actual crash, so its traceback is shown too. + """ + + def setUp(self): + self.tmp = Path(tempfile.mkdtemp(prefix="audiobook_fatal_")) + self.addCleanup(shutil.rmtree, self.tmp, True) + self.book = _make_book(self.tmp) + self.log_dir = self.tmp / "logs" + # setup_logging opens the dated log file from this global. + patcher = patch.object(converter_mod, "LOGS_FOLDER", self.log_dir) + patcher.start() + self.addCleanup(patcher.stop) + self.addCleanup(self._reset_logging) + # convert() repoints the converter module's folder globals; restore + # them so other tests keep seeing the configured folders. + self._old_folders = (converter_mod.BOOKS_FOLDER, + converter_mod.AUDIOBOOKS_FOLDER) + self.addCleanup(self._restore_folders) + + def _reset_logging(self): + root = logging.getLogger() + for handler in list(root.handlers): + root.removeHandler(handler) + handler.close() + logging.getLogger("converter").setLevel(logging.INFO) + + def _restore_folders(self): + converter_mod.BOOKS_FOLDER, converter_mod.AUDIOBOOKS_FOLDER = \ + self._old_folders + + def _convert(self, exc, progress=None): + """Run convert() with the converter class raising EXC in __init__. + + Returns (exit code, stdout, stderr); setup_logging runs for real + with LOGS_FOLDER pointed at the temporary directory, so the dated + log file's contents can be asserted on. + """ + preflight = MagicMock( + return_value=([self.book], [(self.book, "dune")])) + fake_class = MagicMock(side_effect=exc) + fake_class.preflight_overwrites = preflight + out, err = io.StringIO(), io.StringIO() + with patch.object(audiobook, "setup_directories"), \ + contextlib.redirect_stdout(out), \ + contextlib.redirect_stderr(err), \ + patch.object(audiobook, "AudiobookConverter", fake_class): + code = audiobook.convert(backend="audiocpp", progress=progress) + return code, out.getvalue(), err.getvalue() + + def _log_text(self) -> str: + (log_path,) = self.log_dir.glob("audiobook_*.log") + return log_path.read_text(encoding="utf-8") + + def test_expected_failure_shows_one_friendly_line(self): + message = ("The audio.cpp model 'Qwen3-TTS-12Hz-1.7B-Base-GGUF' " + "(family 'qwen3_tts') has no built-in speakers " + "(see README).") + code, out, err = self._convert(RuntimeError(message)) + self.assertEqual(code, 1) + self.assertEqual(out.count("[FATAL]"), 1) + self.assertIn(f"[FATAL] Fatal error: {message}", out) + self.assertNotIn("Traceback (most recent call last)", out) + self.assertNotIn("Traceback (most recent call last)", err) + log_text = self._log_text() + self.assertIn("Traceback (most recent call last):", log_text) + self.assertIn(f"RuntimeError: {message}", log_text) + + def test_expected_failure_reports_error_event(self): + events = [] + code, _, _ = self._convert(ValueError("bad input"), + progress=events.append) + self.assertEqual(code, 1) + self.assertEqual(events, + [{"kind": "error", "message": "bad input"}]) + + def test_unexpected_crash_also_shows_traceback(self): + code, out, err = self._convert(TypeError("boom")) + self.assertEqual(code, 1) + self.assertEqual(out.count("[FATAL]"), 1) + self.assertIn("Traceback (most recent call last)", err) + self.assertIn("TypeError: boom", err) + self.assertIn("Traceback (most recent call last)", self._log_text()) + + if __name__ == "__main__": unittest.main() diff --git a/app/tests/test_converter.py b/app/tests/test_converter.py index e04d3fe..4d7a064 100644 --- a/app/tests/test_converter.py +++ b/app/tests/test_converter.py @@ -2,10 +2,12 @@ import io import logging +import logging_kit import tempfile import time import unittest from contextlib import redirect_stdout +from datetime import datetime from pathlib import Path from unittest.mock import MagicMock, patch @@ -391,6 +393,33 @@ class SetupLoggingTests(unittest.TestCase): "Chunk 1/1 request text", None, None) self.assertTrue(console.filter(chunk_record)) + def test_traceback_logger_filtered_from_console_only(self): + setup_logging(debug=True) + console = self._console_handler() + traceback_record = logging.LogRecord( + logging_kit.TRACEBACK_LOGGER, logging.ERROR, "app", 1, + "Traceback (most recent call last): ...", None, None) + self.assertFalse(console.filter(traceback_record)) + + def test_log_traceback_reaches_file_but_not_console(self): + setup_logging() + console = self._console_handler() + console_stream = io.StringIO() + original = console.setStream(console_stream) + try: + try: + raise RuntimeError("boom") + except RuntimeError: + logging_kit.log_traceback() + finally: + console.setStream(original) + self.assertNotIn("Traceback", console_stream.getvalue()) + self.assertNotIn("boom", console_stream.getvalue()) + log_text = (Path(self._tmp.name) / "audiobook_" + f"{datetime.now():%Y%m%d}.log").read_text(encoding="utf-8") + self.assertIn("Traceback (most recent call last):", log_text) + self.assertIn("RuntimeError: boom", log_text) + class SynthesizeChunkLoggingTests(unittest.TestCase): """Chunk failures surface as a single ERROR record (no print echo).""" |