From e9cd71d0842f92f46bfcd41df4399ff64d1aa4c4 Mon Sep 17 00:00:00 2001 From: Jeff Crouse Date: Fri, 31 Jul 2026 07:43:31 -0400 Subject: [PATCH] fix(scanner): move updated_at when the upsert takes its conflict branch MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit `Track.updated_at` carries `onupdate=func.now()`, and SQLAlchemy applies that to ORM flushes and Core `update()` — but not to an `on_conflict_do_update` `set_` clause, which is emitted verbatim. So `_create_track`'s conflict branch rewrote 22 columns and left the timestamp reading whenever the row was last touched by some other path. **Narrower than it first looked, and the tests are the more useful half.** ADR-0011 asserts this makes the cursor unreliable for a rescan that changes a track's tags. It does not: the ordinary rescan goes through `_update_track`, which is plain ORM attribute assignment, so `onupdate` applies and the timestamp moves. Measured against a real database rather than read off the code — the first two attempts at that measurement both reported a false positive, because `expire_on_commit=False` means the in-memory attribute can be older than the row. The tests here read back on their own engine for that reason. The conflict branch is reached only when two scans race on the same `file_path`, which is what the comment above it always said it was for. Still worth fixing: the timestamp is the cursor an incremental client would page from, and a row whose tags changed but whose `updated_at` did not is invisible to a delta — invisible in the silent direction. Three tests pin the behaviour a delta would rest on, none of which existed: a retag moves it, an unchanged rescan does *not* (or every delta carries the whole library), and the conflict branch moves it. They guard a design that does not exist yet, which is exactly when this is cheap to break by "optimising" the rescan into a bulk statement. Co-Authored-By: Claude Opus 5 (1M context) Claude-Session: https://claude.ai/code/session_014P9p2fvFnyiywBxGkv4gfW --- backend/app/services/scanner.py | 15 +++- backend/tests/test_scanner.py | 119 ++++++++++++++++++++++++++++++++ 2 files changed, 132 insertions(+), 2 deletions(-) diff --git a/backend/app/services/scanner.py b/backend/app/services/scanner.py index 7fc27a62..d33c61e5 100644 --- a/backend/app/services/scanner.py +++ b/backend/app/services/scanner.py @@ -10,7 +10,7 @@ from pathlib import Path from typing import Any -from sqlalchemy import delete, select +from sqlalchemy import delete, func, select from sqlalchemy.ext.asyncio import AsyncSession from app.config import AUDIO_EXTENSIONS, settings @@ -719,6 +719,17 @@ async def _create_track( upsert_stmt = insert_stmt.on_conflict_do_update( index_elements=["file_path"], set_={ + # `Track.updated_at` carries `onupdate=func.now()`, and SQLAlchemy applies that to + # ORM flushes and Core `update()` — but *not* to an `on_conflict_do_update` `set_` + # clause, which is emitted verbatim. So this branch rewrote 22 columns and left the + # timestamp reading whenever the row was last touched by some other path. + # + # Narrow, but real: this branch fires only when two scans race on the same + # `file_path`, since the ordinary rescan goes through `_update_track` and is a plain + # ORM update. It matters because the timestamp is the cursor an incremental client + # would page from — a row whose tags changed but whose `updated_at` did not is + # invisible to a delta, and invisible in the silent direction. + "updated_at": func.now(), "file_hash": insert_stmt.excluded.file_hash, "file_size": insert_stmt.excluded.file_size, "file_modified_at": insert_stmt.excluded.file_modified_at, @@ -763,7 +774,7 @@ async def detect_compilation_albums(self) -> dict[str, int]: Uses case-insensitive album matching to handle variations like "Alice In Ultraland" vs "Alice in Ultraland". """ - from sqlalchemy import func, update + from sqlalchemy import update # Find albums with multiple artists (compilation candidates) # Only consider tracks where album_artist is not already set diff --git a/backend/tests/test_scanner.py b/backend/tests/test_scanner.py index 632db471..bd23ada2 100644 --- a/backend/tests/test_scanner.py +++ b/backend/tests/test_scanner.py @@ -26,8 +26,10 @@ epic_boss_battle.mp3 """ +import asyncio import shutil import tempfile +from datetime import timedelta from pathlib import Path import pytest @@ -696,3 +698,120 @@ async def test_stale_lock_detection_via_heartbeat(self, clean_db): finally: r.delete("familiar:sync:lock") r.delete("familiar:sync:progress") + + +@pytest.mark.asyncio(loop_scope="function") +class TestUpdatedAtCursor: + """`tracks.updated_at` as a cursor an incremental client could page from. + + Nothing consumes it yet — `TrackResponse` does not expose it and `list_tracks` takes no `since` + parameter — but ADR-0011 proposes both, and a cursor that fails to move is wrong in the silent + direction: the row is simply absent from the delta, and the client cannot tell. + + The rescan path is a plain ORM update (`_update_track`), so SQLAlchemy applies the column's + `onupdate=func.now()`. That is the behaviour these tests pin, because it is load-bearing for a + design that does not exist yet and would otherwise be easy to break by "optimising" the rescan + into a bulk statement. + """ + + async def _read_fresh(self): + """Read the row on its own engine, so no session snapshot or identity map can answer.""" + from sqlalchemy import text + from sqlalchemy.ext.asyncio import create_async_engine + + from app.config import settings + + engine = create_async_engine(settings.database_url, echo=False) + async with engine.connect() as conn: + row = ( + await conn.execute(text("SELECT title, updated_at FROM tracks LIMIT 1")) + ).one() + await engine.dispose() + return row[0], row[1] + + async def test_retagging_a_file_moves_updated_at(self, clean_db): + """A tag change is exactly the edit a delta must not miss.""" + from mutagen.easyid3 import EasyID3 + + with tempfile.TemporaryDirectory() as tmpdir: + tmp_path = Path(tmpdir) + target = tmp_path / "track.mp3" + shutil.copy(FIXTURES_DIR / "electronic_short.mp3", target) + + await LibraryScanner(clean_db).scan(tmp_path) + await clean_db.commit() + _, before = await self._read_fresh() + + # Wide enough that the second timestamp cannot be confused for the first, and wide + # enough to survive a slow CI runner. + await asyncio.sleep(2.0) + + tags = EasyID3(target) + tags["title"] = "Retagged By The Test" + tags.save() + + clean_db.expire_all() + await LibraryScanner(clean_db).scan(tmp_path) + await clean_db.commit() + title, after = await self._read_fresh() + + assert title == "Retagged By The Test", "the rescan did not pick up the new tag" + assert after > before + timedelta(seconds=1.5), ( + f"updated_at did not move with the retag ({before} -> {after}); " + "a delta cursor built on it would silently skip this row" + ) + + async def test_the_upsert_conflict_branch_moves_updated_at(self, clean_db): + """The race path: two scans reaching the same `file_path` at once. + + `_create_track`'s `on_conflict_do_update` is emitted verbatim, so unlike the ORM rescan it + gets no `onupdate` applied for free — the timestamp has to be in the `set_` clause. Reached + by calling `_create_track` twice, which is what the race produces. + """ + from app.utils.time import utcnow + + with tempfile.TemporaryDirectory() as tmpdir: + tmp_path = Path(tmpdir) + target = tmp_path / "track.mp3" + shutil.copy(FIXTURES_DIR / "electronic_short.mp3", target) + + scanner = LibraryScanner(clean_db) + await scanner._create_track(target, "hash-one", utcnow(), 1234) + await clean_db.commit() + _, before = await self._read_fresh() + + await asyncio.sleep(2.0) + + # Same path, second writer: takes the conflict branch rather than inserting. + clean_db.expire_all() + await scanner._create_track(target, "hash-two", utcnow(), 5678) + await clean_db.commit() + _, after = await self._read_fresh() + + assert after > before + timedelta(seconds=1.5), ( + f"the conflict branch left updated_at at {before} (now {after}); " + "`set_` is emitted verbatim, so the timestamp must be listed in it" + ) + + async def test_an_unchanged_rescan_leaves_updated_at_alone(self, clean_db): + """The other half: a cursor that moves for every scan carries the whole library every time.""" + with tempfile.TemporaryDirectory() as tmpdir: + tmp_path = Path(tmpdir) + shutil.copy(FIXTURES_DIR / "electronic_short.mp3", tmp_path / "track.mp3") + + await LibraryScanner(clean_db).scan(tmp_path) + await clean_db.commit() + _, before = await self._read_fresh() + + await asyncio.sleep(1.0) + + clean_db.expire_all() + results = await LibraryScanner(clean_db).scan(tmp_path) + await clean_db.commit() + _, after = await self._read_fresh() + + assert results["unchanged"] == 1 + assert after == before, ( + f"an unchanged rescan moved updated_at ({before} -> {after}); " + "every delta would then return the entire library" + )