Fix watchdog misfire in mpv_player.py

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.
This commit is contained in:
imonlinux
2025-09-14 11:54:54 -07:00
committed by GitHub
parent ceb64f89a1
commit 38fc8227f3
+225 -211
View File
@@ -1,278 +1,292 @@
"""Media player using mpv in a subprocess. # Copyright (c) 2025
# mpv-based media player with PulseAudio/ALSA support and no-progress watchdog
- 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")
"""
from __future__ import annotations from __future__ import annotations
import logging import logging
import os import os
from collections.abc import Callable, Sequence import time
from threading import Lock, Timer from threading import Timer
from typing import Optional, Union 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__) _LOGGER = logging.getLogger(__name__)
class MpvMediaPlayer: class MpvMediaPlayer:
def __init__(self, device: Optional[str] = None, watchdog_sec: float = 8.0) -> None: """Thin wrapper around python-mpv suited for short TTS clips.
# Bridge mpv logs into Python logging
self.player = MPV(video=False, terminal=False, log_handler=self._mpv_log)
# Pulse-friendly defaults Features:
try: - Supports PulseAudio and ALSA devices
self.player['audio-samplerate'] = 44100 - Accepts plain sink names (assumed Pulse): e.g. 'alsa_output.foo.bar'
self.player['audio-channels'] = 'stereo' - End-of-playback detection via 'idle-active' and 'eof-reached'
self.player['keep-open'] = 'no' - No-progress watchdog: trips only if time-pos doesn't advance
self.player['network-timeout'] = 7 - Optional duck/unduck helpers using mpv volume property
# 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
# Normalize/select backend and device def __init__(
ao = None self,
norm = None device: Optional[str] = None,
watchdog_sec: float = 8.0,
if device: ) -> None:
d = device.strip() self._done_cb: Optional[Callable[[], None]] = None
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
self._watchdog: Optional[Timer] = None self._watchdog: Optional[Timer] = None
self._watchdog_sec: float = float(watchdog_sec) 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) # Decide backend and device
self.player.observe_property("eof-reached", self._on_eof) ao, audio_device = self._select_backend_and_device(device)
self.player.observe_property("idle-active", self._on_idle_active)
# 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 -------------------- # -------------------- public API --------------------
def play( def play(
self, self,
url: Union[str, Sequence[str]], source: Union[str, Sequence[str]],
done_callback: Optional[Callable[[], None]] = None, done_callback: Optional[Callable[[], None]] = None,
stop_first: bool = False,
) -> None: ) -> None:
"""Begin playback of a URL or local file. Replaces any existing playback. """Play a single URL/path or a sequence of them.
Accepts a single URL (str) or a sequence of URLs; if a sequence is given, the first item is played. Calls done_callback exactly once on clean EOF or on failure/stop.
""" """
if stop_first: self._stopped = False
try: self._done_cb = done_callback
self.stop() self._last_progress = time.monotonic() # seed progress clock
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
try: try:
self.player["mute"] = "no" # Clear any prior state
except Exception: self.stop(silent=True)
pass
self.is_playing = True if isinstance(source, (list, tuple)):
try: if not source:
self.player.play(url) 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() 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: 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: try:
self.player.pause = False self._stopped = True
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._cancel_watchdog() self._cancel_watchdog()
was_playing = self.is_playing # 'stop' stops current file; 'playlist-clear' ensures nothing pending
self.is_playing = False self.player.command("stop")
if was_playing: self.player.command("playlist-clear")
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)))
except Exception: except Exception:
_LOGGER.exception("set_volume(): invalid value %r", vol_arg) if not silent:
return _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: try:
self.player.volume = vol p = max(0.0, min(100.0, float(percent)))
self.player.volume = p
except Exception: except Exception:
_LOGGER.exception("mpv set_volume(%s) failed", vol) _LOGGER.exception("mpv set_volume(%s) failed", percent)
def duck(self, target_percent: int = 20) -> None:
if self._pre_duck_volume is not None:
return # already ducked
def get_volume(self) -> float:
try: try:
current = int(round(float(self.player.volume))) v = float(self.player.volume)
except Exception: 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: 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: except Exception:
_LOGGER.exception("duck(): failed to set duck volume") _LOGGER.exception("duck() failed")
def unduck(self) -> None: def unduck(self) -> None:
if self._pre_duck_volume is None:
return
try: 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: except Exception:
_LOGGER.exception("unduck(): failed to restore volume") _LOGGER.exception("unduck() failed")
finally: finally:
self._pre_duck_volume = None self._duck_prev_volume = None
# -------------------- callbacks & watchdog -------------------- def close(self) -> None:
try:
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")
self._cancel_watchdog() self._cancel_watchdog()
self.is_playing = False self.player.terminate()
self._run_done_callback() 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: def _arm_watchdog(self) -> None:
self._cancel_watchdog() self._cancel_watchdog()
if self._watchdog_sec <= 0: if self._watchdog_sec <= 0:
return 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.daemon = True
self._watchdog.start() self._watchdog.start()
def _cancel_watchdog(self) -> None: def _cancel_watchdog(self) -> None:
if self._watchdog is not None: t = self._watchdog
self._watchdog = None
if t is not None:
try: try:
self._watchdog.cancel() t.cancel()
except Exception: except Exception:
pass pass
self._watchdog = None
def _watchdog_trip(self) -> None: # -------------------- backend/device selection --------------------
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()
def _run_done_callback(self) -> None: @staticmethod
cb: Optional[Callable[[], None]] = None def _select_backend_and_device(device: Optional[str]) -> tuple[str, Optional[str]]:
with self._done_callback_lock: """Return (ao, audio_device) based on a friendly device string.
cb = self._done_callback
self._done_callback = None
if cb is not None: Accepted forms:
try: - None or 'default' -> (ao='pulse', device=None) [Pulse default sink]
cb() - 'pulse/<sink-name>' -> (ao='pulse', device='pulse/<sink-name>')
except Exception: - '<sink-name>' -> (ao='pulse', device='pulse/<sink-name>')
_LOGGER.exception("Unexpected error running done callback") - 'alsa/<hw-spec>' -> (ao='alsa', device='alsa/<hw-spec>')
"""
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 -------------------- # -------------------- mpv log bridge --------------------
def _mpv_log(self, level: str, prefix: str, text: str) -> None:
msg = f"mpv[{level}] {prefix}: {text}".rstrip() def _mpv_log(self, level: str, component: str, message: str) -> None:
if level in ("fatal", "error"): # Map mpv levels to Python logging
_LOGGER.error(msg) lvl = (level or "").lower()
elif level in ("warn", "warning"): log = _LOGGER.debug
_LOGGER.warning(msg) if lvl in ("fatal", "error"):
elif level in ("info",): log = _LOGGER.error
_LOGGER.info(msg) elif lvl in ("warn", "warning"):
else: log = _LOGGER.warning
_LOGGER.debug(msg) elif lvl in ("info",):
log = _LOGGER.info
# keep mpv chatter short; component can be verbose
log("mpv[%s]: %s", component, message)