preview-clip job: fix scan hang + report live per-track progress

two field-reported issues: clicking the job sat at 'Starting…' with Scanned: 0 forever and
never showed the current track.

1) HANG — spotify get_track_details() defaults to allow_fallback=True, which scrapes the
   configured metadata source when the official API isn't authed (HiFi users). that scrape is
   slow and blocked the scan loop on the first track. now pass allow_fallback=False (official
   only — fast, returns None cleanly) and fall through to iTunes/MusicBrainz.
2) NO LIVE UPDATE — progress was only pushed every 5 tracks via update_progress, never the
   current item. now report_progress() every track (phase + 'artist — title' + scanned/total)
   plus a start phase, so the UI moves and shows what it's checking.

also made the test track ids INTEGER to match production (tracks.id is INTEGER PRIMARY KEY),
exercising the real str(id) finding -> WHERE id=? round-trip. 5 tests green.
This commit is contained in:
BoulderBadgeDad 2026-06-27 16:24:31 -07:00
parent 116edeb477
commit bd3c5860f6
2 changed files with 72 additions and 39 deletions

View file

@ -98,25 +98,47 @@ class ShortPreviewTrackJob(RepairJob):
conn.close()
total = len(rows)
if context.report_progress:
try:
context.report_progress(phase=f"Checking {total} short tracks for previews…", total=total)
except Exception: # noqa: S110 — progress is best-effort
pass
for i, row in enumerate(rows):
if context.check_stop() or context.wait_if_paused():
break
result.scanned += 1
title = row["title"] or "Unknown"
artist = row["artist_name"] or "Unknown"
# Live progress EVERY track — the source lookup below is a network call, so without
# per-track reporting the UI looks frozen at "Starting…" (the #937-follow-up report).
if context.update_progress:
try:
context.update_progress(i + 1, total)
except Exception: # noqa: S110 — best-effort
pass
if context.report_progress:
try:
context.report_progress(
phase=f"Checking {i + 1}/{total} short tracks for previews…",
log_line=f"{artist}{title}", scanned=i + 1, total=total,
)
except Exception: # noqa: S110 — best-effort
pass
file_dur_s = (row["duration"] or 0) / 1000.0
expected_dur_s = self._expected_duration_s(context, row)
# Can't verify the real length → never flag (a delete must be backed by evidence).
if expected_dur_s is None or expected_dur_s <= 0:
result.skipped += 1
self._tick(context, i, total)
continue
# Source agrees the track is short (genuine intro/skit) → leave it alone. Only a
# source that says the real track is MUCH longer than the file marks a preview.
if (expected_dur_s - file_dur_s) < min_drift_s:
result.skipped += 1
self._tick(context, i, total)
continue
if context.create_finding:
@ -155,38 +177,47 @@ class ShortPreviewTrackJob(RepairJob):
except Exception as exc:
logger.debug("create_finding failed for track %s: %s", row["id"], exc)
result.errors += 1
self._tick(context, i, total)
return result
def _tick(self, context: JobContext, i: int, total: int) -> None:
if context.update_progress and (i + 1) % 5 == 0:
try:
context.update_progress(i + 1, total)
except Exception: # noqa: S110 — progress reporting is best-effort, never fail a scan on it
pass
def _expected_duration_s(self, context: JobContext, row: Dict[str, Any]) -> Optional[float]:
"""Canonical track length (seconds) from the track's metadata source, or None when
no source id is usable / the lookup fails. Every metadata client exposes
get_track_details(id) -> {... 'duration_ms': N ...} (the metadata-service contract)."""
candidates = [
(row.get("spotify_track_id"), context.spotify_client,
context.is_spotify_rate_limited()),
(row.get("itunes_track_id"), context.itunes_client, False),
(row.get("musicbrainz_recording_id"), context.mb_client, False),
]
for source_id, client, rate_limited in candidates:
if not source_id or client is None or rate_limited:
def _dur(details) -> Optional[float]:
ms = (details or {}).get("duration_ms")
return ms / 1000.0 if ms and ms > 0 else None
# Spotify — pass allow_fallback=False. The default fallback scrapes the configured
# metadata source, which is slow and can BLOCK a scan loop indefinitely when the
# official API isn't authed (the #937-follow-up hang). Official-only is fast and
# returns None cleanly when unavailable, so we just move to the next source.
sp_id = row.get("spotify_track_id")
if sp_id and context.spotify_client and not context.is_spotify_rate_limited():
try:
d = _dur(context.spotify_client.get_track_details(str(sp_id), allow_fallback=False))
if d:
return d
except TypeError:
pass # older client without the flag — skip, don't risk the slow path
except Exception as exc:
logger.debug("spotify duration lookup failed for %s: %s", sp_id, exc)
# iTunes (public API, no auth, fast) then MusicBrainz.
for source_id, client in (
(row.get("itunes_track_id"), context.itunes_client),
(row.get("musicbrainz_recording_id"), context.mb_client),
):
if not source_id or client is None:
continue
getter = getattr(client, "get_track_details", None)
if getter is None:
continue
try:
details = getter(str(source_id))
ms = (details or {}).get("duration_ms")
if ms and ms > 0:
return ms / 1000.0
d = _dur(getter(str(source_id)))
if d:
return d
except Exception as exc:
logger.debug("duration lookup failed for %s: %s", source_id, exc)
return None

View file

@ -21,7 +21,9 @@ def _seed(db: MusicDatabase):
conn.close()
def _track(db, tid, duration_ms, path, spotify_id=None):
def _track(db, tid: int, duration_ms, path, spotify_id=None):
# tid is an INTEGER id, exactly like production (tracks.id is INTEGER PRIMARY KEY) — so the
# test exercises the real round-trip: the finding stores str(id) and the fix queries WHERE id=?.
conn = db._get_connection()
conn.execute(
"INSERT INTO tracks (id, artist_id, album_id, title, duration, file_path, spotify_track_id) "
@ -52,10 +54,10 @@ def _ctx(db, findings, spotify=None):
def test_scan_flags_preview_skips_genuine_short_and_unverifiable(tmp_path: Path):
db = MusicDatabase(str(tmp_path / 'm.db'))
_seed(db)
_track(db, 'preview', 28_000, '/m/p.flac', spotify_id='sp_long') # 28s file, source 200s → FLAG
_track(db, 'skit', 28_000, '/m/i.flac', spotify_id='sp_short') # 28s file, source 28s → skip (genuine)
_track(db, 'noid', 28_000, '/m/m.flac', spotify_id=None) # 28s, no source id → skip (unverifiable)
_track(db, 'longone', 200_000, '/m/l.flac', spotify_id='sp_long') # 200s → not scanned (>30s)
_track(db, 1, 28_000, '/m/p.flac', spotify_id='sp_long') # id 1: 28s file, source 200s → FLAG
_track(db, 2, 28_000, '/m/i.flac', spotify_id='sp_short') # id 2: 28s file, source 28s → skip (genuine)
_track(db, 3, 28_000, '/m/m.flac', spotify_id=None) # id 3: 28s, no source id → skip (unverifiable)
_track(db, 4, 200_000, '/m/l.flac', spotify_id='sp_long') # id 4: 200s → not scanned (>30s)
findings = []
result = ShortPreviewTrackJob().scan(_ctx(db, findings, _FakeSpotify()))
@ -63,7 +65,7 @@ def test_scan_flags_preview_skips_genuine_short_and_unverifiable(tmp_path: Path)
assert len(findings) == 1
f = findings[0]
assert f['finding_type'] == 'short_preview_track'
assert f['entity_id'] == 'preview'
assert f['entity_id'] == '1' # str(int id), as create_finding stores it
assert f['entity_type'] == 'track'
assert f['details']['expected_duration_s'] == pytest.approx(200.0)
assert result.findings_created == 1
@ -74,7 +76,7 @@ def test_scan_flags_preview_skips_genuine_short_and_unverifiable(tmp_path: Path)
def test_scan_creates_no_finding_when_source_agrees_short(tmp_path: Path):
db = MusicDatabase(str(tmp_path / 'm.db'))
_seed(db)
_track(db, 'skit', 28_000, '/m/i.flac', spotify_id='sp_short') # source also says 28s
_track(db, 1, 28_000, '/m/i.flac', spotify_id='sp_short') # source also says 28s
findings = []
ShortPreviewTrackJob().scan(_ctx(db, findings, _FakeSpotify()))
assert findings == []
@ -83,9 +85,9 @@ def test_scan_creates_no_finding_when_source_agrees_short(tmp_path: Path):
def test_estimate_scope_counts_short_tracks(tmp_path: Path):
db = MusicDatabase(str(tmp_path / 'm.db'))
_seed(db)
_track(db, 'a', 28_000, '/m/a.flac', spotify_id='sp_long')
_track(db, 'b', 10_000, '/m/b.flac', spotify_id='sp_short')
_track(db, 'c', 200_000, '/m/c.flac', spotify_id='sp_long') # >30s, excluded
_track(db, 1, 28_000, '/m/a.flac', spotify_id='sp_long')
_track(db, 2, 10_000, '/m/b.flac', spotify_id='sp_short')
_track(db, 3, 200_000, '/m/c.flac', spotify_id='sp_long') # >30s, excluded
assert ShortPreviewTrackJob().estimate_scope(_ctx(db, [], _FakeSpotify())) == 2
@ -96,7 +98,7 @@ def test_fix_deletes_file_removes_row_and_wishlists(tmp_path: Path):
_seed(db)
preview = tmp_path / 'preview.flac'
preview.write_bytes(b'fake audio bytes')
_track(db, 't1', 28_000, str(preview), spotify_id='sp1')
_track(db, 1, 28_000, str(preview), spotify_id='sp1')
captured = {}
db.add_to_wishlist = lambda spotify_track_data, **kw: captured.update(
@ -108,16 +110,16 @@ def test_fix_deletes_file_removes_row_and_wishlists(tmp_path: Path):
w._config_manager = None
res = w._fix_short_preview_track(
'track', 't1', str(preview),
'track', '1', str(preview), # entity_id is the string the finding stored
{'expected_duration_s': 225.0, 'original_path': str(preview)})
assert res['success'] is True
assert not preview.exists() # preview file deleted
assert captured['data']['name'] == 'Track t1' # re-wishlisted with payload
assert captured['data']['name'] == 'Track 1' # re-wishlisted with payload
assert captured['data']['duration_ms'] == 225_000 # uses the real (expected) length
assert captured['kw'].get('source_type') == 'redownload'
conn = db._get_connection()
remaining = conn.execute("SELECT COUNT(*) FROM tracks WHERE id='t1'").fetchone()[0]
remaining = conn.execute("SELECT COUNT(*) FROM tracks WHERE id=1").fetchone()[0]
conn.close()
assert remaining == 0 # DB row dropped → track missing again
@ -126,7 +128,7 @@ def test_fix_missing_file_still_wishlists_and_drops_row(tmp_path: Path):
"""If the preview file is already gone, still re-wishlist + drop the row (idempotent-ish)."""
db = MusicDatabase(str(tmp_path / 'm.db'))
_seed(db)
_track(db, 't2', 28_000, str(tmp_path / 'gone.flac'), spotify_id='sp2')
_track(db, 1, 28_000, str(tmp_path / 'gone.flac'), spotify_id='sp2')
db.add_to_wishlist = lambda spotify_track_data, **kw: True
w = RepairWorker.__new__(RepairWorker)
@ -134,8 +136,8 @@ def test_fix_missing_file_still_wishlists_and_drops_row(tmp_path: Path):
w.transfer_folder = str(tmp_path)
w._config_manager = None
res = w._fix_short_preview_track('track', 't2', str(tmp_path / 'gone.flac'), {})
res = w._fix_short_preview_track('track', '1', str(tmp_path / 'gone.flac'), {})
assert res['success'] is True
conn = db._get_connection()
assert conn.execute("SELECT COUNT(*) FROM tracks WHERE id='t2'").fetchone()[0] == 0
assert conn.execute("SELECT COUNT(*) FROM tracks WHERE id=1").fetchone()[0] == 0
conn.close()