From 0c759d78075bd258a7d173a3814ddbb7144f8f0b Mon Sep 17 00:00:00 2001 From: hp Date: Thu, 14 May 2026 22:02:51 +0800 Subject: [PATCH 1/2] fix: quiet default cli progress output --- src/asr/cli.py | 2 +- src/asr/observability/console.py | 69 +++++++++---- src/asr/providers/qwen_mlx.py | 32 +++++- tests/test_cli.py | 29 ++++++ tests/test_observability.py | 145 ++++++++++++++++++++++++++- tests/test_qwen_provider_windowed.py | 58 ++++++++++- 6 files changed, 308 insertions(+), 27 deletions(-) diff --git a/src/asr/cli.py b/src/asr/cli.py index f380054..b758179 100644 --- a/src/asr/cli.py +++ b/src/asr/cli.py @@ -238,7 +238,7 @@ def _run_transcription( ) -> int: run_id = f"run-{uuid.uuid4().hex[:8]}" collector = MetricsCollectorObserver() if verbose else None - observers = [ConsoleProgressObserver()] + observers = [ConsoleProgressObserver(verbose=verbose)] if collector is not None: observers.append(collector) observer = ObserverMux( diff --git a/src/asr/observability/console.py b/src/asr/observability/console.py index 9807300..349306a 100644 --- a/src/asr/observability/console.py +++ b/src/asr/observability/console.py @@ -14,6 +14,22 @@ from asr.observability.events import ObservabilityEvent _PROGRESS_BAR_WIDTH = 20 +_QUIET_STEP_LABELS = { + "preflight": "checking environment", + "prepare": "preparing audio", + "preprocess_vad": "detecting speech", + "transcribe": "transcribing", +} +_QUIET_FINALIZING_STEPS = frozenset( + { + "provider_merge", + "render_srt", + "render_vtt", + "render_json", + "write_outputs", + } +) +_STATUS_LABELS = {"ok": "done"} class _ThinProgressBarColumn(ProgressColumn): @@ -37,6 +53,7 @@ class ConsoleProgressObserver: stream: TextIO = field(default_factory=lambda: sys.stdout) warning_stream: TextIO = field(default_factory=lambda: sys.stderr) is_tty: bool | None = None + verbose: bool = False _current_index: int = field(default=0, init=False, repr=False) _current_total: int = field(default=0, init=False, repr=False) _current_name: str = field(default="", init=False, repr=False) @@ -48,6 +65,7 @@ class ConsoleProgressObserver: _console: Console | None = field(default=None, init=False, repr=False) _progress: Progress | None = field(default=None, init=False, repr=False) _progress_task_id: int | None = field(default=None, init=False, repr=False) + _quiet_phase: str | None = field(default=None, init=False, repr=False) def __post_init__(self) -> None: if self.is_tty is None: @@ -62,15 +80,21 @@ def on_event(self, event: ObservabilityEvent) -> None: self._current_window_index = 0 self._current_window_count = 0 self._file_start_perf = event.perf_counter + self._quiet_phase = None self._write_line(self._with_elapsed("discover", event.perf_counter)) return if event.event_type == "step_start": if event.step == "provider_window": + self._quiet_phase = None self._record_window_progress(event) self._write_window_progress(event.perf_counter) return + if not self._should_display_step(event): + self._handle_hidden_step(event) + return self._stop_progress() + self._quiet_phase = None self._write_line(self._with_elapsed(self._display_step(event), event.perf_counter)) return @@ -80,30 +104,41 @@ def on_event(self, event: ObservabilityEvent) -> None: if event.event_type == "file_end": status = str(event.meta.get("status", "ok")) - if self._current_window_count > 0: - if status == "ok": - self._current_window_index = self._current_window_count - else: - self._stop_progress() - self._write_line( - f"{status} | {self._window_progress_line(event.perf_counter)}", - finalize=True, - ) - return - self._write_window_progress(event.perf_counter) - self._stop_progress() - return self._stop_progress() self._write_line( - self._with_elapsed(status, event.perf_counter), + self._with_elapsed(self._display_status(status), event.perf_counter), finalize=True, ) def close(self) -> None: self._stop_progress() + def _should_display_step(self, event: ObservabilityEvent) -> bool: + if self.verbose: + return True + return event.step in _QUIET_STEP_LABELS + + def _handle_hidden_step(self, event: ObservabilityEvent) -> None: + if ( + not self.verbose + and event.step in _QUIET_FINALIZING_STEPS + and self._progress is not None + ): + self._stop_progress() + if self._quiet_phase != "finalizing": + self._quiet_phase = "finalizing" + self._write_line(self._with_elapsed("finalizing", event.perf_counter)) + return + self._stop_progress() + def _display_step(self, event: ObservabilityEvent) -> str: - return event.step or "step" + step = event.step or "step" + if self.verbose: + return step + return _QUIET_STEP_LABELS.get(step, step) + + def _display_status(self, status: str) -> str: + return _STATUS_LABELS.get(status, status) def _record_window_progress(self, event: ObservabilityEvent) -> None: window_index = event.meta.get("window_index") @@ -180,8 +215,6 @@ def _stop_progress(self) -> None: if self._progress is None: return self._progress.stop() - if self.is_tty: - self._last_width = 0 self._progress = None self._progress_task_id = None @@ -225,8 +258,8 @@ def _write_line(self, step: str, *, finalize: bool = False) -> None: if self.is_tty: tail = "\n" if finalize else "" padded = line.ljust(self._last_width) - self._last_width = max(self._last_width, len(line)) self.stream.write(f"\r{padded}{tail}") + self._last_width = 0 if finalize else max(self._last_width, len(line)) else: self.stream.write(line + "\n") self.stream.flush() diff --git a/src/asr/providers/qwen_mlx.py b/src/asr/providers/qwen_mlx.py index 9d2e152..911200f 100644 --- a/src/asr/providers/qwen_mlx.py +++ b/src/asr/providers/qwen_mlx.py @@ -3,6 +3,7 @@ from __future__ import annotations import math +import os import shutil import subprocess import tempfile @@ -115,9 +116,7 @@ def transcribe( audio_path: Path, speech_plan: SpeechPlan | None = None, ) -> TranscriptionDocument: - load = self._load_backend() - self._asr_model = self._asr_model or load(self.asr_model_id) - self._aligner_model = self._aligner_model or load(self.aligner_model_id) + self._ensure_models_loaded() with observe_step( self._observer, @@ -580,6 +579,33 @@ def _load_backend(self): ) from exc return load + def _ensure_models_loaded(self) -> None: + if self._asr_model is not None and self._aligner_model is not None: + return + + self._suppress_model_download_progress() + load = self._load_backend() + if self._asr_model is None: + self._asr_model = load(self.asr_model_id) + if self._aligner_model is None: + self._aligner_model = load(self.aligner_model_id) + + def _suppress_model_download_progress(self) -> None: + flag = os.environ.get("HF_HUB_DISABLE_PROGRESS_BARS") + if flag is None: + os.environ["HF_HUB_DISABLE_PROGRESS_BARS"] = "1" + explicitly_enabled = False + else: + explicitly_enabled = flag.strip().lower() in {"0", "false", "off", "no"} + if explicitly_enabled: + return + + try: + from huggingface_hub.utils import disable_progress_bars + except ImportError: + return + disable_progress_bars() + def _probe_duration_sec(self, audio_path: Path) -> float: return probe_duration_sec(audio_path) diff --git a/tests/test_cli.py b/tests/test_cli.py index 547bf8c..980be08 100644 --- a/tests/test_cli.py +++ b/tests/test_cli.py @@ -281,6 +281,35 @@ def test_main_enables_console_progress_by_default( self.assertEqual(exit_code, 0) self.assertTrue(mock_console_observer.called) + self.assertFalse(mock_console_observer.call_args.kwargs["verbose"]) + + @patch("asr.cli.ConsoleProgressObserver") + @patch("asr.cli.discover_cli_sources") + @patch("asr.cli.run_environment_preflight") + @patch("asr.cli.process_media_file") + def test_main_passes_verbose_to_console_progress( + self, + mock_process, + mock_preflight, + mock_discover, + mock_console_observer, + ) -> None: + with TemporaryDirectory() as tmp: + source = Path(tmp) / "demo.mov" + source.write_text("x", encoding="utf-8") + output_root = Path(tmp) / "outputs" + mock_discover.return_value = [(source, Path(tmp))] + mock_preflight.return_value = (True, "") + mock_process.return_value = TranscriptionDocument( + source_path=str(source.with_suffix(".wav")), + provider_name="fake", + segments=[], + ) + + exit_code = main([str(source), "--verbose", "--output-dir", str(output_root)]) + + self.assertEqual(exit_code, 0) + self.assertTrue(mock_console_observer.call_args.kwargs["verbose"]) @patch("asr.cli.discover_cli_sources") @patch("asr.cli.run_environment_preflight") diff --git a/tests/test_observability.py b/tests/test_observability.py index 3c349b2..d942f46 100644 --- a/tests/test_observability.py +++ b/tests/test_observability.py @@ -133,9 +133,145 @@ def test_non_tty_falls_back_to_plain_lines(self) -> None: output = stream.getvalue() self.assertIn("[1/2]", output) - self.assertIn("prepare", output) + self.assertIn("preparing audio", output) self.assertIn("0.5s", output) + def test_default_console_hides_internal_step_names(self) -> None: + stream = io.StringIO() + observer = ConsoleProgressObserver(stream=stream, is_tty=False) + observer.on_event( + ObservabilityEvent( + event_type="file_start", + run_id="run-1", + file_id="1", + source_path="demo.wav", + meta={"index": 1, "total": 1}, + perf_counter=10.0, + ) + ) + observer.on_event( + ObservabilityEvent( + event_type="step_start", + run_id="run-1", + file_id="1", + source_path="demo.wav", + step="transcribe", + perf_counter=11.0, + ) + ) + + for offset, step in enumerate( + ["provider_plan_windows", "provider_merge", "write_outputs"], + start=2, + ): + observer.on_event( + ObservabilityEvent( + event_type="step_start", + run_id="run-1", + file_id="1", + source_path="demo.wav", + step=step, + perf_counter=10.0 + offset, + ) + ) + + output = stream.getvalue() + self.assertIn("transcribing", output) + self.assertNotIn("provider_plan_windows", output) + self.assertNotIn("provider_merge", output) + self.assertNotIn("write_outputs", output) + + def test_default_console_hides_unknown_steps(self) -> None: + stream = io.StringIO() + observer = ConsoleProgressObserver(stream=stream, is_tty=False) + observer.on_event( + ObservabilityEvent( + event_type="file_start", + run_id="run-1", + file_id="1", + source_path="demo.wav", + meta={"index": 1, "total": 1}, + perf_counter=10.0, + ) + ) + observer.on_event( + ObservabilityEvent( + event_type="step_start", + run_id="run-1", + file_id="1", + source_path="demo.wav", + step="provider_tokenize", + perf_counter=11.0, + ) + ) + + self.assertNotIn("provider_tokenize", stream.getvalue()) + + def test_hidden_step_after_rich_progress_displays_finalizing(self) -> None: + stream = io.StringIO() + observer = ConsoleProgressObserver(stream=stream, is_tty=True) + observer.on_event( + ObservabilityEvent( + event_type="file_start", + run_id="run-1", + file_id="1", + source_path="demo.wav", + meta={"index": 1, "total": 1}, + perf_counter=10.0, + ) + ) + observer.on_event( + ObservabilityEvent( + event_type="step_start", + run_id="run-1", + file_id="1", + source_path="demo.wav", + step="provider_window", + meta={"window_index": 7, "window_count": 8}, + perf_counter=20.0, + ) + ) + observer.on_event( + ObservabilityEvent( + event_type="step_start", + run_id="run-1", + file_id="1", + source_path="demo.wav", + step="provider_merge", + perf_counter=21.0, + ) + ) + + output = stream.getvalue() + self.assertIn("finalizing", output) + self.assertNotIn("provider_merge", output) + + def test_verbose_console_keeps_internal_step_names(self) -> None: + stream = io.StringIO() + observer = ConsoleProgressObserver(stream=stream, is_tty=False, verbose=True) + observer.on_event( + ObservabilityEvent( + event_type="file_start", + run_id="run-1", + file_id="1", + source_path="demo.wav", + meta={"index": 1, "total": 1}, + perf_counter=10.0, + ) + ) + observer.on_event( + ObservabilityEvent( + event_type="step_start", + run_id="run-1", + file_id="1", + source_path="demo.wav", + step="provider_plan_windows", + perf_counter=11.0, + ) + ) + + self.assertIn("provider_plan_windows", stream.getvalue()) + def test_provider_window_step_renders_thin_bar_percent_and_elapsed(self) -> None: stream = io.StringIO() observer = ConsoleProgressObserver(stream=stream, is_tty=False) @@ -209,7 +345,7 @@ def test_tty_provider_window_uses_rich_progress(self) -> None: self.assertNotIn("transcribe", output) self.assertNotIn("window", output) - def test_file_end_finalizes_window_progress_bar(self) -> None: + def test_file_end_after_window_progress_prints_done_once(self) -> None: stream = io.StringIO() observer = ConsoleProgressObserver(stream=stream, is_tty=True) observer.on_event( @@ -245,8 +381,9 @@ def test_file_end_finalizes_window_progress_bar(self) -> None: ) output = stream.getvalue() - self.assertIn("100%", output) - self.assertIn("00:15", output) + self.assertIn("done", output) + self.assertNotIn("100%", output) + self.assertEqual(output.count("00:15"), 0) self.assertNotIn("8/8", output) self.assertEqual(observer._last_width, 0) diff --git a/tests/test_qwen_provider_windowed.py b/tests/test_qwen_provider_windowed.py index ca26b53..323125a 100644 --- a/tests/test_qwen_provider_windowed.py +++ b/tests/test_qwen_provider_windowed.py @@ -1,7 +1,10 @@ +import os import subprocess +import sys +import types import unittest from pathlib import Path -from unittest.mock import patch +from unittest.mock import Mock, patch from asr.models import Segment, Token from asr.observability.events import ObservabilityEvent @@ -1192,6 +1195,59 @@ def test_vad_display_bounds_use_largest_overlap_for_cross_bound_segment(self) -> class QwenProviderObservabilityTest(unittest.TestCase): + def test_model_download_progress_is_disabled_by_default(self) -> None: + provider = QwenMlxProvider() + disable_progress_bars = Mock() + hub_module = types.ModuleType("huggingface_hub") + utils_module = types.ModuleType("huggingface_hub.utils") + utils_module.disable_progress_bars = disable_progress_bars + hub_module.utils = utils_module + + with patch.dict( + sys.modules, + { + "huggingface_hub": hub_module, + "huggingface_hub.utils": utils_module, + }, + ), patch.dict(os.environ, {}, clear=True): + provider._suppress_model_download_progress() + + self.assertEqual(os.environ["HF_HUB_DISABLE_PROGRESS_BARS"], "1") + disable_progress_bars.assert_called_once_with() + + def test_model_download_progress_respects_explicit_enable(self) -> None: + provider = QwenMlxProvider() + disable_progress_bars = Mock() + hub_module = types.ModuleType("huggingface_hub") + utils_module = types.ModuleType("huggingface_hub.utils") + utils_module.disable_progress_bars = disable_progress_bars + hub_module.utils = utils_module + + with patch.dict( + sys.modules, + { + "huggingface_hub": hub_module, + "huggingface_hub.utils": utils_module, + }, + ), patch.dict(os.environ, {"HF_HUB_DISABLE_PROGRESS_BARS": "0"}, clear=True): + provider._suppress_model_download_progress() + + self.assertEqual(os.environ["HF_HUB_DISABLE_PROGRESS_BARS"], "0") + disable_progress_bars.assert_not_called() + + def test_model_download_progress_is_suppressed_only_while_loading_models(self) -> None: + provider = QwenMlxProvider() + provider._probe_duration_sec = lambda _: 0.0 + provider._plan_windows = lambda total_duration_sec, speech_plan=None: [] + model = FakeModel([]) + provider._load_backend = lambda: (lambda model_id: model) + + with patch.object(provider, "_suppress_model_download_progress") as suppress: + provider.transcribe(Path("demo.wav")) + provider.transcribe(Path("demo.wav")) + + self.assertEqual(suppress.call_count, 1) + def test_provider_emits_window_and_merge_steps(self) -> None: provider = QwenMlxProvider() provider._probe_duration_sec = lambda _: 140.0 From b9bce7be855d66f126dc3e01e6c51dc882a0ee70 Mon Sep 17 00:00:00 2001 From: hp Date: Mon, 25 May 2026 23:21:36 +0800 Subject: [PATCH 2/2] Address HF progress suppression review --- src/asr/providers/qwen_mlx.py | 12 ++++++------ 1 file changed, 6 insertions(+), 6 deletions(-) diff --git a/src/asr/providers/qwen_mlx.py b/src/asr/providers/qwen_mlx.py index 911200f..225bd60 100644 --- a/src/asr/providers/qwen_mlx.py +++ b/src/asr/providers/qwen_mlx.py @@ -592,14 +592,14 @@ def _ensure_models_loaded(self) -> None: def _suppress_model_download_progress(self) -> None: flag = os.environ.get("HF_HUB_DISABLE_PROGRESS_BARS") - if flag is None: - os.environ["HF_HUB_DISABLE_PROGRESS_BARS"] = "1" - explicitly_enabled = False - else: - explicitly_enabled = flag.strip().lower() in {"0", "false", "off", "no"} - if explicitly_enabled: + if ( + flag is not None + and flag.strip().lower() in {"0", "false", "off", "no"} + ): return + os.environ.setdefault("HF_HUB_DISABLE_PROGRESS_BARS", "1") + try: from huggingface_hub.utils import disable_progress_bars except ImportError: