From 38fc8227f306ec3ad07c2ad96afa88f44c70c108 Mon Sep 17 00:00:00 2001 From: imonlinux <39863321+imonlinux@users.noreply.github.com> Date: Sun, 14 Sep 2025 11:54:54 -0700 Subject: [PATCH] Fix watchdog misfire in mpv_player.py MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The current watchdog is a simple “N-seconds since play()” timer, so it can fire during legit playback (longer TTS, slower network). Convert it to a no-progress watchdog that only trips if mpv makes no progress for N seconds. --- linux_voice_assistant/mpv_player.py | 436 ++++++++++++++-------------- 1 file changed, 225 insertions(+), 211 deletions(-) diff --git a/linux_voice_assistant/mpv_player.py b/linux_voice_assistant/mpv_player.py index cf997e6..c2b67e1 100644 --- a/linux_voice_assistant/mpv_player.py +++ b/linux_voice_assistant/mpv_player.py @@ -1,278 +1,292 @@ -"""Media player using mpv in a subprocess. - -- Supports ALSA and PulseAudio -- Duck/unduck -- Robust URL handling (str | list/tuple | bytes) -- Backwards-compatible API: play(url, done_callback=None, stop_first=False), pause, resume, stop, set_volume -- Pulse-friendly defaults (44100 Hz stereo) and short network timeout -- Default watchdog = 8s (configurable), to avoid hangs if mpv fails to finish -- End-of-playback detection uses BOTH `eof-reached` and `idle-active` to finish immediately after short clips -- mpv log level can be controlled with env var LVA_MPV_MSG_LEVEL (e.g. "all=warn", "all=info") -""" - +# Copyright (c) 2025 +# mpv-based media player with PulseAudio/ALSA support and no-progress watchdog from __future__ import annotations import logging import os -from collections.abc import Callable, Sequence -from threading import Lock, Timer -from typing import Optional, Union +import time +from threading import Timer +from typing import Callable, Optional, Sequence, Union -from mpv import MPV +try: + from mpv import MPV +except Exception as e: # pragma: no cover + # Keep import error visible during service startup + raise _LOGGER = logging.getLogger(__name__) class MpvMediaPlayer: - def __init__(self, device: Optional[str] = None, watchdog_sec: float = 8.0) -> None: - # Bridge mpv logs into Python logging - self.player = MPV(video=False, terminal=False, log_handler=self._mpv_log) + """Thin wrapper around python-mpv suited for short TTS clips. - # Pulse-friendly defaults - try: - self.player['audio-samplerate'] = 44100 - self.player['audio-channels'] = 'stereo' - self.player['keep-open'] = 'no' - self.player['network-timeout'] = 7 - # Log level configurable via env; default to warn - msg_level = os.environ.get("LVA_MPV_MSG_LEVEL", "all=warn") - self.player['msg-level'] = msg_level - except Exception: - pass + Features: + - Supports PulseAudio and ALSA devices + - Accepts plain sink names (assumed Pulse): e.g. 'alsa_output.foo.bar' + - End-of-playback detection via 'idle-active' and 'eof-reached' + - No-progress watchdog: trips only if time-pos doesn't advance + - Optional duck/unduck helpers using mpv volume property + """ - # Normalize/select backend and device - ao = None - norm = None - - if device: - d = device.strip() - if d.startswith("alsa/"): - ao = "alsa"; norm = d - elif d.startswith("pulse/"): - ao = "pulse"; norm = d - elif d == "default": - try: - self.player["ao"] = "pulse"; norm = "pulse/default" - except Exception: - try: - self.player["ao"] = "alsa"; norm = "alsa/default" - except Exception: - _LOGGER.warning("Neither Pulse nor ALSA available for 'default'") - else: - # Assume Pulse sink name if no prefix - ao = "pulse"; norm = f"pulse/{d}" - - if ao: - try: - self.player["ao"] = ao - except Exception: - _LOGGER.warning("Requested ao=%s not available", ao) - - if norm: - try: - self.player["audio-device"] = norm - except Exception: - _LOGGER.warning("Failed to set audio-device=%s", norm) - - # State - self.is_playing: bool = False - self._done_callback: Optional[Callable[[], None]] = None - self._done_callback_lock = Lock() - self._pre_duck_volume: Optional[int] = None # stores 0..100 when ducked + def __init__( + self, + device: Optional[str] = None, + watchdog_sec: float = 8.0, + ) -> None: + self._done_cb: Optional[Callable[[], None]] = None self._watchdog: Optional[Timer] = None self._watchdog_sec: float = float(watchdog_sec) + self._last_progress: float = 0.0 + self._duck_prev_volume: Optional[float] = None + self._stopped: bool = False - # Playback end detection (both EOF and idle) - self.player.observe_property("eof-reached", self._on_eof) - self.player.observe_property("idle-active", self._on_idle_active) + # Decide backend and device + ao, audio_device = self._select_backend_and_device(device) + + # mpv msg level + msg_level = os.getenv("LVA_MPV_MSG_LEVEL", "all=warn") + + # Create player instance tuned for TTS + # NOTE: video disabled; keep-open=no so idle triggers quickly + self.player = MPV( + video=False, + ao=ao, + audio_device=audio_device if audio_device else None, + audio_samplerate="44100", + audio_channels="stereo", + keep_open="no", + msg_level=msg_level, + input_default_bindings=False, + input_vo_keyboard=False, + ytdl=False, + log_handler=self._mpv_log, + network_timeout=7, + ) + + # Bind property observers + self._bind_observers() # -------------------- public API -------------------- def play( self, - url: Union[str, Sequence[str]], + source: Union[str, Sequence[str]], done_callback: Optional[Callable[[], None]] = None, - stop_first: bool = False, ) -> None: - """Begin playback of a URL or local file. Replaces any existing playback. - Accepts a single URL (str) or a sequence of URLs; if a sequence is given, the first item is played. + """Play a single URL/path or a sequence of them. + Calls done_callback exactly once on clean EOF or on failure/stop. """ - if stop_first: - try: - self.stop() - except Exception: - _LOGGER.debug("stop_first=True: stop() raised, continuing", exc_info=True) - - with self._done_callback_lock: - self._done_callback = done_callback - - # Normalize url input - if isinstance(url, (list, tuple)): - if not url: - _LOGGER.error("mpv play() received empty URL list") - self._run_done_callback() - return - url = url[0] - if isinstance(url, bytes): - try: - url = url.decode("utf-8") - except Exception: - url = url.decode(errors="ignore") - if not isinstance(url, str): - _LOGGER.error("mpv play() expected str URL, got %r", type(url)) - self._run_done_callback() - return + self._stopped = False + self._done_cb = done_callback + self._last_progress = time.monotonic() # seed progress clock try: - self.player["mute"] = "no" - except Exception: - pass + # Clear any prior state + self.stop(silent=True) - self.is_playing = True - try: - self.player.play(url) + if isinstance(source, (list, tuple)): + if not source: + raise ValueError("source list is empty") + first, *rest = source + self.player.play(str(first)) + for item in rest: + # Append subsequent items to playlist + self.player.command("loadfile", str(item), "append-play") + else: + self.player.play(str(source)) + + # Arm the no-progress watchdog self._arm_watchdog() - except Exception: - self.is_playing = False - _LOGGER.exception("mpv failed to play %r", url) - self._run_done_callback() - def pause(self) -> None: - try: - self.player.pause = True except Exception: - _LOGGER.exception("mpv pause() failed") + _LOGGER.exception("mpv failed to play %r", source) + self._finish() - def resume(self) -> None: + def stop(self, silent: bool = False) -> None: + """Stop playback immediately.""" try: - self.player.pause = False - except Exception: - _LOGGER.exception("mpv resume() failed") - - def stop(self) -> None: - """Stop playback immediately and clear playing state; run done callback.""" - try: - try: - self.player.command('stop') - except Exception: - self.player.command('loadfile', 'null://', 'replace') - finally: + self._stopped = True self._cancel_watchdog() - was_playing = self.is_playing - self.is_playing = False - if was_playing: - self._run_done_callback() - - def set_volume(self, *args, **kwargs) -> None: - """Set volume 0..100. Accepts positional or keyword 'volume' (backwards-compatible).""" - vol_arg = args[0] if args else kwargs.get("volume") - if vol_arg is None: - _LOGGER.error("set_volume() requires an integer (0..100)") - return - - try: - vol = max(0, min(100, int(vol_arg))) + # 'stop' stops current file; 'playlist-clear' ensures nothing pending + self.player.command("stop") + self.player.command("playlist-clear") except Exception: - _LOGGER.exception("set_volume(): invalid value %r", vol_arg) - return + if not silent: + _LOGGER.exception("mpv stop() failed") + finally: + # Ensure completion callback is fired when explicitly stopping + if not silent: + self._finish() + def set_volume(self, percent: float) -> None: + """Set mpv volume 0-100.""" try: - self.player.volume = vol + p = max(0.0, min(100.0, float(percent))) + self.player.volume = p except Exception: - _LOGGER.exception("mpv set_volume(%s) failed", vol) - - def duck(self, target_percent: int = 20) -> None: - if self._pre_duck_volume is not None: - return # already ducked + _LOGGER.exception("mpv set_volume(%s) failed", percent) + def get_volume(self) -> float: try: - current = int(round(float(self.player.volume))) + v = float(self.player.volume) except Exception: - current = 100 + _LOGGER.exception("mpv get_volume() failed") + v = 0.0 + return v - self._pre_duck_volume = max(0, min(100, current)) + # ---- simple duck/unduck helpers (independent of Pulse role ducking) ---- + def duck(self, to_percent: float = 25.0) -> None: try: - self.player.volume = max(0, min(100, int(target_percent))) + if self._duck_prev_volume is None: + self._duck_prev_volume = self.get_volume() + self.set_volume(to_percent) except Exception: - _LOGGER.exception("duck(): failed to set duck volume") + _LOGGER.exception("duck() failed") def unduck(self) -> None: - if self._pre_duck_volume is None: - return - try: - self.player.volume = self._pre_duck_volume + if self._duck_prev_volume is not None: + self.set_volume(self._duck_prev_volume) except Exception: - _LOGGER.exception("unduck(): failed to restore volume") + _LOGGER.exception("unduck() failed") finally: - self._pre_duck_volume = None + self._duck_prev_volume = None - # -------------------- callbacks & watchdog -------------------- - - def _on_eof(self, _name: str, reached: bool) -> None: - if not reached: - return - self._cancel_watchdog() - self.is_playing = False - self._run_done_callback() - - def _on_idle_active(self, _name: str, active: bool) -> None: - # When playback ends, mpv enters idle; treat that as completion. - if not self.is_playing: - return - if bool(active): - _LOGGER.debug("mpv became idle; treating as end-of-playback") + def close(self) -> None: + try: self._cancel_watchdog() - self.is_playing = False - self._run_done_callback() + self.player.terminate() + except Exception: + _LOGGER.exception("mpv terminate failed") + + # -------------------- internal helpers -------------------- + + def _bind_observers(self) -> None: + # Idle means no file is playing; ideal for short TTS EOF detection + @self.player.property_observer("idle-active") + def _idle_active(_name, value): + try: + self._on_idle(value) + except Exception: + _LOGGER.exception("idle-active observer failed") + + # Some builds also toggle eof-reached at end of a file + @self.player.property_observer("eof-reached") + def _eof(_name, value): + try: + if value: + self._on_eof() + except Exception: + _LOGGER.exception("eof-reached observer failed") + + # Progress while playing; used by the no-progress watchdog + @self.player.property_observer("time-pos") + def _timepos(_name, value): + try: + self._on_timepos(value) + except Exception: + _LOGGER.exception("time-pos observer failed") + + def _on_idle(self, value: bool) -> None: + if value: + _LOGGER.debug("mpv became idle; treating as end-of-playback") + self._finish() + + def _on_eof(self) -> None: + _LOGGER.debug("mpv reported eof-reached") + self._finish() + + def _on_timepos(self, value: Optional[float]) -> None: + # Called frequently during active playback; update progress clock + if value is not None: + self._last_progress = time.monotonic() + # keep watchdog fresh during active playback + self._arm_watchdog() + + def _finish(self) -> None: + # Stop watchdog and call done callback once + self._cancel_watchdog() + cb, self._done_cb = self._done_cb, None + if cb is not None: + try: + cb() + except Exception: + _LOGGER.exception("done_callback raised") + + # -------------------- watchdog (no-progress) -------------------- def _arm_watchdog(self) -> None: self._cancel_watchdog() if self._watchdog_sec <= 0: return - self._watchdog = Timer(self._watchdog_sec, self._watchdog_trip) + # seed if never set + if self._last_progress == 0.0: + self._last_progress = time.monotonic() + + def _trip(): + try: + stalled_for = time.monotonic() - self._last_progress + if stalled_for >= self._watchdog_sec and not self._stopped: + _LOGGER.warning( + "mpv watchdog (no progress) fired after %.1fs; stopping playback", + self._watchdog_sec, + ) + self.stop(silent=False) + else: + # progress happened; keep monitoring + self._arm_watchdog() + except Exception: + _LOGGER.exception("watchdog trip failed") + + self._watchdog = Timer(self._watchdog_sec, _trip) self._watchdog.daemon = True self._watchdog.start() def _cancel_watchdog(self) -> None: - if self._watchdog is not None: + t = self._watchdog + self._watchdog = None + if t is not None: try: - self._watchdog.cancel() + t.cancel() except Exception: pass - self._watchdog = None - def _watchdog_trip(self) -> None: - if self.is_playing: - _LOGGER.warning("mpv watchdog fired after %.1fs; stopping playback", self._watchdog_sec) - try: - self.player.command('stop') - except Exception: - pass - self.is_playing = False - self._run_done_callback() + # -------------------- backend/device selection -------------------- - def _run_done_callback(self) -> None: - cb: Optional[Callable[[], None]] = None - with self._done_callback_lock: - cb = self._done_callback - self._done_callback = None + @staticmethod + def _select_backend_and_device(device: Optional[str]) -> tuple[str, Optional[str]]: + """Return (ao, audio_device) based on a friendly device string. - if cb is not None: - try: - cb() - except Exception: - _LOGGER.exception("Unexpected error running done callback") + Accepted forms: + - None or 'default' -> (ao='pulse', device=None) [Pulse default sink] + - 'pulse/' -> (ao='pulse', device='pulse/') + - '' -> (ao='pulse', device='pulse/') + - 'alsa/' -> (ao='alsa', device='alsa/') + """ + if not device or device == "default": + return "pulse", None + + d = str(device).strip() + if d.startswith("pulse/"): + return "pulse", d + if d.startswith("alsa/"): + return "alsa", d + + # Unprefixed: assume Pulse sink name + return "pulse", f"pulse/{d}" # -------------------- mpv log bridge -------------------- - def _mpv_log(self, level: str, prefix: str, text: str) -> None: - msg = f"mpv[{level}] {prefix}: {text}".rstrip() - if level in ("fatal", "error"): - _LOGGER.error(msg) - elif level in ("warn", "warning"): - _LOGGER.warning(msg) - elif level in ("info",): - _LOGGER.info(msg) - else: - _LOGGER.debug(msg) + + def _mpv_log(self, level: str, component: str, message: str) -> None: + # Map mpv levels to Python logging + lvl = (level or "").lower() + log = _LOGGER.debug + if lvl in ("fatal", "error"): + log = _LOGGER.error + elif lvl in ("warn", "warning"): + log = _LOGGER.warning + elif lvl in ("info",): + log = _LOGGER.info + # keep mpv chatter short; component can be verbose + log("mpv[%s]: %s", component, message)