diff --git a/core/spotify_client.py b/core/spotify_client.py index 824112b1..efd83021 100644 --- a/core/spotify_client.py +++ b/core/spotify_client.py @@ -495,6 +495,32 @@ class Playlist: total_tracks=(playlist_data.get('tracks') or playlist_data.get('items') or {}).get('total', 0) ) +def describe_spotify_unavailable(*, configured: bool, rate_limited: bool, + ban_seconds_left: int = 0, in_cooldown: bool = False, + cooldown_seconds_left: int = 0, has_token: bool = True) -> str: + """Human reason Spotify can't serve a request right now. + + ``is_spotify_authenticated()`` returns False for five distinct reasons, but + every API call site logged the same bare "Not authenticated with Spotify" — + so a rate-limit ban looked like a logout. This maps the real state to a + clear message (priority matches is_spotify_authenticated): not-configured → + rate-limited → post-ban cooldown → no-token → unknown probe failure. Pure. + """ + if not configured: + return "Spotify not configured (add credentials in Settings)" + if rate_limited: + if ban_seconds_left and ban_seconds_left > 0: + return f"Spotify rate-limited — ban ~{max(1, round(ban_seconds_left / 60))}m left (not a logout)" + return "Spotify rate-limited — waiting out a ban (not a logout)" + if in_cooldown: + if cooldown_seconds_left and cooldown_seconds_left > 0: + return f"Spotify post-ban cooldown — ~{cooldown_seconds_left}s left (not a logout)" + return "Spotify post-ban cooldown (not a logout)" + if not has_token: + return "Spotify not connected — no saved token; re-authenticate in Settings" + return "Spotify auth check failed (token refresh may have failed — see debug log)" + + class SpotifyClient: def __init__(self): self.sp: Optional[spotipy.Spotify] = None @@ -848,6 +874,28 @@ class SpotifyClient: return result + def _auth_unavailable_reason(self) -> str: + """Real reason an API call can't reach Spotify right now, for logging — + distinguishes a rate-limit ban / cooldown from a genuine logout instead + of the old catch-all 'Not authenticated'. Side-effect-free: reads the + cached token (no refresh, no API probe).""" + has_token = True + try: + if self.sp is not None: + ch = getattr(self.sp.auth_manager, 'cache_handler', None) + has_token = ch is None or ch.get_cached_token() is not None + except Exception: + has_token = True # unknown → don't wrongly claim "not connected" + rl = _get_rate_limit_info() if _is_globally_rate_limited() else None + return describe_spotify_unavailable( + configured=self.sp is not None, + rate_limited=_is_globally_rate_limited(), + ban_seconds_left=(rl or {}).get('remaining_seconds', 0) or 0, + in_cooldown=_is_in_post_ban_cooldown(), + cooldown_seconds_left=_get_post_ban_cooldown_remaining() or 0, + has_token=has_token, + ) + def disconnect(self): """Disconnect Spotify: clear client, delete cache, invalidate auth cache, clear rate limit""" import os @@ -915,7 +963,7 @@ class SpotifyClient: @rate_limited def get_user_playlists(self) -> List[Playlist]: if not self.is_spotify_authenticated(): - logger.error("Not authenticated with Spotify") + logger.error("Spotify request skipped — %s", self._auth_unavailable_reason()) return [] if not self._ensure_user_id(): @@ -960,7 +1008,7 @@ class SpotifyClient: def get_user_playlists_metadata_only(self) -> List[Playlist]: """Get playlists without fetching all track details for faster loading""" if not self.is_spotify_authenticated(): - logger.error("Not authenticated with Spotify") + logger.error("Spotify request skipped — %s", self._auth_unavailable_reason()) return [] if not self._ensure_user_id(): @@ -1033,7 +1081,7 @@ class SpotifyClient: def get_saved_tracks_count(self) -> int: """Get the total count of user's saved/liked songs without fetching all tracks""" if not self.is_spotify_authenticated(): - logger.error("Not authenticated with Spotify") + logger.error("Spotify request skipped — %s", self._auth_unavailable_reason()) return 0 try: @@ -1052,7 +1100,7 @@ class SpotifyClient: def get_saved_tracks(self) -> List[Track]: """Fetch all user's saved/liked songs from Spotify""" if not self.is_spotify_authenticated(): - logger.error("Not authenticated with Spotify") + logger.error("Spotify request skipped — %s", self._auth_unavailable_reason()) return [] tracks = [] @@ -1103,7 +1151,7 @@ class SpotifyClient: List of dicts with album metadata ready for DB upsert. """ if not self.is_spotify_authenticated(): - logger.error("Not authenticated with Spotify") + logger.error("Spotify request skipped — %s", self._auth_unavailable_reason()) return [] albums = [] diff --git a/tests/test_spotify_unavailable_reason.py b/tests/test_spotify_unavailable_reason.py new file mode 100644 index 00000000..d137d6a4 --- /dev/null +++ b/tests/test_spotify_unavailable_reason.py @@ -0,0 +1,54 @@ +"""The 'Not authenticated with Spotify' log line was a catch-all — it fired for +a rate-limit ban, a post-ban cooldown, a missing token, AND a genuine probe +failure, so a daily ban looked like a logout. describe_spotify_unavailable maps +the real state to a clear reason; these pin the priority + messaging. +""" + +from __future__ import annotations + +from core.spotify_client import describe_spotify_unavailable + + +def test_not_configured_wins_first(): + msg = describe_spotify_unavailable(configured=False, rate_limited=True) + assert 'not configured' in msg.lower() + + +def test_rate_limited_says_ban_not_logout(): + msg = describe_spotify_unavailable(configured=True, rate_limited=True, ban_seconds_left=1680) + assert 'rate-limited' in msg.lower() + assert '28m' in msg # 1680s -> ~28 min + assert 'not a logout' in msg.lower() + + +def test_rate_limited_without_known_duration(): + msg = describe_spotify_unavailable(configured=True, rate_limited=True, ban_seconds_left=0) + assert 'rate-limited' in msg.lower() and 'not a logout' in msg.lower() + + +def test_cooldown_when_not_rate_limited(): + msg = describe_spotify_unavailable(configured=True, rate_limited=False, + in_cooldown=True, cooldown_seconds_left=45) + assert 'cooldown' in msg.lower() and '45s' in msg + + +def test_no_token_is_a_real_logout(): + msg = describe_spotify_unavailable(configured=True, rate_limited=False, + in_cooldown=False, has_token=False) + assert 'not connected' in msg.lower() and 're-authenticate' in msg.lower() + + +def test_probe_failure_fallback(): + # configured, not rate-limited, not cooldown, has a token, but auth still + # failed → token refresh likely failed. + msg = describe_spotify_unavailable(configured=True, rate_limited=False, + in_cooldown=False, has_token=True) + assert 'auth check failed' in msg.lower() + + +def test_rate_limit_takes_priority_over_missing_token(): + # A ban must never be reported as "not connected". + msg = describe_spotify_unavailable(configured=True, rate_limited=True, + ban_seconds_left=600, has_token=False) + assert 'rate-limited' in msg.lower() + assert 'not connected' not in msg.lower()