From 933e2341fd53bad40153368df304b9127fad1ff4 Mon Sep 17 00:00:00 2001 From: Michael Gerbush <405526+msgerbush@users.noreply.github.com> Date: Tue, 12 May 2026 11:29:20 -0400 Subject: [PATCH 1/5] Back off failed playback commands --- jukebox/domain/entities/__init__.py | 3 +- jukebox/domain/entities/playback_session.py | 16 ++ jukebox/domain/use_cases/handle_tag_event.py | 133 +++++++++++++--- .../domain/use_cases/test_handle_tag_event.py | 149 ++++++++++++++---- 4 files changed, 250 insertions(+), 51 deletions(-) diff --git a/jukebox/domain/entities/__init__.py b/jukebox/domain/entities/__init__.py index ab41acaa..4ca76fbf 100644 --- a/jukebox/domain/entities/__init__.py +++ b/jukebox/domain/entities/__init__.py @@ -3,13 +3,14 @@ from .disc import Disc, DiscMetadata, DiscOption from .library import Library from .playback_action import PlaybackAction -from .playback_session import PlaybackSession +from .playback_session import PlaybackCommandRetry, PlaybackSession from .tag_event import TagEvent __all__ = [ "CurrentTagAction", "CurrentTagStatus", "PlaybackAction", + "PlaybackCommandRetry", "PlaybackSession", "TagEvent", "Library", diff --git a/jukebox/domain/entities/playback_session.py b/jukebox/domain/entities/playback_session.py index d6f7ee43..3c1dee49 100644 --- a/jukebox/domain/entities/playback_session.py +++ b/jukebox/domain/entities/playback_session.py @@ -1,5 +1,18 @@ from pydantic import BaseModel +from .playback_action import PlaybackAction + + +class PlaybackCommandRetry(BaseModel): + """Tracks retry timing for a failed playback command.""" + + action: PlaybackAction + command_key: str + first_failed_at: float + last_failed_at: float + attempt_count: int + next_retry_at: float + class PlaybackSession(BaseModel): """Tracks the current logical playback and physical reader states.""" @@ -15,3 +28,6 @@ class PlaybackSession(BaseModel): # Timestamp last_event_timestamp: float | None = None + + # Playback command retry state + playback_command_retry: PlaybackCommandRetry | None = None diff --git a/jukebox/domain/use_cases/handle_tag_event.py b/jukebox/domain/use_cases/handle_tag_event.py index b6db6954..2b65d2a3 100644 --- a/jukebox/domain/use_cases/handle_tag_event.py +++ b/jukebox/domain/use_cases/handle_tag_event.py @@ -1,7 +1,7 @@ import logging -from contextlib import contextmanager +from collections.abc import Callable -from jukebox.domain.entities import CurrentTagAction, PlaybackAction, PlaybackSession, TagEvent +from jukebox.domain.entities import CurrentTagAction, PlaybackAction, PlaybackCommandRetry, PlaybackSession, TagEvent from jukebox.domain.errors import PlaybackError from jukebox.domain.ports import PlayerPort from jukebox.domain.repositories import CurrentTagRepository, LibraryRepository @@ -9,6 +9,7 @@ from jukebox.domain.use_cases.determine_current_tag_action import DetermineCurrentTagAction LOGGER = logging.getLogger("jukebox") +PLAYBACK_RETRY_DELAYS_SECONDS = (0.5, 1.0, 2.0, 5.0, 10.0, 30.0) class HandleTagEvent: @@ -21,16 +22,21 @@ def __init__( current_tag_repository: CurrentTagRepository, determine_action: DetermineAction, determine_current_tag_action: DetermineCurrentTagAction, + retry_delays_seconds: tuple[float, ...] = PLAYBACK_RETRY_DELAYS_SECONDS, ): self.player = player self.library = library self.current_tag_repository = current_tag_repository self.determine_action = determine_action self.determine_current_tag_action = determine_current_tag_action + if not retry_delays_seconds: + raise ValueError("retry_delays_seconds must not be empty") + self.retry_delays_seconds = retry_delays_seconds def execute(self, tag_event: TagEvent, session: PlaybackSession) -> PlaybackSession: self._apply_current_tag_action_best_effort(tag_event, session) action = self.determine_action.execute(tag_event, session) + self._clear_stale_playback_retry(action, session) LOGGER.debug( "%s \t\t %s | %s | %s | %s", @@ -47,8 +53,14 @@ def execute(self, tag_event: TagEvent, session: PlaybackSession) -> PlaybackSess session.playing_tag_removed_at = None case PlaybackAction.RESUME: - with suppress_playback_error("Playback operation `RESUME` failed; stopping session update"): - self.player.resume() + if self._run_playback_command( + PlaybackAction.RESUME, + "resume", + tag_event, + session, + "Playback operation `RESUME` failed; stopping session update", + self.player.resume, + ): session.paused_at = None session.playing_tag_removed_at = None @@ -58,14 +70,19 @@ def execute(self, tag_event: TagEvent, session: PlaybackSession) -> PlaybackSess disc = self.library.get_disc(tag_event.tag_id) if tag_event.tag_id is not None else None if disc is not None: LOGGER.info("Found corresponding disc: %s", disc) - with suppress_playback_error( - f"Playback operation `PLAY` failed for tag_id='{tag_event.tag_id}'; stopping session update" + if self._run_playback_command( + PlaybackAction.PLAY, + f"play:{tag_event.tag_id}", + tag_event, + session, + f"Playback operation `PLAY` failed for tag_id='{tag_event.tag_id}'; stopping session update", + lambda: self.player.play(disc.uri, disc.option.shuffle), ): - self.player.play(disc.uri, disc.option.shuffle) session.playing_tag = tag_event.tag_id session.paused_at = None session.playing_tag_removed_at = None else: + session.playback_command_retry = None LOGGER.warning("No disc found for UID: %s", tag_event.tag_id) case PlaybackAction.WAITING: @@ -76,16 +93,28 @@ def execute(self, tag_event: TagEvent, session: PlaybackSession) -> PlaybackSess LOGGER.debug("Grace period: %.3fs / %gs", grace_period_elapsed, self.determine_action.pause_delay) case PlaybackAction.PAUSE: - with suppress_playback_error("Playback operation `PAUSE` failed; continuing session update"): - self.player.pause() - session.paused_at = tag_event.timestamp + if self._run_playback_command( + PlaybackAction.PAUSE, + "pause", + tag_event, + session, + "Playback operation `PAUSE` failed; stopping session update", + self.player.pause, + ): + session.paused_at = tag_event.timestamp case PlaybackAction.STOP: - with suppress_playback_error("Playback operation `STOP` failed; continuing session update"): - self.player.stop() - session.playing_tag = None - session.paused_at = None - session.playing_tag_removed_at = None + if self._run_playback_command( + PlaybackAction.STOP, + "stop", + tag_event, + session, + "Playback operation `STOP` failed; stopping session update", + self.player.stop, + ): + session.playing_tag = None + session.paused_at = None + session.playing_tag_removed_at = None case PlaybackAction.IDLE: pass @@ -136,10 +165,72 @@ def _apply_current_tag_action( case CurrentTagAction.KEEP: pass # No state changed + def _run_playback_command( + self, + action: PlaybackAction, + command_key: str, + tag_event: TagEvent, + session: PlaybackSession, + error_message: str, + command: Callable[[], None], + ) -> bool: + retry = session.playback_command_retry + if ( + retry is not None + and retry.action == action + and retry.command_key == command_key + and tag_event.timestamp < retry.next_retry_at + ): + LOGGER.debug( + "Skipping playback operation `%s` until retry time %.3f", + action.value.upper(), + retry.next_retry_at, + ) + return False + + try: + command() + except PlaybackError: + retry = self._record_playback_command_failure(action, command_key, tag_event, session) + LOGGER.warning("%s; retrying in %.3fs", error_message, retry.next_retry_at - tag_event.timestamp) + return False + + session.playback_command_retry = None + return True -@contextmanager -def suppress_playback_error(msg: str): - try: - yield - except PlaybackError: - LOGGER.warning(msg) + def _record_playback_command_failure( + self, + action: PlaybackAction, + command_key: str, + tag_event: TagEvent, + session: PlaybackSession, + ) -> PlaybackCommandRetry: + existing_retry = session.playback_command_retry + if existing_retry is None or existing_retry.action != action or existing_retry.command_key != command_key: + attempt_count = 1 + first_failed_at = tag_event.timestamp + else: + attempt_count = existing_retry.attempt_count + 1 + first_failed_at = existing_retry.first_failed_at + + retry_delay = self._retry_delay_for_attempt(attempt_count) + retry = PlaybackCommandRetry( + action=action, + command_key=command_key, + first_failed_at=first_failed_at, + last_failed_at=tag_event.timestamp, + attempt_count=attempt_count, + next_retry_at=tag_event.timestamp + retry_delay, + ) + session.playback_command_retry = retry + return retry + + def _retry_delay_for_attempt(self, attempt_count: int) -> float: + delay_index = min(attempt_count - 1, len(self.retry_delays_seconds) - 1) + return self.retry_delays_seconds[delay_index] + + @staticmethod + def _clear_stale_playback_retry(action: PlaybackAction, session: PlaybackSession) -> None: + retry = session.playback_command_retry + if retry is not None and retry.action != action: + session.playback_command_retry = None diff --git a/tests/jukebox/domain/use_cases/test_handle_tag_event.py b/tests/jukebox/domain/use_cases/test_handle_tag_event.py index b75a9215..6ab73b9b 100644 --- a/tests/jukebox/domain/use_cases/test_handle_tag_event.py +++ b/tests/jukebox/domain/use_cases/test_handle_tag_event.py @@ -2,11 +2,19 @@ import pytest -from jukebox.domain.entities import CurrentTagAction, Disc, DiscMetadata, DiscOption, PlaybackSession, TagEvent +from jukebox.domain.entities import ( + CurrentTagAction, + Disc, + DiscMetadata, + DiscOption, + PlaybackAction, + PlaybackSession, + TagEvent, +) from jukebox.domain.errors import PlaybackError from jukebox.domain.use_cases.determine_action import DetermineAction from jukebox.domain.use_cases.determine_current_tag_action import DetermineCurrentTagAction -from jukebox.domain.use_cases.handle_tag_event import HandleTagEvent, suppress_playback_error +from jukebox.domain.use_cases.handle_tag_event import HandleTagEvent @pytest.fixture @@ -462,6 +470,21 @@ def test_handle_play_action_does_not_update_session_when_player_raises(handle_ta mock_player.play.assert_called_once() assert new_session.playing_tag is None + assert new_session.playback_command_retry is not None + assert new_session.playback_command_retry.action == PlaybackAction.PLAY + assert new_session.playback_command_retry.command_key == "play:test-tag" + + +def test_handle_play_failure_does_not_throttle_different_tag(handle_tag_event, mock_player): + mock_player.play.side_effect = [PlaybackError("bad uri"), None] + session = PlaybackSession() + + session = handle_tag_event.execute(TagEvent(tag_id="tag-a", timestamp=100.0), session) + session = handle_tag_event.execute(TagEvent(tag_id="tag-b", timestamp=100.2), session) + + assert mock_player.play.call_count == 2 + assert session.playing_tag == "tag-b" + assert session.playback_command_retry is None def test_handle_resume_action_does_not_update_session_when_player_raises(handle_tag_event, mock_player): @@ -475,9 +498,12 @@ def test_handle_resume_action_does_not_update_session_when_player_raises(handle_ mock_player.resume.assert_called_once() assert new_session.paused_at == 60.0 + assert new_session.playback_command_retry is not None + assert new_session.playback_command_retry.action == PlaybackAction.RESUME + assert new_session.playback_command_retry.command_key == "resume" -def test_handle_pause_action_updates_session_even_when_player_raises(handle_tag_event, mock_player): +def test_handle_pause_action_does_not_update_session_when_player_raises(handle_tag_event, mock_player): mock_player.pause.side_effect = PlaybackError("cannot pause") session = PlaybackSession() session.playing_tag = "test-tag" @@ -487,10 +513,84 @@ def test_handle_pause_action_updates_session_even_when_player_raises(handle_tag_ new_session = handle_tag_event.execute(tag_event, session) mock_player.pause.assert_called_once() - assert new_session.paused_at == 100.0 + assert new_session.paused_at is None + assert new_session.playing_tag == "test-tag" + assert new_session.playing_tag_removed_at == 96.9 + assert new_session.playback_command_retry is not None + assert new_session.playback_command_retry.action == PlaybackAction.PAUSE + assert new_session.playback_command_retry.command_key == "pause" + assert new_session.playback_command_retry.attempt_count == 1 + assert new_session.playback_command_retry.next_retry_at == pytest.approx(100.5) + + +def test_handle_pause_failure_does_not_retry_before_backoff_expires(handle_tag_event, mock_player): + mock_player.pause.side_effect = PlaybackError("cannot pause") + session = PlaybackSession(playing_tag="test-tag", playing_tag_removed_at=96.9) + + session = handle_tag_event.execute(TagEvent(tag_id=None, timestamp=100.0), session) + session = handle_tag_event.execute(TagEvent(tag_id=None, timestamp=100.2), session) + + mock_player.pause.assert_called_once() + assert session.paused_at is None + assert session.playback_command_retry is not None + assert session.playback_command_retry.attempt_count == 1 + + +def test_handle_pause_failure_retries_after_backoff_and_updates_session_on_success(handle_tag_event, mock_player): + mock_player.pause.side_effect = [PlaybackError("cannot pause"), None] + session = PlaybackSession(playing_tag="test-tag", playing_tag_removed_at=96.9) + + session = handle_tag_event.execute(TagEvent(tag_id=None, timestamp=100.0), session) + session = handle_tag_event.execute(TagEvent(tag_id=None, timestamp=100.5), session) + + assert mock_player.pause.call_count == 2 + assert session.paused_at == 100.5 + assert session.playback_command_retry is None + + +def test_handle_pause_failure_uses_next_backoff_after_retry_fails(handle_tag_event, mock_player): + mock_player.pause.side_effect = PlaybackError("cannot pause") + session = PlaybackSession(playing_tag="test-tag", playing_tag_removed_at=96.9) + + session = handle_tag_event.execute(TagEvent(tag_id=None, timestamp=100.0), session) + session = handle_tag_event.execute(TagEvent(tag_id=None, timestamp=100.5), session) + + assert mock_player.pause.call_count == 2 + assert session.playback_command_retry is not None + assert session.playback_command_retry.attempt_count == 2 + assert session.playback_command_retry.next_retry_at == pytest.approx(101.5) + + +def test_persistent_pause_failure_keeps_retrying_pause_after_pause_duration(handle_tag_event, mock_player): + mock_player.pause.side_effect = PlaybackError("cannot pause") + session = PlaybackSession(playing_tag="test-tag", playing_tag_removed_at=96.9) + + session = handle_tag_event.execute(TagEvent(tag_id=None, timestamp=100.0), session) + session = handle_tag_event.execute(TagEvent(tag_id=None, timestamp=100.5), session) + session = handle_tag_event.execute(TagEvent(tag_id=None, timestamp=1000.0), session) + + assert mock_player.pause.call_count == 3 + mock_player.stop.assert_not_called() + assert session.paused_at is None + assert session.playback_command_retry is not None + assert session.playback_command_retry.action == PlaybackAction.PAUSE + assert session.playback_command_retry.attempt_count == 3 + assert session.playback_command_retry.next_retry_at == pytest.approx(1002.0) + + +def test_handle_pause_failure_clears_retry_when_action_changes(handle_tag_event, mock_player): + mock_player.pause.side_effect = PlaybackError("cannot pause") + session = PlaybackSession(playing_tag="test-tag", playing_tag_removed_at=96.9) + + session = handle_tag_event.execute(TagEvent(tag_id=None, timestamp=100.0), session) + session = handle_tag_event.execute(TagEvent(tag_id="test-tag", timestamp=100.2), session) + + mock_player.pause.assert_called_once() + assert session.playback_command_retry is None + assert session.playing_tag_removed_at is None -def test_handle_stop_action_updates_session_even_when_player_raises(handle_tag_event, mock_player): +def test_handle_stop_action_does_not_update_session_when_player_raises(handle_tag_event, mock_player): mock_player.stop.side_effect = PlaybackError("cannot stop") session = PlaybackSession() session.playing_tag = "test-tag" @@ -500,31 +600,22 @@ def test_handle_stop_action_updates_session_even_when_player_raises(handle_tag_e new_session = handle_tag_event.execute(tag_event, session) mock_player.stop.assert_called_once() - assert new_session.playing_tag is None - assert new_session.paused_at is None - - -def test_suppress_playback_error_suppresses_playback_error(): - with suppress_playback_error("msg"): - raise PlaybackError("boom") - - -def test_suppress_playback_error_logs_warning(caplog): - with suppress_playback_error("something went wrong"), caplog.at_level("WARNING"): - raise PlaybackError("boom") - - assert "something went wrong" in caplog.text - assert any(r.levelname == "WARNING" for r in caplog.records) - + assert new_session.playing_tag == "test-tag" + assert new_session.paused_at == 49.0 + assert new_session.playback_command_retry is not None + assert new_session.playback_command_retry.action == PlaybackAction.STOP + assert new_session.playback_command_retry.command_key == "stop" -def test_suppress_playback_error_does_not_suppress_other_exceptions(): - with pytest.raises(RuntimeError), suppress_playback_error("msg"): - raise RuntimeError("not a playback error") +def test_handle_stop_failure_does_not_retry_before_backoff_expires(handle_tag_event, mock_player): + mock_player.stop.side_effect = PlaybackError("cannot stop") + session = PlaybackSession(playing_tag="test-tag", paused_at=49.0) -def test_suppress_playback_error_runs_body_when_no_error(): - executed = False - with suppress_playback_error("msg"): - executed = True + session = handle_tag_event.execute(TagEvent(tag_id=None, timestamp=100.0), session) + session = handle_tag_event.execute(TagEvent(tag_id=None, timestamp=100.2), session) - assert executed is True + mock_player.stop.assert_called_once() + assert session.playing_tag == "test-tag" + assert session.paused_at == 49.0 + assert session.playback_command_retry is not None + assert session.playback_command_retry.attempt_count == 1 From 1957625b11ad8155cdb8fafb66f3da01491a3eab Mon Sep 17 00:00:00 2001 From: Michael Gerbush <405526+msgerbush@users.noreply.github.com> Date: Tue, 12 May 2026 13:52:11 -0400 Subject: [PATCH 2/5] Preserve playback retries across missed reads --- jukebox/domain/use_cases/handle_tag_event.py | 12 ++--- .../domain/use_cases/test_handle_tag_event.py | 50 +++++++++++++++++++ 2 files changed, 55 insertions(+), 7 deletions(-) diff --git a/jukebox/domain/use_cases/handle_tag_event.py b/jukebox/domain/use_cases/handle_tag_event.py index 2b65d2a3..e58d4023 100644 --- a/jukebox/domain/use_cases/handle_tag_event.py +++ b/jukebox/domain/use_cases/handle_tag_event.py @@ -36,7 +36,6 @@ def __init__( def execute(self, tag_event: TagEvent, session: PlaybackSession) -> PlaybackSession: self._apply_current_tag_action_best_effort(tag_event, session) action = self.determine_action.execute(tag_event, session) - self._clear_stale_playback_retry(action, session) LOGGER.debug( "%s \t\t %s | %s | %s | %s", @@ -51,6 +50,11 @@ def execute(self, tag_event: TagEvent, session: PlaybackSession) -> PlaybackSess case PlaybackAction.CONTINUE: # Reset when tag is present session.playing_tag_removed_at = None + if ( + session.playback_command_retry is not None + and session.playback_command_retry.action == PlaybackAction.PAUSE + ): + session.playback_command_retry = None case PlaybackAction.RESUME: if self._run_playback_command( @@ -228,9 +232,3 @@ def _record_playback_command_failure( def _retry_delay_for_attempt(self, attempt_count: int) -> float: delay_index = min(attempt_count - 1, len(self.retry_delays_seconds) - 1) return self.retry_delays_seconds[delay_index] - - @staticmethod - def _clear_stale_playback_retry(action: PlaybackAction, session: PlaybackSession) -> None: - retry = session.playback_command_retry - if retry is not None and retry.action != action: - session.playback_command_retry = None diff --git a/tests/jukebox/domain/use_cases/test_handle_tag_event.py b/tests/jukebox/domain/use_cases/test_handle_tag_event.py index 6ab73b9b..acc749c5 100644 --- a/tests/jukebox/domain/use_cases/test_handle_tag_event.py +++ b/tests/jukebox/domain/use_cases/test_handle_tag_event.py @@ -487,6 +487,41 @@ def test_handle_play_failure_does_not_throttle_different_tag(handle_tag_event, m assert session.playback_command_retry is None +def test_handle_play_failure_keeps_retry_after_brief_missed_read(handle_tag_event, mock_player): + mock_player.play.side_effect = PlaybackError("bad uri") + session = PlaybackSession() + + session = handle_tag_event.execute(TagEvent(tag_id="test-tag", timestamp=100.0), session) + session = handle_tag_event.execute(TagEvent(tag_id=None, timestamp=100.2), session) + session = handle_tag_event.execute(TagEvent(tag_id="test-tag", timestamp=100.3), session) + + mock_player.play.assert_called_once() + assert session.playback_command_retry is not None + assert session.playback_command_retry.action == PlaybackAction.PLAY + assert session.playback_command_retry.command_key == "play:test-tag" + assert session.playback_command_retry.next_retry_at == pytest.approx(100.5) + + +def test_handle_play_failure_clears_retry_when_unknown_tag_is_read(handle_tag_event, mock_player, mock_library): + known_disc = Disc(uri="uri:tag-a", metadata=DiscMetadata(), option=DiscOption(shuffle=False)) + mock_library.get_disc.side_effect = lambda tag_id: known_disc if tag_id == "tag-a" else None + mock_player.play.side_effect = PlaybackError("bad uri") + session = PlaybackSession() + + session = handle_tag_event.execute(TagEvent(tag_id="tag-a", timestamp=100.0), session) + assert session.playback_command_retry is not None + assert session.playback_command_retry.command_key == "play:tag-a" + + session = handle_tag_event.execute(TagEvent(tag_id="unknown-tag", timestamp=100.2), session) + assert session.playback_command_retry is None + + session = handle_tag_event.execute(TagEvent(tag_id="tag-a", timestamp=100.3), session) + + assert mock_player.play.call_count == 2 + assert session.playback_command_retry is not None + assert session.playback_command_retry.command_key == "play:tag-a" + + def test_handle_resume_action_does_not_update_session_when_player_raises(handle_tag_event, mock_player): mock_player.resume.side_effect = PlaybackError("cannot resume") session = PlaybackSession() @@ -503,6 +538,21 @@ def test_handle_resume_action_does_not_update_session_when_player_raises(handle_ assert new_session.playback_command_retry.command_key == "resume" +def test_handle_resume_failure_keeps_retry_after_brief_missed_read(handle_tag_event, mock_player): + mock_player.resume.side_effect = PlaybackError("cannot resume") + session = PlaybackSession(playing_tag="test-tag", paused_at=60.0) + + session = handle_tag_event.execute(TagEvent(tag_id="test-tag", timestamp=100.0), session) + session = handle_tag_event.execute(TagEvent(tag_id=None, timestamp=100.2), session) + session = handle_tag_event.execute(TagEvent(tag_id="test-tag", timestamp=100.3), session) + + mock_player.resume.assert_called_once() + assert session.playback_command_retry is not None + assert session.playback_command_retry.action == PlaybackAction.RESUME + assert session.playback_command_retry.command_key == "resume" + assert session.playback_command_retry.next_retry_at == pytest.approx(100.5) + + def test_handle_pause_action_does_not_update_session_when_player_raises(handle_tag_event, mock_player): mock_player.pause.side_effect = PlaybackError("cannot pause") session = PlaybackSession() From e87dc657cd3a023265499bf76e50fee7b3cbc903 Mon Sep 17 00:00:00 2001 From: Michael Gerbush <405526+msgerbush@users.noreply.github.com> Date: Tue, 12 May 2026 14:48:44 -0400 Subject: [PATCH 3/5] Bound playback command retries --- jukebox/domain/entities/playback_session.py | 3 +- jukebox/domain/use_cases/handle_tag_event.py | 28 +++++++-- .../domain/use_cases/test_handle_tag_event.py | 63 +++++++++++++++---- 3 files changed, 75 insertions(+), 19 deletions(-) diff --git a/jukebox/domain/entities/playback_session.py b/jukebox/domain/entities/playback_session.py index 3c1dee49..2f095d1e 100644 --- a/jukebox/domain/entities/playback_session.py +++ b/jukebox/domain/entities/playback_session.py @@ -11,7 +11,8 @@ class PlaybackCommandRetry(BaseModel): first_failed_at: float last_failed_at: float attempt_count: int - next_retry_at: float + next_retry_at: float | None + exhausted: bool = False class PlaybackSession(BaseModel): diff --git a/jukebox/domain/use_cases/handle_tag_event.py b/jukebox/domain/use_cases/handle_tag_event.py index e58d4023..1c0c6731 100644 --- a/jukebox/domain/use_cases/handle_tag_event.py +++ b/jukebox/domain/use_cases/handle_tag_event.py @@ -9,7 +9,7 @@ from jukebox.domain.use_cases.determine_current_tag_action import DetermineCurrentTagAction LOGGER = logging.getLogger("jukebox") -PLAYBACK_RETRY_DELAYS_SECONDS = (0.5, 1.0, 2.0, 5.0, 10.0, 30.0) +PLAYBACK_RETRY_DELAYS_SECONDS = (0.1, 0.25, 0.5, 1.0, 2.0, 5.0, 10.0, 30.0) class HandleTagEvent: @@ -179,10 +179,19 @@ def _run_playback_command( command: Callable[[], None], ) -> bool: retry = session.playback_command_retry + if retry is not None and retry.action == action and retry.command_key == command_key and retry.exhausted: + LOGGER.debug( + "Skipping playback operation `%s`; retry exhausted after %d attempts", + action.value.upper(), + retry.attempt_count, + ) + return False + if ( retry is not None and retry.action == action and retry.command_key == command_key + and retry.next_retry_at is not None and tag_event.timestamp < retry.next_retry_at ): LOGGER.debug( @@ -196,7 +205,13 @@ def _run_playback_command( command() except PlaybackError: retry = self._record_playback_command_failure(action, command_key, tag_event, session) - LOGGER.warning("%s; retrying in %.3fs", error_message, retry.next_retry_at - tag_event.timestamp) + if retry.exhausted: + LOGGER.warning("%s; retry exhausted after %d attempts", error_message, retry.attempt_count) + else: + next_retry_at = retry.next_retry_at + if next_retry_at is None: + raise RuntimeError("retry is not exhausted but next_retry_at is missing") + LOGGER.warning("%s; retrying in %.3fs", error_message, next_retry_at - tag_event.timestamp) return False session.playback_command_retry = None @@ -224,11 +239,14 @@ def _record_playback_command_failure( first_failed_at=first_failed_at, last_failed_at=tag_event.timestamp, attempt_count=attempt_count, - next_retry_at=tag_event.timestamp + retry_delay, + next_retry_at=None if retry_delay is None else tag_event.timestamp + retry_delay, + exhausted=retry_delay is None, ) session.playback_command_retry = retry return retry - def _retry_delay_for_attempt(self, attempt_count: int) -> float: - delay_index = min(attempt_count - 1, len(self.retry_delays_seconds) - 1) + def _retry_delay_for_attempt(self, attempt_count: int) -> float | None: + delay_index = attempt_count - 1 + if delay_index >= len(self.retry_delays_seconds): + return None return self.retry_delays_seconds[delay_index] diff --git a/tests/jukebox/domain/use_cases/test_handle_tag_event.py b/tests/jukebox/domain/use_cases/test_handle_tag_event.py index acc749c5..8949f133 100644 --- a/tests/jukebox/domain/use_cases/test_handle_tag_event.py +++ b/tests/jukebox/domain/use_cases/test_handle_tag_event.py @@ -492,14 +492,32 @@ def test_handle_play_failure_keeps_retry_after_brief_missed_read(handle_tag_even session = PlaybackSession() session = handle_tag_event.execute(TagEvent(tag_id="test-tag", timestamp=100.0), session) - session = handle_tag_event.execute(TagEvent(tag_id=None, timestamp=100.2), session) - session = handle_tag_event.execute(TagEvent(tag_id="test-tag", timestamp=100.3), session) + session = handle_tag_event.execute(TagEvent(tag_id=None, timestamp=100.04), session) + session = handle_tag_event.execute(TagEvent(tag_id="test-tag", timestamp=100.05), session) mock_player.play.assert_called_once() assert session.playback_command_retry is not None assert session.playback_command_retry.action == PlaybackAction.PLAY assert session.playback_command_retry.command_key == "play:test-tag" - assert session.playback_command_retry.next_retry_at == pytest.approx(100.5) + assert session.playback_command_retry.next_retry_at == pytest.approx(100.1) + + +def test_handle_play_failure_gives_up_after_retry_delays_are_exhausted(handle_tag_event, mock_player): + handle_tag_event.retry_delays_seconds = (0.5,) + mock_player.play.side_effect = PlaybackError("bad uri") + session = PlaybackSession() + + session = handle_tag_event.execute(TagEvent(tag_id="test-tag", timestamp=100.0), session) + session = handle_tag_event.execute(TagEvent(tag_id="test-tag", timestamp=100.5), session) + session = handle_tag_event.execute(TagEvent(tag_id="test-tag", timestamp=101.0), session) + + assert mock_player.play.call_count == 2 + assert session.playback_command_retry is not None + assert session.playback_command_retry.action == PlaybackAction.PLAY + assert session.playback_command_retry.command_key == "play:test-tag" + assert session.playback_command_retry.attempt_count == 2 + assert session.playback_command_retry.exhausted is True + assert session.playback_command_retry.next_retry_at is None def test_handle_play_failure_clears_retry_when_unknown_tag_is_read(handle_tag_event, mock_player, mock_library): @@ -543,14 +561,14 @@ def test_handle_resume_failure_keeps_retry_after_brief_missed_read(handle_tag_ev session = PlaybackSession(playing_tag="test-tag", paused_at=60.0) session = handle_tag_event.execute(TagEvent(tag_id="test-tag", timestamp=100.0), session) - session = handle_tag_event.execute(TagEvent(tag_id=None, timestamp=100.2), session) - session = handle_tag_event.execute(TagEvent(tag_id="test-tag", timestamp=100.3), session) + session = handle_tag_event.execute(TagEvent(tag_id=None, timestamp=100.04), session) + session = handle_tag_event.execute(TagEvent(tag_id="test-tag", timestamp=100.05), session) mock_player.resume.assert_called_once() assert session.playback_command_retry is not None assert session.playback_command_retry.action == PlaybackAction.RESUME assert session.playback_command_retry.command_key == "resume" - assert session.playback_command_retry.next_retry_at == pytest.approx(100.5) + assert session.playback_command_retry.next_retry_at == pytest.approx(100.1) def test_handle_pause_action_does_not_update_session_when_player_raises(handle_tag_event, mock_player): @@ -570,7 +588,7 @@ def test_handle_pause_action_does_not_update_session_when_player_raises(handle_t assert new_session.playback_command_retry.action == PlaybackAction.PAUSE assert new_session.playback_command_retry.command_key == "pause" assert new_session.playback_command_retry.attempt_count == 1 - assert new_session.playback_command_retry.next_retry_at == pytest.approx(100.5) + assert new_session.playback_command_retry.next_retry_at == pytest.approx(100.1) def test_handle_pause_failure_does_not_retry_before_backoff_expires(handle_tag_event, mock_player): @@ -578,7 +596,7 @@ def test_handle_pause_failure_does_not_retry_before_backoff_expires(handle_tag_e session = PlaybackSession(playing_tag="test-tag", playing_tag_removed_at=96.9) session = handle_tag_event.execute(TagEvent(tag_id=None, timestamp=100.0), session) - session = handle_tag_event.execute(TagEvent(tag_id=None, timestamp=100.2), session) + session = handle_tag_event.execute(TagEvent(tag_id=None, timestamp=100.05), session) mock_player.pause.assert_called_once() assert session.paused_at is None @@ -591,10 +609,10 @@ def test_handle_pause_failure_retries_after_backoff_and_updates_session_on_succe session = PlaybackSession(playing_tag="test-tag", playing_tag_removed_at=96.9) session = handle_tag_event.execute(TagEvent(tag_id=None, timestamp=100.0), session) - session = handle_tag_event.execute(TagEvent(tag_id=None, timestamp=100.5), session) + session = handle_tag_event.execute(TagEvent(tag_id=None, timestamp=100.1), session) assert mock_player.pause.call_count == 2 - assert session.paused_at == 100.5 + assert session.paused_at == 100.1 assert session.playback_command_retry is None @@ -602,13 +620,32 @@ def test_handle_pause_failure_uses_next_backoff_after_retry_fails(handle_tag_eve mock_player.pause.side_effect = PlaybackError("cannot pause") session = PlaybackSession(playing_tag="test-tag", playing_tag_removed_at=96.9) + session = handle_tag_event.execute(TagEvent(tag_id=None, timestamp=100.0), session) + session = handle_tag_event.execute(TagEvent(tag_id=None, timestamp=100.1), session) + + assert mock_player.pause.call_count == 2 + assert session.playback_command_retry is not None + assert session.playback_command_retry.attempt_count == 2 + assert session.playback_command_retry.next_retry_at == pytest.approx(100.35) + + +def test_handle_pause_failure_gives_up_after_retry_delays_are_exhausted(handle_tag_event, mock_player): + handle_tag_event.retry_delays_seconds = (0.5,) + mock_player.pause.side_effect = PlaybackError("cannot pause") + session = PlaybackSession(playing_tag="test-tag", playing_tag_removed_at=96.9) + session = handle_tag_event.execute(TagEvent(tag_id=None, timestamp=100.0), session) session = handle_tag_event.execute(TagEvent(tag_id=None, timestamp=100.5), session) + session = handle_tag_event.execute(TagEvent(tag_id=None, timestamp=200.0), session) assert mock_player.pause.call_count == 2 + mock_player.stop.assert_not_called() + assert session.paused_at is None assert session.playback_command_retry is not None + assert session.playback_command_retry.action == PlaybackAction.PAUSE assert session.playback_command_retry.attempt_count == 2 - assert session.playback_command_retry.next_retry_at == pytest.approx(101.5) + assert session.playback_command_retry.exhausted is True + assert session.playback_command_retry.next_retry_at is None def test_persistent_pause_failure_keeps_retrying_pause_after_pause_duration(handle_tag_event, mock_player): @@ -625,7 +662,7 @@ def test_persistent_pause_failure_keeps_retrying_pause_after_pause_duration(hand assert session.playback_command_retry is not None assert session.playback_command_retry.action == PlaybackAction.PAUSE assert session.playback_command_retry.attempt_count == 3 - assert session.playback_command_retry.next_retry_at == pytest.approx(1002.0) + assert session.playback_command_retry.next_retry_at == pytest.approx(1000.5) def test_handle_pause_failure_clears_retry_when_action_changes(handle_tag_event, mock_player): @@ -662,7 +699,7 @@ def test_handle_stop_failure_does_not_retry_before_backoff_expires(handle_tag_ev session = PlaybackSession(playing_tag="test-tag", paused_at=49.0) session = handle_tag_event.execute(TagEvent(tag_id=None, timestamp=100.0), session) - session = handle_tag_event.execute(TagEvent(tag_id=None, timestamp=100.2), session) + session = handle_tag_event.execute(TagEvent(tag_id=None, timestamp=100.05), session) mock_player.stop.assert_called_once() assert session.playing_tag == "test-tag" From c670ac5e1f84f1f02d8be816f242a0e2bd22206a Mon Sep 17 00:00:00 2001 From: Michael Gerbush <405526+msgerbush@users.noreply.github.com> Date: Tue, 12 May 2026 15:24:17 -0400 Subject: [PATCH 4/5] Refine playback command retry interface --- jukebox/domain/entities/playback_session.py | 2 +- jukebox/domain/use_cases/handle_tag_event.py | 85 ++++++++++--------- .../domain/use_cases/test_handle_tag_event.py | 18 ++-- 3 files changed, 57 insertions(+), 48 deletions(-) diff --git a/jukebox/domain/entities/playback_session.py b/jukebox/domain/entities/playback_session.py index 2f095d1e..fb584d4d 100644 --- a/jukebox/domain/entities/playback_session.py +++ b/jukebox/domain/entities/playback_session.py @@ -7,7 +7,7 @@ class PlaybackCommandRetry(BaseModel): """Tracks retry timing for a failed playback command.""" action: PlaybackAction - command_key: str + retry_key: str first_failed_at: float last_failed_at: float attempt_count: int diff --git a/jukebox/domain/use_cases/handle_tag_event.py b/jukebox/domain/use_cases/handle_tag_event.py index 1c0c6731..1caa2870 100644 --- a/jukebox/domain/use_cases/handle_tag_event.py +++ b/jukebox/domain/use_cases/handle_tag_event.py @@ -58,12 +58,12 @@ def execute(self, tag_event: TagEvent, session: PlaybackSession) -> PlaybackSess case PlaybackAction.RESUME: if self._run_playback_command( - PlaybackAction.RESUME, - "resume", - tag_event, - session, - "Playback operation `RESUME` failed; stopping session update", - self.player.resume, + action=PlaybackAction.RESUME, + retry_key="resume", + timestamp=tag_event.timestamp, + session=session, + error_message="Playback operation `RESUME` failed; stopping session update", + command=self.player.resume, ): session.paused_at = None session.playing_tag_removed_at = None @@ -75,12 +75,14 @@ def execute(self, tag_event: TagEvent, session: PlaybackSession) -> PlaybackSess if disc is not None: LOGGER.info("Found corresponding disc: %s", disc) if self._run_playback_command( - PlaybackAction.PLAY, - f"play:{tag_event.tag_id}", - tag_event, - session, - f"Playback operation `PLAY` failed for tag_id='{tag_event.tag_id}'; stopping session update", - lambda: self.player.play(disc.uri, disc.option.shuffle), + action=PlaybackAction.PLAY, + retry_key=f"play:{tag_event.tag_id}", + timestamp=tag_event.timestamp, + session=session, + error_message=( + f"Playback operation `PLAY` failed for tag_id='{tag_event.tag_id}'; stopping session update" + ), + command=lambda: self.player.play(disc.uri, disc.option.shuffle), ): session.playing_tag = tag_event.tag_id session.paused_at = None @@ -98,23 +100,23 @@ def execute(self, tag_event: TagEvent, session: PlaybackSession) -> PlaybackSess case PlaybackAction.PAUSE: if self._run_playback_command( - PlaybackAction.PAUSE, - "pause", - tag_event, - session, - "Playback operation `PAUSE` failed; stopping session update", - self.player.pause, + action=PlaybackAction.PAUSE, + retry_key="pause", + timestamp=tag_event.timestamp, + session=session, + error_message="Playback operation `PAUSE` failed; stopping session update", + command=self.player.pause, ): session.paused_at = tag_event.timestamp case PlaybackAction.STOP: if self._run_playback_command( - PlaybackAction.STOP, - "stop", - tag_event, - session, - "Playback operation `STOP` failed; stopping session update", - self.player.stop, + action=PlaybackAction.STOP, + retry_key="stop", + timestamp=tag_event.timestamp, + session=session, + error_message="Playback operation `STOP` failed; stopping session update", + command=self.player.stop, ): session.playing_tag = None session.paused_at = None @@ -171,15 +173,16 @@ def _apply_current_tag_action( def _run_playback_command( self, + *, action: PlaybackAction, - command_key: str, - tag_event: TagEvent, + retry_key: str, + timestamp: float, session: PlaybackSession, error_message: str, command: Callable[[], None], ) -> bool: retry = session.playback_command_retry - if retry is not None and retry.action == action and retry.command_key == command_key and retry.exhausted: + if retry is not None and retry.action == action and retry.retry_key == retry_key and retry.exhausted: LOGGER.debug( "Skipping playback operation `%s`; retry exhausted after %d attempts", action.value.upper(), @@ -190,9 +193,9 @@ def _run_playback_command( if ( retry is not None and retry.action == action - and retry.command_key == command_key + and retry.retry_key == retry_key and retry.next_retry_at is not None - and tag_event.timestamp < retry.next_retry_at + and timestamp < retry.next_retry_at ): LOGGER.debug( "Skipping playback operation `%s` until retry time %.3f", @@ -204,14 +207,19 @@ def _run_playback_command( try: command() except PlaybackError: - retry = self._record_playback_command_failure(action, command_key, tag_event, session) + retry = self._record_playback_command_failure( + action=action, + retry_key=retry_key, + timestamp=timestamp, + session=session, + ) if retry.exhausted: LOGGER.warning("%s; retry exhausted after %d attempts", error_message, retry.attempt_count) else: next_retry_at = retry.next_retry_at if next_retry_at is None: raise RuntimeError("retry is not exhausted but next_retry_at is missing") - LOGGER.warning("%s; retrying in %.3fs", error_message, next_retry_at - tag_event.timestamp) + LOGGER.warning("%s; retrying in %.3fs", error_message, next_retry_at - timestamp) return False session.playback_command_retry = None @@ -219,15 +227,16 @@ def _run_playback_command( def _record_playback_command_failure( self, + *, action: PlaybackAction, - command_key: str, - tag_event: TagEvent, + retry_key: str, + timestamp: float, session: PlaybackSession, ) -> PlaybackCommandRetry: existing_retry = session.playback_command_retry - if existing_retry is None or existing_retry.action != action or existing_retry.command_key != command_key: + if existing_retry is None or existing_retry.action != action or existing_retry.retry_key != retry_key: attempt_count = 1 - first_failed_at = tag_event.timestamp + first_failed_at = timestamp else: attempt_count = existing_retry.attempt_count + 1 first_failed_at = existing_retry.first_failed_at @@ -235,11 +244,11 @@ def _record_playback_command_failure( retry_delay = self._retry_delay_for_attempt(attempt_count) retry = PlaybackCommandRetry( action=action, - command_key=command_key, + retry_key=retry_key, first_failed_at=first_failed_at, - last_failed_at=tag_event.timestamp, + last_failed_at=timestamp, attempt_count=attempt_count, - next_retry_at=None if retry_delay is None else tag_event.timestamp + retry_delay, + next_retry_at=None if retry_delay is None else timestamp + retry_delay, exhausted=retry_delay is None, ) session.playback_command_retry = retry diff --git a/tests/jukebox/domain/use_cases/test_handle_tag_event.py b/tests/jukebox/domain/use_cases/test_handle_tag_event.py index 8949f133..8cf156f6 100644 --- a/tests/jukebox/domain/use_cases/test_handle_tag_event.py +++ b/tests/jukebox/domain/use_cases/test_handle_tag_event.py @@ -472,7 +472,7 @@ def test_handle_play_action_does_not_update_session_when_player_raises(handle_ta assert new_session.playing_tag is None assert new_session.playback_command_retry is not None assert new_session.playback_command_retry.action == PlaybackAction.PLAY - assert new_session.playback_command_retry.command_key == "play:test-tag" + assert new_session.playback_command_retry.retry_key == "play:test-tag" def test_handle_play_failure_does_not_throttle_different_tag(handle_tag_event, mock_player): @@ -498,7 +498,7 @@ def test_handle_play_failure_keeps_retry_after_brief_missed_read(handle_tag_even mock_player.play.assert_called_once() assert session.playback_command_retry is not None assert session.playback_command_retry.action == PlaybackAction.PLAY - assert session.playback_command_retry.command_key == "play:test-tag" + assert session.playback_command_retry.retry_key == "play:test-tag" assert session.playback_command_retry.next_retry_at == pytest.approx(100.1) @@ -514,7 +514,7 @@ def test_handle_play_failure_gives_up_after_retry_delays_are_exhausted(handle_ta assert mock_player.play.call_count == 2 assert session.playback_command_retry is not None assert session.playback_command_retry.action == PlaybackAction.PLAY - assert session.playback_command_retry.command_key == "play:test-tag" + assert session.playback_command_retry.retry_key == "play:test-tag" assert session.playback_command_retry.attempt_count == 2 assert session.playback_command_retry.exhausted is True assert session.playback_command_retry.next_retry_at is None @@ -528,7 +528,7 @@ def test_handle_play_failure_clears_retry_when_unknown_tag_is_read(handle_tag_ev session = handle_tag_event.execute(TagEvent(tag_id="tag-a", timestamp=100.0), session) assert session.playback_command_retry is not None - assert session.playback_command_retry.command_key == "play:tag-a" + assert session.playback_command_retry.retry_key == "play:tag-a" session = handle_tag_event.execute(TagEvent(tag_id="unknown-tag", timestamp=100.2), session) assert session.playback_command_retry is None @@ -537,7 +537,7 @@ def test_handle_play_failure_clears_retry_when_unknown_tag_is_read(handle_tag_ev assert mock_player.play.call_count == 2 assert session.playback_command_retry is not None - assert session.playback_command_retry.command_key == "play:tag-a" + assert session.playback_command_retry.retry_key == "play:tag-a" def test_handle_resume_action_does_not_update_session_when_player_raises(handle_tag_event, mock_player): @@ -553,7 +553,7 @@ def test_handle_resume_action_does_not_update_session_when_player_raises(handle_ assert new_session.paused_at == 60.0 assert new_session.playback_command_retry is not None assert new_session.playback_command_retry.action == PlaybackAction.RESUME - assert new_session.playback_command_retry.command_key == "resume" + assert new_session.playback_command_retry.retry_key == "resume" def test_handle_resume_failure_keeps_retry_after_brief_missed_read(handle_tag_event, mock_player): @@ -567,7 +567,7 @@ def test_handle_resume_failure_keeps_retry_after_brief_missed_read(handle_tag_ev mock_player.resume.assert_called_once() assert session.playback_command_retry is not None assert session.playback_command_retry.action == PlaybackAction.RESUME - assert session.playback_command_retry.command_key == "resume" + assert session.playback_command_retry.retry_key == "resume" assert session.playback_command_retry.next_retry_at == pytest.approx(100.1) @@ -586,7 +586,7 @@ def test_handle_pause_action_does_not_update_session_when_player_raises(handle_t assert new_session.playing_tag_removed_at == 96.9 assert new_session.playback_command_retry is not None assert new_session.playback_command_retry.action == PlaybackAction.PAUSE - assert new_session.playback_command_retry.command_key == "pause" + assert new_session.playback_command_retry.retry_key == "pause" assert new_session.playback_command_retry.attempt_count == 1 assert new_session.playback_command_retry.next_retry_at == pytest.approx(100.1) @@ -691,7 +691,7 @@ def test_handle_stop_action_does_not_update_session_when_player_raises(handle_ta assert new_session.paused_at == 49.0 assert new_session.playback_command_retry is not None assert new_session.playback_command_retry.action == PlaybackAction.STOP - assert new_session.playback_command_retry.command_key == "stop" + assert new_session.playback_command_retry.retry_key == "stop" def test_handle_stop_failure_does_not_retry_before_backoff_expires(handle_tag_event, mock_player): From c4b087efe2fbc0e332393d07d8bf66df898214ae Mon Sep 17 00:00:00 2001 From: Michael Gerbush <405526+msgerbush@users.noreply.github.com> Date: Wed, 20 May 2026 15:50:07 -0400 Subject: [PATCH 5/5] Address playback retry review comments --- jukebox/domain/entities/playback_session.py | 18 ++++++++-- jukebox/domain/use_cases/handle_tag_event.py | 26 +++++---------- .../domain/entities/test_playback_session.py | 33 +++++++++++++++++++ .../domain/use_cases/test_handle_tag_event.py | 18 +++++----- 4 files changed, 67 insertions(+), 28 deletions(-) create mode 100644 tests/jukebox/domain/entities/test_playback_session.py diff --git a/jukebox/domain/entities/playback_session.py b/jukebox/domain/entities/playback_session.py index fb584d4d..bc220b69 100644 --- a/jukebox/domain/entities/playback_session.py +++ b/jukebox/domain/entities/playback_session.py @@ -1,4 +1,6 @@ -from pydantic import BaseModel +from typing import Self + +from pydantic import BaseModel, model_validator from .playback_action import PlaybackAction @@ -7,13 +9,25 @@ class PlaybackCommandRetry(BaseModel): """Tracks retry timing for a failed playback command.""" action: PlaybackAction - retry_key: str + tag_id: str | None = None first_failed_at: float last_failed_at: float attempt_count: int next_retry_at: float | None exhausted: bool = False + @model_validator(mode="after") + def validate_tag_id_matches_action(self) -> Self: + if self.action == PlaybackAction.PLAY: + if self.tag_id is None: + raise ValueError("tag_id is required for PLAY retry") + elif self.tag_id is not None: + raise ValueError("tag_id is only valid for PLAY retry") + return self + + def matches(self, *, action: PlaybackAction, tag_id: str | None = None) -> bool: + return self.action == action and self.tag_id == tag_id + class PlaybackSession(BaseModel): """Tracks the current logical playback and physical reader states.""" diff --git a/jukebox/domain/use_cases/handle_tag_event.py b/jukebox/domain/use_cases/handle_tag_event.py index 1caa2870..63814d1f 100644 --- a/jukebox/domain/use_cases/handle_tag_event.py +++ b/jukebox/domain/use_cases/handle_tag_event.py @@ -59,7 +59,6 @@ def execute(self, tag_event: TagEvent, session: PlaybackSession) -> PlaybackSess case PlaybackAction.RESUME: if self._run_playback_command( action=PlaybackAction.RESUME, - retry_key="resume", timestamp=tag_event.timestamp, session=session, error_message="Playback operation `RESUME` failed; stopping session update", @@ -76,7 +75,7 @@ def execute(self, tag_event: TagEvent, session: PlaybackSession) -> PlaybackSess LOGGER.info("Found corresponding disc: %s", disc) if self._run_playback_command( action=PlaybackAction.PLAY, - retry_key=f"play:{tag_event.tag_id}", + tag_id=tag_event.tag_id, timestamp=tag_event.timestamp, session=session, error_message=( @@ -101,7 +100,6 @@ def execute(self, tag_event: TagEvent, session: PlaybackSession) -> PlaybackSess case PlaybackAction.PAUSE: if self._run_playback_command( action=PlaybackAction.PAUSE, - retry_key="pause", timestamp=tag_event.timestamp, session=session, error_message="Playback operation `PAUSE` failed; stopping session update", @@ -112,7 +110,6 @@ def execute(self, tag_event: TagEvent, session: PlaybackSession) -> PlaybackSess case PlaybackAction.STOP: if self._run_playback_command( action=PlaybackAction.STOP, - retry_key="stop", timestamp=tag_event.timestamp, session=session, error_message="Playback operation `STOP` failed; stopping session update", @@ -175,14 +172,15 @@ def _run_playback_command( self, *, action: PlaybackAction, - retry_key: str, timestamp: float, session: PlaybackSession, error_message: str, command: Callable[[], None], + tag_id: str | None = None, ) -> bool: retry = session.playback_command_retry - if retry is not None and retry.action == action and retry.retry_key == retry_key and retry.exhausted: + retry_matches = retry is not None and retry.matches(action=action, tag_id=tag_id) + if retry_matches and retry.exhausted: LOGGER.debug( "Skipping playback operation `%s`; retry exhausted after %d attempts", action.value.upper(), @@ -190,13 +188,7 @@ def _run_playback_command( ) return False - if ( - retry is not None - and retry.action == action - and retry.retry_key == retry_key - and retry.next_retry_at is not None - and timestamp < retry.next_retry_at - ): + if retry_matches and retry.next_retry_at is not None and timestamp < retry.next_retry_at: LOGGER.debug( "Skipping playback operation `%s` until retry time %.3f", action.value.upper(), @@ -209,9 +201,9 @@ def _run_playback_command( except PlaybackError: retry = self._record_playback_command_failure( action=action, - retry_key=retry_key, timestamp=timestamp, session=session, + tag_id=tag_id, ) if retry.exhausted: LOGGER.warning("%s; retry exhausted after %d attempts", error_message, retry.attempt_count) @@ -229,12 +221,12 @@ def _record_playback_command_failure( self, *, action: PlaybackAction, - retry_key: str, timestamp: float, session: PlaybackSession, + tag_id: str | None = None, ) -> PlaybackCommandRetry: existing_retry = session.playback_command_retry - if existing_retry is None or existing_retry.action != action or existing_retry.retry_key != retry_key: + if existing_retry is None or not existing_retry.matches(action=action, tag_id=tag_id): attempt_count = 1 first_failed_at = timestamp else: @@ -244,7 +236,7 @@ def _record_playback_command_failure( retry_delay = self._retry_delay_for_attempt(attempt_count) retry = PlaybackCommandRetry( action=action, - retry_key=retry_key, + tag_id=tag_id, first_failed_at=first_failed_at, last_failed_at=timestamp, attempt_count=attempt_count, diff --git a/tests/jukebox/domain/entities/test_playback_session.py b/tests/jukebox/domain/entities/test_playback_session.py new file mode 100644 index 00000000..746cc63e --- /dev/null +++ b/tests/jukebox/domain/entities/test_playback_session.py @@ -0,0 +1,33 @@ +import pytest +from pydantic import ValidationError + +from jukebox.domain.entities import PlaybackAction, PlaybackCommandRetry + + +def make_retry(action: PlaybackAction, tag_id: str | None = None) -> PlaybackCommandRetry: + return PlaybackCommandRetry( + action=action, + tag_id=tag_id, + first_failed_at=100.0, + last_failed_at=100.0, + attempt_count=1, + next_retry_at=100.1, + ) + + +def test_playback_command_retry_requires_tag_id_for_play(): + with pytest.raises(ValidationError, match="tag_id is required for PLAY retry"): + make_retry(PlaybackAction.PLAY) + + +def test_playback_command_retry_rejects_tag_id_for_non_play(): + with pytest.raises(ValidationError, match="tag_id is only valid for PLAY retry"): + make_retry(PlaybackAction.PAUSE, tag_id="test-tag") + + +def test_playback_command_retry_matches_action_and_tag_id(): + retry = make_retry(PlaybackAction.PLAY, tag_id="test-tag") + + assert retry.matches(action=PlaybackAction.PLAY, tag_id="test-tag") is True + assert retry.matches(action=PlaybackAction.PLAY, tag_id="other-tag") is False + assert retry.matches(action=PlaybackAction.PAUSE, tag_id="test-tag") is False diff --git a/tests/jukebox/domain/use_cases/test_handle_tag_event.py b/tests/jukebox/domain/use_cases/test_handle_tag_event.py index 8cf156f6..3ea2ad82 100644 --- a/tests/jukebox/domain/use_cases/test_handle_tag_event.py +++ b/tests/jukebox/domain/use_cases/test_handle_tag_event.py @@ -472,7 +472,7 @@ def test_handle_play_action_does_not_update_session_when_player_raises(handle_ta assert new_session.playing_tag is None assert new_session.playback_command_retry is not None assert new_session.playback_command_retry.action == PlaybackAction.PLAY - assert new_session.playback_command_retry.retry_key == "play:test-tag" + assert new_session.playback_command_retry.tag_id == "test-tag" def test_handle_play_failure_does_not_throttle_different_tag(handle_tag_event, mock_player): @@ -498,7 +498,7 @@ def test_handle_play_failure_keeps_retry_after_brief_missed_read(handle_tag_even mock_player.play.assert_called_once() assert session.playback_command_retry is not None assert session.playback_command_retry.action == PlaybackAction.PLAY - assert session.playback_command_retry.retry_key == "play:test-tag" + assert session.playback_command_retry.tag_id == "test-tag" assert session.playback_command_retry.next_retry_at == pytest.approx(100.1) @@ -514,7 +514,7 @@ def test_handle_play_failure_gives_up_after_retry_delays_are_exhausted(handle_ta assert mock_player.play.call_count == 2 assert session.playback_command_retry is not None assert session.playback_command_retry.action == PlaybackAction.PLAY - assert session.playback_command_retry.retry_key == "play:test-tag" + assert session.playback_command_retry.tag_id == "test-tag" assert session.playback_command_retry.attempt_count == 2 assert session.playback_command_retry.exhausted is True assert session.playback_command_retry.next_retry_at is None @@ -528,7 +528,7 @@ def test_handle_play_failure_clears_retry_when_unknown_tag_is_read(handle_tag_ev session = handle_tag_event.execute(TagEvent(tag_id="tag-a", timestamp=100.0), session) assert session.playback_command_retry is not None - assert session.playback_command_retry.retry_key == "play:tag-a" + assert session.playback_command_retry.tag_id == "tag-a" session = handle_tag_event.execute(TagEvent(tag_id="unknown-tag", timestamp=100.2), session) assert session.playback_command_retry is None @@ -537,7 +537,7 @@ def test_handle_play_failure_clears_retry_when_unknown_tag_is_read(handle_tag_ev assert mock_player.play.call_count == 2 assert session.playback_command_retry is not None - assert session.playback_command_retry.retry_key == "play:tag-a" + assert session.playback_command_retry.tag_id == "tag-a" def test_handle_resume_action_does_not_update_session_when_player_raises(handle_tag_event, mock_player): @@ -553,7 +553,7 @@ def test_handle_resume_action_does_not_update_session_when_player_raises(handle_ assert new_session.paused_at == 60.0 assert new_session.playback_command_retry is not None assert new_session.playback_command_retry.action == PlaybackAction.RESUME - assert new_session.playback_command_retry.retry_key == "resume" + assert new_session.playback_command_retry.tag_id is None def test_handle_resume_failure_keeps_retry_after_brief_missed_read(handle_tag_event, mock_player): @@ -567,7 +567,7 @@ def test_handle_resume_failure_keeps_retry_after_brief_missed_read(handle_tag_ev mock_player.resume.assert_called_once() assert session.playback_command_retry is not None assert session.playback_command_retry.action == PlaybackAction.RESUME - assert session.playback_command_retry.retry_key == "resume" + assert session.playback_command_retry.tag_id is None assert session.playback_command_retry.next_retry_at == pytest.approx(100.1) @@ -586,7 +586,7 @@ def test_handle_pause_action_does_not_update_session_when_player_raises(handle_t assert new_session.playing_tag_removed_at == 96.9 assert new_session.playback_command_retry is not None assert new_session.playback_command_retry.action == PlaybackAction.PAUSE - assert new_session.playback_command_retry.retry_key == "pause" + assert new_session.playback_command_retry.tag_id is None assert new_session.playback_command_retry.attempt_count == 1 assert new_session.playback_command_retry.next_retry_at == pytest.approx(100.1) @@ -691,7 +691,7 @@ def test_handle_stop_action_does_not_update_session_when_player_raises(handle_ta assert new_session.paused_at == 49.0 assert new_session.playback_command_retry is not None assert new_session.playback_command_retry.action == PlaybackAction.STOP - assert new_session.playback_command_retry.retry_key == "stop" + assert new_session.playback_command_retry.tag_id is None def test_handle_stop_failure_does_not_retry_before_backoff_expires(handle_tag_event, mock_player):