diff --git a/services/media.py b/services/media.py index 22c9dd7..418c4d4 100644 --- a/services/media.py +++ b/services/media.py @@ -20,6 +20,7 @@ import os import sys +import time import queue import threading import subprocess @@ -350,6 +351,9 @@ def spawn_stream(track: dict) -> AudioStream: # and long enough to cover the gaps yt-dlp leaves when YouTube throttles a # download after its initial burst. READ_AHEAD_SECONDS = 5.0 +# Longest to wait for the first audio before starting playback. yt-dlp needs +# seconds to resolve and connect; beyond this something is genuinely wrong. +PRIME_TIMEOUT_SECONDS = 30.0 class BufferedAudioSource(discord.AudioSource): @@ -415,13 +419,41 @@ def _fill(self) -> None: pass def read(self) -> bytes: - if self._stop.is_set(): - return b"" - try: - return self._queue.get(timeout=1.0) - except queue.Empty: - # The producer is wedged; ending is better than stalling playback. - return b"" + """ + The next frame, or ``b""`` when the source is finished. + + An empty buffer is NOT the end. yt-dlp needs seconds to produce its + first byte, so returning ``b""`` while the producer is still working + would tell discord.py the track had ended and stop it immediately. Only + the sentinel the producer puts in on exit, or a producer that has died, + means finished. + """ + while not self._stop.is_set(): + try: + return self._queue.get(timeout=0.5) + except queue.Empty: + if not self._thread.is_alive(): + return b"" # producer gone without leaving a sentinel + continue + return b"" + + def prime(self, *, timeout: float = PRIME_TIMEOUT_SECONDS) -> bool: + """ + Block until there is audio ready, or the source ends. Never on the loop. + + discord.py's player starts its clock *before* its first read, so + beginning playback against an empty buffer leaves it seconds behind + schedule — and it catches up by bursting frames, which is the exact + artefact this class exists to prevent. Filling first means the clock + starts when audio is genuinely ready. + """ + deadline = time.monotonic() + timeout + while time.monotonic() < deadline: + if self._stop.is_set() or self.buffered_frames or not self._thread.is_alive(): + return self.buffered_frames > 0 + time.sleep(0.05) + log.warning("Timed out waiting %.0fs for audio to buffer", timeout) + return False def cleanup(self) -> None: """Stop the reader thread and tear down the wrapped source.""" @@ -463,3 +495,15 @@ def make_pipe_source(stdin, *, volume: float = 0.5, ffmpeg_filter: str = "", return discord.PCMVolumeTransformer( BufferedAudioSource(source), volume=volume, ) + + +def prime_source(source) -> bool: + """ + Wait for a source from :func:`make_pipe_source` to have audio ready. + + Blocks, so call it from an executor. Returns whether anything buffered — + ``False`` means the track produced no audio and the caller should treat it + as a failed load rather than start playing silence. + """ + inner = getattr(source, "original", None) + return inner.prime() if isinstance(inner, BufferedAudioSource) else True diff --git a/tests/test_buffered_source.py b/tests/test_buffered_source.py index 60199c1..cb16b4e 100644 --- a/tests/test_buffered_source.py +++ b/tests/test_buffered_source.py @@ -252,3 +252,66 @@ def test_volume_can_still_be_changed_mid_playback(tmp_path): assert source.volume == pytest.approx(0.9) finally: source.cleanup() + + +# -- an empty buffer is not the end ------------------------------------ + +def test_a_slow_first_byte_is_not_mistaken_for_the_end(): + """ + The regression this guards: read() used to give up after a second and + return b"", which discord.py reads as "the track finished" and stops + playback. yt-dlp routinely takes 3-8s to produce its first byte, so every + track would have ended instantly. + """ + inner = FakeSource(frames=10, stall_at=0, stall_for=2.0) + source = BufferedAudioSource(inner, seconds=1.0) + try: + started = time.monotonic() + first = source.read() + waited = time.monotonic() - started + assert first, f"gave up after {waited:.1f}s instead of waiting for audio" + assert waited > 1.0, "the test did not actually exercise a slow start" + finally: + source.cleanup() + + +def test_prime_waits_for_audio_then_reports_ready(): + """ + discord.py starts its clock before its first read, so playback must not + begin against an empty buffer or the player is instantly behind schedule. + """ + inner = FakeSource(frames=50, stall_at=0, stall_for=1.0) + source = BufferedAudioSource(inner, seconds=2.0) + try: + assert source.prime(timeout=10) is True + assert source.buffered_frames > 0 + finally: + source.cleanup() + + +def test_prime_gives_up_on_a_source_that_never_produces(): + class Silent(discord.AudioSource): + def read(self): + time.sleep(30) + return b"" + + def cleanup(self): + pass + + source = BufferedAudioSource(Silent(), seconds=1.0) + try: + started = time.monotonic() + assert source.prime(timeout=1.0) is False + assert time.monotonic() - started < 3.0, "prime overran its timeout" + finally: + source.cleanup() + + +def test_prime_returns_promptly_when_the_source_is_already_finished(): + source = BufferedAudioSource(FakeSource(frames=0), seconds=1.0) + try: + started = time.monotonic() + source.prime(timeout=5) + assert time.monotonic() - started < 2.0 + finally: + source.cleanup() diff --git a/utils/player.py b/utils/player.py index 268debd..dd4b309 100644 --- a/utils/player.py +++ b/utils/player.py @@ -340,6 +340,10 @@ async def _player_loop(self) -> None: stream.stdout, volume=self.volume, ffmpeg_filter=self.effect_filter, seek_seconds=seek_to, ) + # discord.py starts its playback clock before its first read, + # so it must not begin against an empty buffer — it would be + # seconds behind immediately and burst frames to catch up. + await self.bot.loop.run_in_executor(None, media.prime_source, source) vc.play(source, after=self._after_play) # Backdate the clock by the seek so a *second* effect change # resumes from the real position, not from the respawn point.