feat: show persistent conversion progress

This commit is contained in:
drockhollaback
2026-08-29 17:08:16 -04:00
parent 029cc8f841
commit c40b8ffe6a
8 changed files with 359 additions and 11 deletions
+5
View File
@@ -12,6 +12,9 @@ All notable changes to this project are documented in this file.
deterministic silence-only chapter candidates with detailed preview reasons.
- Bounded FFmpeg silence analysis across sorted multi-track input and a
deterministic container smoke fixture covering real detector integration.
- Persistent conversion progress for converting, chapter application,
validation, and final moves, with elapsed time, observable output size,
terminal status, and mirrored log records.
### Security
@@ -26,6 +29,8 @@ All notable changes to this project are documented in this file.
- Documented Discovery configuration, chapter thresholds, known limitations,
real-ASIN Enterprise-D acceptance, explicit approval, and absence of invented
percentage or ETA.
- Documented five-second progress cadence, cancellation behavior, persistent log
location, and filesystem-only observation of growing output.
## 0.1.0 - 2026-08-26
+25 -1
View File
@@ -149,7 +149,8 @@ conversion services, and checks the final duration and two chapter titles. A
second deterministic tone/silence/tone fixture runs through the real bounded
silence detector and must report its known midpoint. Temporary media is removed
on every normal, failed, or interrupted exit. The smoke test does not touch host
audiobook paths.
audiobook paths. It also requires active and inactive records for all four
progress phases and exact terminal-callback/log mirroring.
## Launch over SSH
@@ -331,6 +332,26 @@ does not approve or move source. For disposable backed-up book, approve one
conversion and verify output chapter count, titles, playback, and pending to
ready-plus-done transition.
## Conversion progress
After exact approval, terminal tracker reports observable phase, elapsed time, output size, active/inactive state, exit status, and sanitized error. It updates
every five seconds by default while work remains active. Phases cover converting
audio, applying chapters, validating output, and moving completed files. Output
size appears only when a regular conversion artifact can be observed safely.
Tracker does not report percentage or ETA because `m4b-tool` does not expose
reliable values for either. It reads growing output size from filesystem
metadata and never runs `ffprobe` against a growing output. Validation invokes
`ffprobe` only after chapter application finishes.
For every terminal event, that same progress record is appended exactly once to current
UTC-timestamped log beneath `./state/logs`. Pressing Ctrl-C retains existing
cancellation behavior: conversion child process group is stopped, final
inactive event records interruption, source remains pending, and recoverable
partial/work artifacts remain available for explicit cleanup. Moving starts
only after successful validation; moving failure receives its own inactive
error record and keeps existing workflow recovery guarantees.
## Collisions and recovery
If the selected output name already exists in `ready`, choose another name or
@@ -424,11 +445,14 @@ Never promote a new pin solely because the image builds.
- [ ] Launch through `ssh -t` is interactive and remains usable at 80 columns.
- [ ] Pending content is visible and all destination paths are writable.
- [ ] A disposable conversion produces a playable M4B with expected chapters.
- [ ] A nontrivial conversion visibly reports all four progress phases without
percentage or ETA, and its persistent log contains same records once.
- [ ] Output, moved source, and log ownership match `PUID:PGID`.
- [ ] An existing output collision is refused without changing either file.
- [ ] Existing `done` and `review` collisions are refused without changing the
pending source or the existing destination.
- [ ] Ctrl-C leaves the source pending and stale cleanup lists only expected paths.
- [ ] Ctrl-C adds final inactive interruption record to persistent conversion log.
- [ ] Removing the interrupted container leaves stale work under `./state/work`.
- [ ] Successful conversion yields the expected pending → ready + done transition.
- [ ] `REVIEW` yields the expected pending → review transition.
+8 -1
View File
@@ -12,6 +12,7 @@ import sys
from typing import Sequence, TextIO
from .config import ConfigError, load_settings
from .converter import Converter
from .models import Settings
from .silence import detect_silences
from .tui import AudiobookApp, TerminalUI
@@ -90,9 +91,15 @@ def doctor(
def build_app(settings: Settings) -> AudiobookApp:
"""Build the normal interactive composition, including optional Audnexus ownership."""
ui = TerminalUI(roots=settings.roots)
return AudiobookApp(
settings,
TerminalUI(roots=settings.roots),
ui,
converter=Converter(
settings,
on_output=ui.stream,
on_progress=ui.show_progress,
),
silence_detector=detect_silences,
)
+66 -4
View File
@@ -6,7 +6,8 @@ from collections.abc import Callable, Mapping
from dataclasses import replace
from datetime import UTC, datetime
from pathlib import Path
from typing import Any, Protocol
import time
from typing import Any, Protocol, TextIO
from .audnexus import AudnexusBook, AudnexusChapters, AudnexusClient
from .chapter_analysis import (
@@ -25,6 +26,7 @@ from .converter import Converter, ValidationResult
from .metadata import infer_metadata, safe_output_stem
from .models import Book, BookMetadata, Chapter, ChapterMode, ConversionPlan, Roots, Settings
from .planner import PlanError, build_ffmetadata_argv, build_plan, render_command
from .progress import ProgressEvent, ProgressPhase, format_progress
from .scanner import ScanError, discover_pending, scan_book
from .silence import Silence, detect_silences
from .workflow import WorkflowError, cleanup_stale, finalize_success, find_stale, move_to_review
@@ -61,6 +63,7 @@ class UIAdapter(Protocol):
def select_stale_cleanup(self, paths: tuple[Path, ...]) -> tuple[Path, ...]: ...
def confirm_stale_cleanup(self, paths: tuple[Path, ...], *, all_selected: bool) -> bool: ...
def stream(self, line: str) -> None: ...
def show_progress(self, event: ProgressEvent) -> None: ...
def show_result(self, message: str, *, success: bool) -> None: ...
def show_error(self, message: str) -> None: ...
@@ -382,6 +385,8 @@ class TerminalUI:
return self._session.prompt("Delete selected displayed stale artifacts? [y/N]: ") == "y"
def stream(self, line: str) -> None: self._print(line.rstrip())
def show_progress(self, event: ProgressEvent) -> None:
self._print(format_progress(event))
def show_result(self, message: str, *, success: bool) -> None: self._print(message, style="green" if success else "red")
def show_error(self, message: str) -> None: self._print(message, style="red")
@@ -395,6 +400,7 @@ ReviewMover = Callable[[Path, Roots], Path]
StaleFinder = Callable[[Settings], tuple[Path, ...]]
StaleCleaner = Callable[[tuple[Path, ...], Settings], None]
SilenceDetector = Callable[[Book, Settings], tuple[Silence, ...]]
ProgressClock = Callable[[], float]
class ConverterService(Protocol):
@@ -412,6 +418,51 @@ def _utc_now() -> datetime:
return datetime.now(UTC)
def finalize_with_progress(
plan: ConversionPlan,
roots: Roots,
validation: ValidationResult,
finalizer: Finalizer,
log_path: Path,
on_progress: Callable[[ProgressEvent], None],
*,
clock: ProgressClock = time.monotonic,
) -> Path:
"""Mirror finalization progress to its terminal sink and conversion log."""
log_path.parent.mkdir(parents=True, exist_ok=True)
started = clock()
def emit(event: ProgressEvent, log_file: TextIO) -> None:
log_file.write(format_progress(event) + "\n")
log_file.flush()
on_progress(event)
with log_path.open("a", encoding="utf-8") as log_file:
emit(ProgressEvent(ProgressPhase.MOVING, 0), log_file)
try:
destination = finalizer(plan, roots, validation)
except BaseException as error:
emit(
ProgressEvent(
ProgressPhase.MOVING,
max(0.0, clock() - started),
active=False,
error=str(error) or error.__class__.__name__,
),
log_file,
)
raise
emit(
ProgressEvent(
ProgressPhase.MOVING,
max(0.0, clock() - started),
active=False,
),
log_file,
)
return destination
class AudiobookApp:
"""Compose a deliberate workflow; no state mutation occurs before typed approval."""
@@ -433,14 +484,16 @@ class AudiobookApp:
audnexus: AudnexusService | None = None,
silence_detector: SilenceDetector = detect_silences,
log_clock: Callable[[], datetime] = _utc_now,
progress_clock: ProgressClock = time.monotonic,
) -> None:
self._settings, self._ui, self._discoverer = settings, ui, discoverer
self._scanner, self._infer_metadata = scanner or self._scan_with_ffprobe, infer_metadata
self._chapter_builders = chapter_builders or {ChapterMode.EMBEDDED: chapters_from_embedded, ChapterMode.FILENAMES: chapters_from_filenames}
self._planner, self._converter, self._finalizer = planner, converter or Converter(settings, on_output=ui.stream), finalizer
self._planner, self._converter, self._finalizer = planner, converter or Converter(settings, on_output=ui.stream, on_progress=ui.show_progress), finalizer
self._review_mover, self._stale_finder, self._stale_cleaner = review_mover, stale_finder, stale_cleaner
self._silence_detector = silence_detector
self._log_clock = log_clock
self._progress_clock = progress_clock
self._audnexus = audnexus if settings.audnexus_enabled else None
if self._audnexus is None and settings.audnexus_enabled:
self._audnexus = AudnexusClient(settings.audnexus_base_url, connect_timeout=settings.audnexus_connect_timeout, read_timeout=settings.audnexus_read_timeout)
@@ -577,8 +630,9 @@ class AudiobookApp:
return 1
self._ui.preview_conversion(plan, chapter_source)
if not self._ui.confirm_conversion(): return 0
log_path = self._log_path(plan)
try:
result = self._run_converter(plan, self._log_path(plan))
result = self._run_converter(plan, log_path)
except Exception as error:
self._ui.show_error(f"Conversion failed before validation: {error}")
return 1
@@ -586,7 +640,15 @@ class AudiobookApp:
self._ui.show_result("Conversion failed: " + "; ".join(result.errors), success=False)
return 1
try:
destination = self._finalizer(plan, self._settings.roots, result)
destination = finalize_with_progress(
plan,
self._settings.roots,
result,
self._finalizer,
log_path,
self._ui.show_progress,
clock=self._progress_clock,
)
except Exception as error:
self._ui.show_result(f"Conversion validated but finalization failed: {error}", success=False)
return 1
+45 -2
View File
@@ -106,7 +106,9 @@ from app.chapters import chapters_from_embedded
from app.converter import Converter
from app.models import BookMetadata, Roots, Settings
from app.planner import build_plan
from app.progress import ProgressPhase, format_progress
from app.scanner import scan_book
from app.tui import finalize_with_progress
from app.workflow import finalize_success
root = Path(os.environ["AUDIOBOOK_SMOKE_ROOT"])
@@ -122,6 +124,9 @@ settings = Settings(
work_dir=root / "state" / "work",
jobs=1,
audnexus_enabled=False,
progress_update_seconds=float(
os.environ.get("AUDIOBOOK_SMOKE_PROGRESS_UPDATE_SECONDS", "0.05")
),
)
def run_probe(argv: tuple[str, ...]) -> subprocess.CompletedProcess[str]:
@@ -141,14 +146,52 @@ metadata = BookMetadata(
cover=root / "pending" / "Synthetic Book" / "cover.jpg",
)
plan = build_plan(book, metadata, chapters, "Synthetic Book.m4b", settings)
validation = Converter(settings).run(plan, settings.state_dir / "smoke.log")
log_path = settings.state_dir / "smoke.log"
progress = []
validation = Converter(settings, on_progress=progress.append).run(plan, log_path)
if not validation.ok:
raise SystemExit("conversion validation failed: " + "; ".join(validation.errors))
finalize_success(plan, roots, validation)
finalize_with_progress(
plan,
roots,
validation,
finalize_success,
log_path,
progress.append,
)
if source.exists():
raise SystemExit("source was not moved out of pending")
if not (roots.done / source.name).is_dir():
raise SystemExit("source was not moved to done")
required_phases = {
ProgressPhase.CONVERTING,
ProgressPhase.APPLYING_CHAPTERS,
ProgressPhase.VALIDATING,
ProgressPhase.MOVING,
}
for phase in required_phases:
if not any(event.phase is phase and event.active for event in progress):
raise SystemExit(f"progress smoke missing active phase: {phase.value}")
if not any(event.phase is phase and not event.active for event in progress):
raise SystemExit(f"progress smoke missing terminal phase: {phase.value}")
progress_prefixes = (
"[Converting audio]",
"[Applying chapters]",
"[Validating output]",
"[Moving completed files]",
)
logged_progress = [
line
for line in log_path.read_text(encoding="utf-8").splitlines()
if line.startswith(progress_prefixes)
]
callback_progress = [format_progress(event) for event in progress]
if logged_progress != callback_progress:
raise SystemExit(
"progress smoke terminal/log mismatch: "
f"callback={callback_progress!r} log={logged_progress!r}"
)
print("conversion progress smoke passed")
PY
ffprobe -v error \
+51 -2
View File
@@ -5,6 +5,7 @@ import pytest
import app.main as main_module
from app.models import Roots, Settings
from app.progress import ProgressEvent, ProgressPhase
def test_run_rejects_noninteractive_terminal(monkeypatch, capsys) -> None:
@@ -128,11 +129,29 @@ def test_build_app_composes_the_real_silence_detector(monkeypatch) -> None:
Roots(Path("pending"), Path("ready"), Path("done"), Path("review"))
)
detector = object()
ui = object()
class UI:
def stream(self, line: str) -> None:
pass
def show_progress(self, event: ProgressEvent) -> None:
pass
ui = UI()
converter = object()
converter_calls: list[tuple[Settings, object, object]] = []
received: list[tuple[Settings, object, dict[str, object]]] = []
monkeypatch.setattr(main_module, "detect_silences", detector, raising=False)
monkeypatch.setattr(main_module, "TerminalUI", lambda **kwargs: ui)
monkeypatch.setattr(
main_module,
"Converter",
lambda configured, *, on_output, on_progress: converter_calls.append(
(configured, on_output, on_progress)
)
or converter,
raising=False,
)
monkeypatch.setattr(
main_module,
"AudiobookApp",
@@ -145,5 +164,35 @@ def test_build_app_composes_the_real_silence_detector(monkeypatch) -> None:
main_module.build_app(settings)
assert received == [
(settings, ui, {"silence_detector": detector}),
(
settings,
ui,
{"converter": converter, "silence_detector": detector},
),
]
assert converter_calls == [(settings, ui.stream, ui.show_progress)]
def test_build_app_routes_real_converter_progress_to_terminal_ui(monkeypatch) -> None:
settings = Settings(
Roots(Path("pending"), Path("ready"), Path("done"), Path("review"))
)
class UI:
def __init__(self) -> None:
self.progress: list[ProgressEvent] = []
def stream(self, line: str) -> None:
pass
def show_progress(self, event: ProgressEvent) -> None:
self.progress.append(event)
ui = UI()
monkeypatch.setattr(main_module, "TerminalUI", lambda **kwargs: ui)
app = main_module.build_app(settings)
event = ProgressEvent(ProgressPhase.CONVERTING, 5)
app._converter._on_progress(event)
assert ui.progress == [event]
+21 -1
View File
@@ -152,6 +152,7 @@ def _run_container_smoke_with_probe_payload(
" mv \"$AUDIOBOOK_SMOKE_ROOT/pending/Synthetic Book\" "
"\"$AUDIOBOOK_SMOKE_ROOT/done/Synthetic Book\"\n"
" : > \"$AUDIOBOOK_SMOKE_ROOT/ready/Synthetic Book.m4b\"\n"
" printf '%s\\n' 'conversion progress smoke passed'\n"
" exit 0\n"
"fi\n"
"exec \"$REAL_PYTHON3\" \"$@\"\n",
@@ -227,6 +228,7 @@ def test_packaged_config_enables_discovery_chapter_analysis() -> None:
"max_output_bytes": 10_485_760,
},
}
assert config["progress"] == {"update_seconds": 5.0}
def test_operator_docs_cover_private_audnexus_chapter_analysis() -> None:
@@ -251,6 +253,23 @@ def test_operator_docs_cover_private_audnexus_chapter_analysis() -> None:
assert guidance in readme
def test_operator_docs_explain_honest_persistent_conversion_progress() -> None:
readme = Path("README.md").read_text(encoding="utf-8")
required_operator_guidance = (
"## Conversion progress",
"five seconds",
"phase, elapsed time, output size, active/inactive state, exit status, and sanitized error",
"does not report percentage or ETA",
"never runs `ffprobe` against a growing output",
"same progress record is appended exactly once",
"Ctrl-C",
"./state/logs",
)
for guidance in required_operator_guidance:
assert guidance in readme
def test_work_directory_is_persistent_in_the_state_mount() -> None:
config = tomllib.loads(Path("config.toml").read_text(encoding="utf-8"))
service = _service()
@@ -359,7 +378,7 @@ def test_container_smoke_runs_silence_detector_before_conversion() -> None:
smoke = Path("scripts/container-smoke.sh").read_text(encoding="utf-8")
assert smoke.index('print("silence detector smoke passed")') < smoke.index(
"validation = Converter(settings).run"
"validation = Converter(settings, on_progress=progress.append).run"
)
@@ -499,6 +518,7 @@ def test_container_smoke_accepts_expected_final_stream_layout(
assert result.returncode == 0, result.stderr
assert "silence detector smoke passed" in result.stdout
assert "conversion progress smoke passed" in result.stdout
assert "container smoke test passed" in result.stdout
+138
View File
@@ -12,6 +12,7 @@ from app.chapter_analysis import Alignment, ChapterCandidate
from app.converter import ValidationResult
from app.models import Book, BookMetadata, Chapter, ChapterMode, ConversionPlan, Roots, Settings, Track
from app.planner import PlanError, build_ffmetadata_argv, render_command
from app.progress import ProgressEvent, ProgressPhase, format_progress
from app.silence import Silence
from app.tui import AudiobookApp, TerminalUI, UIAdapter, confirm_exact
@@ -48,6 +49,7 @@ class ScriptedUI(UIAdapter):
self.remote_metadata: BookMetadata | None = None
self.chapter_candidates: tuple[ChapterCandidate, ...] = ()
self.preview_source: ChapterCandidate | ChapterMode | None = None
self.progress_events: list[ProgressEvent] = []
def show_queue(self, queue: tuple[Path, ...]) -> None: self.events.append("queue")
def select_book(self, queue: tuple[Path, ...]) -> Path | None: return self.source
@@ -99,6 +101,9 @@ class ScriptedUI(UIAdapter):
return self.stale_selection
def confirm_stale_cleanup(self, paths: tuple[Path, ...], *, all_selected: bool) -> bool: return True
def stream(self, line: str) -> None: self.events.append("stream")
def show_progress(self, event: ProgressEvent) -> None:
self.progress_events.append(event)
self.events.append(f"progress:{event.phase.value}:{'active' if event.active else 'inactive'}")
def show_result(self, message: str, *, success: bool) -> None: self.events.append("result")
def show_error(self, message: str) -> None: self.events.append(f"error:{message}")
@@ -146,6 +151,7 @@ def test_approved_conversion_preserves_validation_result_and_service_order(tmp_p
calls.append("finalizer")
return roots.done / "Book"
app = _conversion_app(tmp_path, ui, converter=ConverterWithRun(), finalizer=finalizer)
app._log_path = lambda plan: tmp_path / "state" / "logs" / "Book.log" # type: ignore[method-assign]
app._scanner = lambda path: calls.append("scanner") or _book(path) # type: ignore[method-assign]
app._chapter_builders = {ChapterMode.FILENAMES: lambda book: calls.append("chapters") or (Chapter(0, "One"),)}
app._planner = lambda *args: calls.append("planner") or _plan(_book(tmp_path / "pending" / "Book"), BookMetadata("Book", "Author"), (Chapter(0, "One"),), _settings(tmp_path))
@@ -153,6 +159,117 @@ def test_approved_conversion_preserves_validation_result_and_service_order(tmp_p
assert calls == ["scanner", "chapters", "planner", "converter", "finalizer"]
def test_successful_finalization_mirrors_moving_progress_after_validation(
tmp_path: Path,
) -> None:
source = tmp_path / "pending" / "Book"
source.mkdir(parents=True)
log_path = tmp_path / "state" / "logs" / "Book.log"
order: list[str] = []
ui = ScriptedUI(source=source)
class OrderedUI(ScriptedUI):
def show_progress(self, event: ProgressEvent) -> None:
super().show_progress(event)
order.append(f"progress:{event.phase.value}:{event.active}")
ui = OrderedUI(source=source)
def converter(plan: ConversionPlan, received_log: Path) -> ValidationResult:
assert received_log == log_path
order.append("validated")
return ValidationResult(True)
def finalizer(
plan: ConversionPlan, roots: Roots, result: ValidationResult
) -> Path:
order.append("finalizer")
return roots.done / "Book"
ticks = iter((10.0, 12.5))
app = _conversion_app(
tmp_path,
ui,
converter=converter,
finalizer=finalizer,
progress_clock=lambda: next(ticks),
)
app._log_path = lambda plan: log_path # type: ignore[method-assign]
assert app.run() == 0
assert order == [
"validated",
"progress:moving:True",
"finalizer",
"progress:moving:False",
]
expected = [
ProgressEvent(ProgressPhase.MOVING, 0),
ProgressEvent(ProgressPhase.MOVING, 2.5, active=False),
]
assert ui.progress_events == expected
assert log_path.read_text(encoding="utf-8").splitlines() == [
format_progress(event) for event in expected
]
def test_failed_finalization_logs_moving_error_and_preserves_source(
tmp_path: Path,
) -> None:
source = tmp_path / "pending" / "Book"
source.mkdir(parents=True)
log_path = tmp_path / "state" / "logs" / "Book.log"
ui = ScriptedUI(source=source)
def fail_finalization(
plan: ConversionPlan, roots: Roots, result: ValidationResult
) -> Path:
assert source.is_dir()
raise OSError("done destination unavailable")
ticks = iter((20.0, 23.0))
app = _conversion_app(
tmp_path,
ui,
converter=lambda plan, log: ValidationResult(True),
finalizer=fail_finalization,
progress_clock=lambda: next(ticks),
)
app._log_path = lambda plan: log_path # type: ignore[method-assign]
assert app.run() == 1
assert source.is_dir()
assert ui.progress_events == [
ProgressEvent(ProgressPhase.MOVING, 0),
ProgressEvent(
ProgressPhase.MOVING,
3,
active=False,
error="done destination unavailable",
),
]
assert log_path.read_text(encoding="utf-8").splitlines() == [
format_progress(event) for event in ui.progress_events
]
def test_failed_validation_never_emits_moving_or_calls_finalizer(
tmp_path: Path,
) -> None:
ui = ScriptedUI(source=tmp_path / "pending" / "Book")
app = _conversion_app(
tmp_path,
ui,
converter=lambda plan, log: ValidationResult(False, ("invalid output",)),
finalizer=lambda *args: (_ for _ in ()).throw(
AssertionError("finalizer called after failed validation")
),
)
assert app.run() == 1
assert ui.progress_events == []
def test_conversion_log_path_contains_a_utc_timestamp(tmp_path: Path) -> None:
logs: list[Path] = []
ui = ScriptedUI(source=tmp_path / "pending" / "Book")
@@ -696,9 +813,11 @@ def test_invalid_output_filename_retries_before_planning(tmp_path: Path) -> None
class FakeConsole:
def __init__(self) -> None:
self.values: list[str] = []
self.calls: list[tuple[str, dict[str, object]]] = []
def print(self, value: object, **kwargs: object) -> None:
self.values.append(str(value))
self.calls.append((str(value), kwargs))
class Answers:
@@ -719,6 +838,25 @@ def test_terminal_adapter_retries_selection_and_uses_exact_review_and_clean_toke
assert any("Choose a listed number" in value for value in console.values)
def test_terminal_progress_is_one_plain_non_markup_line() -> None:
console = FakeConsole()
ui = TerminalUI(console=console, session=Answers())
event = ProgressEvent(
ProgressPhase.CONVERTING,
65,
output_bytes=1_048_576,
)
ui.show_progress(event)
assert console.calls == [
(
"[Converting audio] elapsed 00:01:05 | output 1.0 MiB | active",
{"markup": False, "highlight": False},
)
]
def test_terminal_stale_selection_retries_malformed_and_out_of_range_input(tmp_path: Path) -> None:
console = FakeConsole()
ui = TerminalUI(console=console, session=Answers("1,,2", "9", "p"))