diff --git a/core/similar_artists_worker.py b/core/similar_artists_worker.py index c2bca2e5..283e05a5 100644 --- a/core/similar_artists_worker.py +++ b/core/similar_artists_worker.py @@ -78,26 +78,29 @@ def process_artist( ``fetch_similars(name, limit)`` returns the ``get_musicmap_similar_artists`` payload; ``store_similar(**kwargs)`` is ``add_or_update_similar_artist``. - Returns ``(status, stored_count)`` where status is one of: + Returns ``(status, stored_count, detail)`` where status is one of: - ``'matched'`` — stored ≥1 similar artist - ``'not_found'`` — MusicMap had no entry / nothing matched a source - ``'error'`` — MusicMap/source failure (transient; eligible for retry) + ``detail`` is a short human-readable reason (status code + message, or + ``'no matches'`` / ``''``) so the worker can surface WHY a fetch failed + instead of swallowing it — needed to diagnose error rates. """ try: result = fetch_similars(artist_name, limit) or {} except Exception as exc: - logger.debug("MusicMap fetch raised for %s: %s", artist_name, exc) - return ('error', 0) + return ('error', 0, f'exception: {exc}') if not result.get('success'): # 404/400 = genuinely no MusicMap entry → 'not_found' (don't keep retrying); # anything else (timeout, 5xx, no providers) = transient → 'error' (retry). code = result.get('status_code') - return ('not_found' if code in (400, 404) else 'error', 0) + detail = f"{code}: {result.get('error') or 'unknown'}" + return ('not_found' if code in (400, 404) else 'error', 0, detail) sims = result.get('similar_artists') or [] if not sims: - return ('not_found', 0) + return ('not_found', 0, 'no matches') stored = 0 for rank, s in enumerate(sims, 1): @@ -121,7 +124,7 @@ def process_artist( except Exception as exc: logger.debug("store similar failed for %s: %s", name, exc) - return ('matched' if stored else 'not_found', stored) + return ('matched' if stored else 'not_found', stored, '') class SimilarArtistsWorker: @@ -138,6 +141,8 @@ class SimilarArtistsWorker: self.stats = {'matched': 0, 'not_found': 0, 'pending': 0, 'errors': 0} self.retry_days = 30 self.limit = 25 + self._err_logged = 0 # how many fetch errors we've logged at WARNING this session + self._last_error = None # most recent fetch-error reason (for diagnosis) # similar_artists rows are profile-scoped; the library is shared. v1 keys # under the default profile (matches single-profile setups, which is the # common case). Multi-profile per-source-chain population is future work. @@ -220,7 +225,7 @@ class SimilarArtistsWorker: continue self.current_item = artist.get('name') - status, count = process_artist( + status, count, detail = process_artist( sid, artist['name'], get_musicmap_similar_artists, self.db.add_or_update_similar_artist, @@ -234,6 +239,15 @@ class SimilarArtistsWorker: self.stats['not_found'] += 1 else: self.stats['errors'] += 1 + # Surface WHY fetches error — the first handful at WARNING (so + # the cause is visible in app.log without spamming a 4000-artist + # run), the rest at DEBUG. Keep the most recent reason for stats. + self._last_error = detail + if self._err_logged < 15: + self._err_logged += 1 + logger.warning("Similar artists fetch error for '%s' — %s", artist['name'], detail) + else: + logger.debug("Similar artists fetch error for '%s' — %s", artist['name'], detail) # Pace MusicMap (name search per candidate is heavy + rate-limited). interruptible_sleep(self._stop_event, 3) diff --git a/tests/test_similar_artists_worker.py b/tests/test_similar_artists_worker.py index ad23f15d..364f0f14 100644 --- a/tests/test_similar_artists_worker.py +++ b/tests/test_similar_artists_worker.py @@ -72,8 +72,8 @@ def test_process_artist_matched_stores_with_keying(): {'name': 'C', 'id': 'it_c', 'source': 'itunes', 'image_url': 'http://x'}, ], } - status, count = w.process_artist('SRC1', 'A', lambda n, l: payload, store, limit=25, profile_id=1) - assert status == 'matched' and count == 2 + status, count, detail = w.process_artist('SRC1', 'A', lambda n, l: payload, store, limit=25, profile_id=1) + assert status == 'matched' and count == 2 and detail == '' # All similars keyed by the SOURCE artist id we passed (not the library PK). assert all(c['source_artist_id'] == 'SRC1' for c in calls) assert all(c['profile_id'] == 1 for c in calls) @@ -85,31 +85,34 @@ def test_process_artist_matched_stores_with_keying(): def test_process_artist_not_found_when_no_matches(): store, calls = _capture_store() - status, count = w.process_artist('S', 'A', lambda n, l: {'success': True, 'similar_artists': []}, store) - assert status == 'not_found' and count == 0 and calls == [] + status, count, detail = w.process_artist('S', 'A', lambda n, l: {'success': True, 'similar_artists': []}, store) + assert status == 'not_found' and count == 0 and calls == [] and detail == 'no matches' def test_process_artist_not_found_on_404(): # Genuinely no MusicMap entry — shouldn't be retried as an error. store, _ = _capture_store() - status, _ = w.process_artist('S', 'A', lambda n, l: {'success': False, 'status_code': 404}, store) + status, _, _ = w.process_artist('S', 'A', lambda n, l: {'success': False, 'status_code': 404}, store) assert status == 'not_found' -def test_process_artist_error_on_outage_is_retriable(): - # 5xx / no providers → transient error (worker retries after retry_days). +def test_process_artist_error_on_outage_is_retriable_and_explains_why(): + # 5xx / no providers → transient error (retried after retry_days), and the + # reason is surfaced (code + message) so the cause is diagnosable, not silent. store, _ = _capture_store() - status, _ = w.process_artist('S', 'A', lambda n, l: {'success': False, 'status_code': 502}, store) + status, _, detail = w.process_artist( + 'S', 'A', lambda n, l: {'success': False, 'status_code': 502, 'error': 'Failed to fetch from MusicMap'}, store) assert status == 'error' + assert '502' in detail and 'MusicMap' in detail -def test_process_artist_error_when_fetch_raises(): +def test_process_artist_error_when_fetch_raises_carries_detail(): store, _ = _capture_store() def boom(n, l): raise RuntimeError('musicmap down') - status, count = w.process_artist('S', 'A', boom, store) - assert status == 'error' and count == 0 + status, count, detail = w.process_artist('S', 'A', boom, store) + assert status == 'error' and count == 0 and 'musicmap down' in detail def test_process_artist_skips_unstorable_but_counts_real(): @@ -123,5 +126,5 @@ def test_process_artist_skips_unstorable_but_counts_real(): {'name': 'B', 'id': '1', 'source': 'spotify'}, {'name': 'C', 'id': '2', 'source': 'spotify'}, ]} - status, count = w.process_artist('S', 'A', lambda n, l: payload, store) + status, count, _ = w.process_artist('S', 'A', lambda n, l: payload, store) assert status == 'matched' and count == 1 and len(calls) == 2