From d3ded8af0e6cde101fc53b99a88f4c4380e125c9 Mon Sep 17 00:00:00 2001 From: Artem Akymenko Date: Wed, 29 Jul 2026 11:05:52 +0000 Subject: [PATCH] feat: add comprehensive logging throughout conversion pipeline - voice_resolver: log spec resolution and cache hits - conversion_executor: log chapter start/end, voice resolution, timing - conversion_planner: log plan summary - conversion_service: log entry point params and outcome - conversion_runner: log job params and lifecycle - form.py: log PendingJob creation - synthesize.py: log pipeline creation and device selection --- abogen/application/conversion_executor.py | 16 ++++++++++++++++ abogen/application/conversion_planner.py | 8 ++++++++ abogen/application/conversion_service.py | 7 +++++++ abogen/application/voice_resolver.py | 4 ++++ abogen/webui/conversion_runner.py | 11 +++++++++++ abogen/webui/routes/utils/form.py | 6 ++++++ abogen/webui/routes/utils/synthesize.py | 5 +++++ 7 files changed, 57 insertions(+) diff --git a/abogen/application/conversion_executor.py b/abogen/application/conversion_executor.py index a866268..4e6eb90 100644 --- a/abogen/application/conversion_executor.py +++ b/abogen/application/conversion_executor.py @@ -8,6 +8,7 @@ This is Stage 6 of the conversion flow unification plan. from __future__ import annotations +import logging import time from contextlib import ExitStack from typing import Any, Callable, Dict, List, Optional, Set, Tuple @@ -172,6 +173,14 @@ def execute_conversion( result = ConversionResult(metadata=plan.metadata) collector = MarkerCollector() + logging.info( + "[executor] Starting: chapters=%d intro=%s outro=%s merge=%s", + len(plan.chapters), + bool(plan.intro and plan.intro.enabled), + bool(plan.outro and plan.outro.enabled), + request.save.merge_chapters_at_end, + ) + # Determine cancellation checker if check_cancelled is None: check_cancelled = lambda: events.check_cancelled() @@ -207,10 +216,12 @@ def execute_conversion( # Resolve voices base_voice_spec = request.voice or "M1" + logging.info("[executor] Resolving base voice: spec=%s", base_voice_spec) base_provider, base_voice_choice, base_speed, base_steps = _resolve_voice( voice_resolver, base_voice_spec, request, log_callback=lambda msg: events.log(msg, level="warning"), ) + logging.info("[executor] Base voice resolved: provider=%s voice=%s speed=%.2f", base_provider, base_voice_choice, base_speed) # Use ExitStack for resource management with ExitStack() as stack: @@ -290,12 +301,14 @@ def execute_conversion( chapter_display = f"Chapter {chapter_idx}/{len(plan.chapters)}: {chapter.title}" events.log(f"Processing {chapter_display}") + logging.info("[executor] Chapter %d/%d start: title=%s", chapter_idx, len(plan.chapters), chapter.title) # Resolve chapter voice chapter_provider, chapter_voice, chapter_speed, chapter_steps = _resolve_voice( voice_resolver, chapter.voice_spec, request, log_callback=lambda msg: events.log(msg, level="warning"), ) + logging.info("[executor] Chapter %d voice: provider=%s voice=%s speed=%.2f", chapter_idx, chapter_provider, chapter_voice, chapter_speed) chapter_backend = pipeline_provider.get(chapter_provider, request.language, request.use_gpu) # Record chapter start for markers @@ -517,6 +530,9 @@ def execute_conversion( # Record chapter end for markers collector.on_chapter_end(stats.current_time) + logging.info("[executor] Chapter %d/%d done: time=%.1fs", chapter_idx, len(plan.chapters), stats.current_time) + + logging.info("[executor] All chapters processed, total time=%.1fs", stats.current_time) # Process outro if plan.outro and plan.outro.enabled and merge_chapters: diff --git a/abogen/application/conversion_planner.py b/abogen/application/conversion_planner.py index aced6d8..96e2ff7 100644 --- a/abogen/application/conversion_planner.py +++ b/abogen/application/conversion_planner.py @@ -8,6 +8,7 @@ This is Stage 2 of the conversion flow unification plan. from __future__ import annotations +import logging from typing import Any, Dict, List, Optional, Tuple from abogen.application.conversion_models import ( @@ -65,6 +66,13 @@ def build_conversion_plan(request: ConversionRequest) -> ConversionPlan: # 7. Resolve output layout output_layout = resolve_output_layout(request) + logging.info( + "[planner] Plan built: chapters=%d intro=%s outro=%s", + len(chapters), + bool(intro and intro.enabled), + bool(outro and outro.enabled), + ) + return ConversionPlan( request=request, metadata=metadata, diff --git a/abogen/application/conversion_service.py b/abogen/application/conversion_service.py index 8103ab9..7b654c8 100644 --- a/abogen/application/conversion_service.py +++ b/abogen/application/conversion_service.py @@ -15,6 +15,7 @@ The service NEVER imports from PyQt or WebUI. from __future__ import annotations +import logging from collections import defaultdict from typing import Any, Dict @@ -61,6 +62,10 @@ def run_conversion( try: # Stage 0: Create voice resolver events.log("Preparing conversion pipeline") + logging.info( + "[app] run_conversion: provider=%s language=%s voice=%s speed=%.2f", + request.tts_provider, request.language, request.voice, request.speed, + ) resolver = _create_voice_resolver(request, pool, voice_cache) # Stage 1: Prepare TTS context @@ -94,10 +99,12 @@ def run_conversion( _finalize(request, result, plan, events) events.log("Conversion complete") + logging.info("[app] run_conversion completed successfully") return result except Exception as e: events.log(f"Conversion failed: {e}", level="error") + logging.exception("[app] run_conversion failed: %s", e) raise finally: pool.dispose_all() diff --git a/abogen/application/voice_resolver.py b/abogen/application/voice_resolver.py index 62b15c9..0b3086c 100644 --- a/abogen/application/voice_resolver.py +++ b/abogen/application/voice_resolver.py @@ -7,6 +7,7 @@ PyQtVoiceResolver) with a single app-layer implementation. from __future__ import annotations +import logging from typing import Any, Dict, Optional from abogen.application.conversion_ports import ResolvedVoice, VoiceResolver @@ -49,6 +50,7 @@ class AppVoiceResolver: cache_key = f"{provider}:{resolved}" if resolved else provider cached = self._cache.get(cache_key) if cached is not None: + logging.info("[resolver] Cache hit: spec=%s -> provider=%s resolved=%s", voice_spec, provider, resolved) return ResolvedVoice( provider=provider, resolved_spec=resolved, @@ -68,6 +70,8 @@ class AppVoiceResolver: loaded = resolved self._cache.set(cache_key, loaded) + logging.info("[resolver] Resolved: spec=%s -> provider=%s resolved=%s speed=%.2f steps=%s", + voice_spec, provider, resolved, speed, steps) return ResolvedVoice( provider=provider, resolved_spec=resolved, diff --git a/abogen/webui/conversion_runner.py b/abogen/webui/conversion_runner.py index 7e0de18..167de11 100644 --- a/abogen/webui/conversion_runner.py +++ b/abogen/webui/conversion_runner.py @@ -15,6 +15,7 @@ Engine converts Language → its own format internally. from __future__ import annotations +import logging from pathlib import Path from typing import Any @@ -48,6 +49,11 @@ def _build_request(job: Job) -> ConversionRequest: """Build a ConversionRequest from a WebUI Job.""" source_path = Path(job.stored_path) if job.stored_path else None + logging.info( + "[runner] Building request: job=%s provider=%s language=%s voice=%s speed=%.2f gpu=%s", + job.id, job.tts_provider, job.language, job.voice, job.speed, job.use_gpu, + ) + return ConversionRequest( # Source source_path=source_path, @@ -186,6 +192,7 @@ def run_conversion_job(job: Job) -> None: request = _build_request(job) events = WebUIEventsAdapter(job) + logging.info("[runner] Starting conversion: job=%s", job.id) try: result = run_conversion(request, events) _apply_result(job, result) @@ -193,10 +200,14 @@ def run_conversion_job(job: Job) -> None: if job.status != JobStatus.CANCELLED: job.progress = 1.0 + logging.info("[runner] Conversion completed: job=%s", job.id) + except ConversionCancelled: job.status = JobStatus.CANCELLED job.add_log("Job cancelled", level="warning") + logging.info("[runner] Conversion cancelled: job=%s", job.id) except Exception as exc: job.error = str(exc) job.status = JobStatus.FAILED job.add_log(f"Job failed: {exc}", level="error") + logging.exception("[runner] Conversion failed: job=%s error=%s", job.id, exc) diff --git a/abogen/webui/routes/utils/form.py b/abogen/webui/routes/utils/form.py index fbc163d..14bb829 100644 --- a/abogen/webui/routes/utils/form.py +++ b/abogen/webui/routes/utils/form.py @@ -1,3 +1,4 @@ +import logging import time import uuid from typing import Any, Dict, Iterable, List, Mapping, Optional, Tuple, cast @@ -794,6 +795,11 @@ def build_pending_job_from_extraction( else: normalization_overrides[key] = default_val + logging.info( + "[form] Creating PendingJob: language=%s voice=%s speed=%.2f provider=%s", + language, voice, speed, settings.get("tts_provider", "kokoro"), + ) + pending = PendingJob( id=uuid.uuid4().hex, original_filename=original_name, diff --git a/abogen/webui/routes/utils/synthesize.py b/abogen/webui/routes/utils/synthesize.py index ecb0716..e5eee08 100644 --- a/abogen/webui/routes/utils/synthesize.py +++ b/abogen/webui/routes/utils/synthesize.py @@ -1,4 +1,5 @@ import io +import logging import threading from typing import Any, Dict, Iterable, List, Mapping, Optional, Tuple import numpy as np @@ -43,9 +44,11 @@ def _resolve_pipeline(language: Language, use_gpu: bool) -> Tuple[Any, bool]: last_error: Optional[Exception] = None for device in devices: try: + logging.info("[preview] Trying device=%s for language=%s", device, language) return get_preview_pipeline(language, device), device != "cpu" except Exception as exc: last_error = exc + logging.warning("[preview] Device %s failed: %s", device, exc) raise RuntimeError("Preview pipeline is unavailable") from last_error @@ -55,9 +58,11 @@ def get_preview_pipeline(language: Language, device: str) -> Any: with _preview_pipeline_lock: pipeline = _preview_pipelines.get(key) if pipeline is not None: + logging.info("[preview] Using cached pipeline for %s/%s", language, device) return pipeline from abogen.tts_plugin.utils import create_pipeline + logging.info("[preview] Creating pipeline: provider=kokoro language=%s device=%s", language, device) pipeline = create_pipeline("kokoro", language=language, device=device) _preview_pipelines[key] = pipeline return pipeline