Merge pull request #275 from kettui/fix/spotify-ratelimited-search

Add missing rate-limit handling for Spotify search requests

core/spotify_client.py

@@ -99,7 +99,7 @@ def _set_global_rate_limit(retry_after_seconds, endpoint_name, has_real_header=F
             _rate_limit_endpoint = endpoint_name
             _rate_limit_set_at = now
             logger.warning(
-                f"GLOBAL RATE LIMIT ACTIVATED: {retry_after_seconds}s ban "
+                f"⚠️ GLOBAL RATE LIMIT ACTIVATED: {retry_after_seconds}s ban "
                 f"(expires {time.strftime('%H:%M:%S', time.localtime(new_until))}) "
                 f"triggered by {endpoint_name}"
             )
@@ -227,7 +227,7 @@ def _detect_and_set_rate_limit(exception, endpoint_name="unknown"):
                 logger.info(f"Rate limit detected on {endpoint_name} — Retry-After header: {delay}s")
             except (ValueError, TypeError):
                 delay = _BASE_UNKNOWN_BAN
-                logger.warning(f"Rate limit detected on {endpoint_name} — unparseable Retry-After: {retry_after}")
+                logger.warning(f"⚠️ Rate limit detected on {endpoint_name} — unparseable Retry-After: {retry_after}")
         else:
             # No Retry-After header available
             if "max retries" in error_str.lower():
@@ -237,7 +237,7 @@ def _detect_and_set_rate_limit(exception, endpoint_name="unknown"):
                 delay = _BASE_MAX_RETRIES_BAN  # 4 hours
             else:
                 delay = _BASE_UNKNOWN_BAN  # 30 min
-            logger.warning(f"Rate limit detected on {endpoint_name} — no Retry-After header, using {delay}s default")
+            logger.warning(f"⚠️ Rate limit detected on {endpoint_name} — no Retry-After header, using {delay}s default")
 
         _set_global_rate_limit(delay, endpoint_name, has_real_header=has_real_header)
         return True
@@ -312,7 +312,7 @@ def rate_limited(func):
                         delay = 3.0 * (2 ** attempt)  # 3, 6, 12, 24, 48
 
                     if attempt < max_retries:
-                        logger.warning(f"Spotify rate limit hit, retrying in {delay:.0f}s (attempt {attempt + 1}/{max_retries}): {func.__name__}")
+                        logger.warning(f"⚠️ Spotify rate limit hit, retrying in {delay:.0f}s (attempt {attempt + 1}/{max_retries}): {func.__name__}")
                         time.sleep(delay)
                         continue
                     else:
@@ -323,7 +323,7 @@ def rate_limited(func):
 
                 elif is_server_error and attempt < max_retries:
                     delay = 2.0 * (2 ** attempt)  # 2, 4, 8, 16, 32
-                    logger.warning(f"Spotify server error, retrying in {delay:.0f}s (attempt {attempt + 1}/{max_retries}): {func.__name__}")
+                    logger.warning(f"⚠️ Spotify server error, retrying in {delay:.0f}s (attempt {attempt + 1}/{max_retries}): {func.__name__}")
                     time.sleep(delay)
                     continue
 
@@ -534,7 +534,7 @@ class SpotifyClient:
         config = config_manager.get_spotify_config()
         
         if not config.get('client_id') or not config.get('client_secret'):
-            logger.warning("Spotify credentials not configured")
+            logger.warning("⚠️ Spotify credentials not configured")
             return
         
         try:
@@ -630,7 +630,7 @@ class SpotifyClient:
                 # Minimum 30 min for auth probe 429s — these indicate persistent throttling
                 ban_duration = max(delay, _BASE_UNKNOWN_BAN)
                 _set_global_rate_limit(ban_duration, 'is_spotify_authenticated', has_real_header=has_real_header)
-                logger.warning(f"Auth probe rate limited — activating {ban_duration}s global ban")
+                logger.warning(f"⚠️ Auth probe rate limited — activating {ban_duration}s global ban")
                 result = True
             else:
                 logger.debug(f"Spotify authentication check failed: {e}")
@@ -656,7 +656,7 @@ class SpotifyClient:
                 os.remove(cache_path)
                 logger.info("Deleted Spotify cache file")
         except Exception as e:
-            logger.warning(f"Failed to delete Spotify cache: {e}")
+            logger.warning(f"⚠️ Failed to delete Spotify cache: {e}")
 
         logger.info("Spotify client disconnected")
 
@@ -1075,7 +1075,7 @@ class SpotifyClient:
             return artists
         except Exception as e:
             if '403' in str(e) or 'Forbidden' in str(e):
-                logger.warning("Spotify user-follow-read scope not granted — re-authorize to see followed artists")
+                logger.warning("⚠️ Spotify user-follow-read scope not granted — re-authorize to see followed artists")
                 return []
             _detect_and_set_rate_limit(e, 'get_followed_artists')
             logger.error(f"Error fetching followed artists: {e}")
@@ -1125,6 +1125,7 @@ class SpotifyClient:
                     return tracks
 
                 except Exception as e:
+                    _detect_and_set_rate_limit(e, 'search_tracks')
                     logger.error(f"Error searching tracks via Spotify: {e}")
                     # Fall through to fallback
 
@@ -1153,6 +1154,10 @@ class SpotifyClient:
                     artists.sort(key=lambda a: (0 if a.name.lower().strip() == query_lower else 1))
                     return artists
 
+            if self.is_rate_limited():
+                logger.debug(f"Spotify rate limited, skipping artist search for: {query}")
+                use_spotify = False
+
         if use_spotify:
             try:
                 search_query = f'artist:{query}' if len(query.strip()) <= 4 else query
@@ -1178,6 +1183,7 @@ class SpotifyClient:
                 return artists
 
             except Exception as e:
+                _detect_and_set_rate_limit(e, 'search_artists')
                 logger.error(f"Error searching artists via Spotify: {e}")
                 # Fall through to iTunes fallback
 
@@ -1232,6 +1238,7 @@ class SpotifyClient:
                     return albums
 
                 except Exception as e:
+                    _detect_and_set_rate_limit(e, 'search_albums')
                     logger.error(f"Error searching albums via Spotify: {e}")
                     # Fall through to iTunes fallback
 
@@ -1600,4 +1607,4 @@ class SpotifyClient:
             except Exception as e:
                 logger.error(f"Error in batch artist fetch: {e}")
 
-        return found
+        return found

core/watchlist_scanner.py

@@ -363,6 +363,11 @@ class WatchlistScanner:
             self._metadata_service = None  # Lazy load if needed
         else:
             raise ValueError("Must provide either spotify_client or metadata_service")
+
+        # Run-local Spotify suppression. One rate-limit hit disables Spotify
+        # for rest of current scan, but keeps fallback providers running.
+        self._spotify_disabled_for_run = False
+        self._spotify_disabled_reason = None
     
     @property
     def database(self):
@@ -393,6 +398,26 @@ class WatchlistScanner:
             self._metadata_service = MetadataService()
         return self._metadata_service
 
+    def _reset_spotify_run_state(self):
+        """Clear per-run Spotify suppression state."""
+        self._spotify_disabled_for_run = False
+        self._spotify_disabled_reason = None
+
+    def _disable_spotify_for_run(self, reason: str):
+        """Disable Spotify for rest of current run, once."""
+        if not self._spotify_disabled_for_run:
+            logger.warning(f"⚠️ Spotify disabled for rest of run: {reason}")
+        self._spotify_disabled_for_run = True
+        self._spotify_disabled_reason = reason
+
+    def _spotify_available_for_run(self) -> bool:
+        """Check if Spotify should be used for this run."""
+        if self._spotify_disabled_for_run:
+            return False
+        if not self.spotify_client:
+            return False
+        return self.spotify_client.is_spotify_authenticated()
+
     def _get_active_client_and_artist_id(self, watchlist_artist: WatchlistArtist):
         """
         Get the appropriate client and artist ID based on active provider.
@@ -543,6 +568,7 @@ class WatchlistScanner:
         logger.info("Starting watchlist scan")
 
         try:
+            self._reset_spotify_run_state()
             from datetime import datetime, timedelta
             import random
 
@@ -598,8 +624,10 @@ class WatchlistScanner:
             # PROACTIVE ID BACKFILLING (cross-provider support)
             # Before scanning, ensure ALL artists have IDs for ALL available sources
             # iTunes and Deezer are always available; Spotify requires authentication
+            if self.spotify_client and self.spotify_client.is_rate_limited():
+                self._disable_spotify_for_run("global Spotify rate limit active")
             providers_to_backfill = ['itunes', 'deezer']
-            if self.spotify_client and self.spotify_client.is_spotify_authenticated():
+            if self._spotify_available_for_run():
                 providers_to_backfill.append('spotify')
             try:
                 from config.settings import config_manager as _cfg
@@ -612,19 +640,19 @@ class WatchlistScanner:
                 try:
                     self._backfill_missing_ids(all_watchlist_artists, provider)
                 except Exception as backfill_error:
-                    logger.warning(f"Error during {provider} ID backfilling: {backfill_error}")
+                    logger.warning(f"⚠️ Error during {provider} ID backfilling: {backfill_error}")
                     # Continue with scan even if backfilling fails
             
             scan_results = []
             for i, artist in enumerate(watchlist_artists):
-                # Abort scan if Spotify is rate limited — don't keep hammering
-                if self.spotify_client and hasattr(self.spotify_client, 'is_rate_limited') and self.spotify_client.is_rate_limited():
-                    logger.warning(f"⚠️ Spotify rate limited — aborting watchlist scan after {i}/{len(watchlist_artists)} artists")
-                    break
+                if self.spotify_client and self.spotify_client.is_rate_limited():
+                    self._disable_spotify_for_run("global Spotify rate limit active")
 
                 try:
                     result = self.scan_artist(artist)
                     scan_results.append(result)
+                    if self.spotify_client and self.spotify_client.is_rate_limited():
+                        self._disable_spotify_for_run("global Spotify rate limit active")
 
                     if result.success:
                         logger.info(f"✅ Scanned {artist.artist_name}: {result.new_tracks_found} new tracks found")
@@ -659,6 +687,8 @@ class WatchlistScanner:
 
             # Populate discovery pool with tracks from similar artists
             logger.info("Starting discovery pool population...")
+            if self.spotify_client and self.spotify_client.is_rate_limited():
+                self._disable_spotify_for_run("global Spotify rate limit active")
             self.populate_discovery_pool()
 
             # Populate seasonal content (runs independently with its own threshold)
@@ -667,15 +697,19 @@ class WatchlistScanner:
 
             # Sync Spotify library cache (runs after main scan)
             try:
+                if self.spotify_client and self.spotify_client.is_rate_limited():
+                    self._disable_spotify_for_run("global Spotify rate limit active")
                 self.sync_spotify_library_cache()
             except Exception as lib_err:
-                logger.warning(f"Error syncing Spotify library cache: {lib_err}")
-
+                logger.warning(f"⚠️ Error syncing Spotify library cache: {lib_err}")
+            
             return scan_results
             
         except Exception as e:
             logger.error(f"Error during watchlist scan: {e}")
             return []
+        finally:
+            self._reset_spotify_run_state()
     
     def scan_artist(self, watchlist_artist: WatchlistArtist) -> ScanResult:
         """
@@ -1689,7 +1723,7 @@ class WatchlistScanner:
             searched_fallback_id = None
             try:
                 # Try Spotify search
-                if self.spotify_client and self.spotify_client.is_spotify_authenticated():
+                if self._spotify_available_for_run():
                     searched_results = self.spotify_client.search_artists(artist_name, limit=1)
                     if searched_results and len(searched_results) > 0:
                         searched_spotify_id = searched_results[0].id
@@ -1726,7 +1760,7 @@ class WatchlistScanner:
                     }
 
                     # Try to match on Spotify
-                    if self.spotify_client and self.spotify_client.is_spotify_authenticated():
+                    if self._spotify_available_for_run():
                         try:
                             spotify_results = self.spotify_client.search_artists(artist_name_to_match, limit=1)
                             if spotify_results and len(spotify_results) > 0:
@@ -1914,6 +1948,9 @@ class WatchlistScanner:
             from datetime import datetime, timedelta
             import random
 
+            if self.spotify_client and self.spotify_client.is_rate_limited():
+                self._disable_spotify_for_run("global Spotify rate limit active")
+
             # Check if we should run discovery pool population (prevents over-polling)
             skip_pool_population = not self.database.should_populate_discovery_pool(hours_threshold=24, profile_id=profile_id)
 
@@ -1934,7 +1971,7 @@ class WatchlistScanner:
             logger.info("Populating discovery pool from similar artists...")
 
             # Determine which sources are available
-            spotify_available = self.spotify_client and self.spotify_client.is_spotify_authenticated()
+            spotify_available = self._spotify_available_for_run()
 
             # Import fallback metadata client (iTunes or Deezer)
             itunes_client, fallback_source = _get_fallback_metadata_client()
@@ -2543,6 +2580,9 @@ class WatchlistScanner:
 
             logger.info("Caching recent albums for discover page...")
 
+            if self.spotify_client and self.spotify_client.is_rate_limited():
+                self._disable_spotify_for_run("global Spotify rate limit active")
+
             # Clear existing cache for this profile
             self.database.clear_discovery_recent_albums(profile_id=profile_id)
 
@@ -2563,7 +2603,7 @@ class WatchlistScanner:
             albums_checked = 0
 
             # Determine available sources
-            spotify_available = self.spotify_client and self.spotify_client.is_spotify_authenticated()
+            spotify_available = self._spotify_available_for_run()
 
             # Get fallback metadata client (iTunes or Deezer)
             itunes_client, fallback_source = _get_fallback_metadata_client()
@@ -2787,6 +2827,9 @@ class WatchlistScanner:
 
             logger.info("Curating discovery playlists...")
 
+            if self.spotify_client and self.spotify_client.is_rate_limited():
+                self._disable_spotify_for_run("global Spotify rate limit active")
+
             # Build listening profile for personalization
             profile = self._get_listening_profile(profile_id)
             if profile['has_data']:
@@ -2795,7 +2838,7 @@ class WatchlistScanner:
                            f"{profile['avg_daily_plays']:.1f} avg daily plays")
 
             # Determine available sources
-            spotify_available = self.spotify_client and self.spotify_client.is_spotify_authenticated()
+            spotify_available = self._spotify_available_for_run()
             itunes_client, fallback_source = _get_fallback_metadata_client()
 
             # Process each available source
@@ -3165,7 +3208,7 @@ class WatchlistScanner:
         subsequent syncs are incremental (only fetch newly saved albums).
         Every 7 days, does a full re-sync to detect un-saved albums.
         """
-        if not self.spotify_client or not self.spotify_client.is_spotify_authenticated():
+        if not self._spotify_available_for_run():
             logger.debug("Spotify not authenticated, skipping library cache sync")
             return