genreRepository::GetAll() sometimes returns no results

vs49688 commented 1 year ago

Description

Sometimes genreRepository::GetAll() returns an empty result set, when there are in fact, results.

This can manifest as #1564. Before scanning, Navidrome caches all the known genres via cachedGenreRepo (which calls GetAll()). Because the cache is empty, the scanner tries to INSERT all the existing genres, causing the UNIQUE constraint failed: genre.name errors, as seen in #1564 .

Expected Behaviour

genreRepository::GetAll() to return the correct results.

Steps to reproduce

This is annoying to reproduce, as it only seems to happen on some systems, mine being one of them.

Add new files (or touch existing ones)
Trigger a full/quick rescan
Observe error

Platform information

Navidrome version: https://github.com/vs49688/navidrome/commit/2584f5968adb311bb7538a2c6aa4c5c8fdc070cd
- Has some extra log.Debug patches
- Also has my MusicBrainz patches, but I've seen this on vanilla Navidrome, so it's unrelated
Browser and version: Firefox 104.0.2
Operating System: NixOS 22.05.20221003.81a3237 (Quokka)

Additional information

I've traced this down to the GetAll() query not returning any results in Navidrome. Suspiciously, the same exact query does return results when run via the sqlite3 cli:

sqlite> SELECT genre.id, genre.name, a.album_count, m.song_count FROM genre LEFT JOIN (select ag.genre_id, count(ag.album_id) as album_count from album_genres ag group by ag.genre_id) a on a.genre_id = genre.id LEFT JOIN (select mg.genre_id, count(mg.media_file_id) as song_count from media_file_genres mg group by mg.genre_id) m on m.genre_id = genre.id;
44fd8c23-02d8-4058-a4b5-e10b8eb3d30e|Electronic|36|441
3a8313a9-f5d4-4fad-a66d-427e5ad9fcbd|New Wave|7|81
cdf659cd-8177-481b-a974-21ae8d275e2d|Pop|323|3664
a31870de-189e-4de8-a466-8cc5dddd3f0c|Hard Rock|32|295
de9edb17-c571-4418-8fb4-80a06e814a5a|Trance|4|61
fe8bf247-197f-4b9d-a27e-ea67928f2b4c|Soundtrack|218|5630
---snip---

Logs, with some extra log.Debugs I've littered around the place. Specifically take note of after the level=debug msg="XXX: newCachedGenreResository()/GetAll() BEGIN" line.

level=debug msg="API: New request /music/rest/startScan" client=NavidromeUI requestId=ee4bd091444b/YGiJgGbMSy-000005 username=zane version=1.8.0
level=info msg="Triggering manual scan" fullScan=false requestId=ee4bd091444b/YGiJgGbMSy-000005 user=zane
level=debug msg="Scanning folder" folder=/storage/SyncRoot/Music/music lastModifiedSince="2022-10-06 15:39:21.575 +0000 UTC"
level=debug msg="API: Successful response" requestId=ee4bd091444b/YGiJgGbMSy-000005 status=OK
level=debug msg="Directory tree loaded from DB" elapsed=1.18s total=2949
level=debug msg="XXX: newCachedGenreResository() BEGIN"
level=debug msg="XXX: newCachedGenreResository()/GetAll() BEGIN"
level=debug msg="XXX: queryAll()" args=null count=0 query="SELECT genre.id, genre.name, a.album_count, m.song_count FROM genre LEFT JOIN (select ag.genre_id, count(ag.album_id) as album_count from album_genres ag group by ag.genre_id) a on a.genre_id = genre.id LEFT JOIN (select mg.genre_id, count(mg.media_file_id) as song_count from media_file_genres mg group by mg.genre_id) m on m.genre_id = genre.id"
level=debug msg="XXX: newCachedGenreResository()/GetAll() END" count=0
level=debug msg="XXX: newCachedGenreResository() CACHED" count=0
level=debug msg="XXX: newCachedGenreResository() END/SUCCESS"
level=debug msg="Processing changed folder" dir="/storage/SyncRoot/Music/music/Saki Kaskas/Callista"
level=debug msg="XXX: toMediaFile() BEGIN" path="/storage/SyncRoot/Music/music/Saki Kaskas/Callista/01 Callista.flac"
level=debug msg="XXX: mapGenres() BEGIN" genres="[Electronic]"
level=debug msg="XXX: cachedGenreRepo/Put() BEGIN" id= name=Electronic
level=debug msg="XXX: cachedGenreRepo/Put() CACHE MISS" id= name=Electronic
level=debug msg="XXX: genreRepository/Put() BEGIN" id= name=Electronic
level=error msg="SQL: `INSERT INTO genre (id,name) VALUES (?,?)`" args="['62bc8bfe-10f3-4563-9316-6eddbb41f731','Electronic']" elapsedTime="198.86µs" error="UNIQUE constraint failed: genre.name" requestId=ee4bd091444b/YGiJgGbMSy-000005 rowsAffected=0
level=debug msg="XXX: genreRepository/Put() END" error="UNIQUE constraint failed: genre.name" id=62bc8bfe-10f3-4563-9316-6eddbb41f731 name=Electronic
level=debug msg="XXX: cachedGenreRepo/Put() END" id=62bc8bfe-10f3-4563-9316-6eddbb41f731 name=Electronic
level=debug msg="XXX: mapGenres() END/SUCCESS/NONEMPTY" genres="[Electronic]" name=Electronic out_genre="[{\"id\":\"62bc8bfe-10f3-4563-9316-6eddbb41f731\",\"name\":\"Electronic\"}]"
level=debug msg="XXX: toMediaFile() END" path="/storage/SyncRoot/Music/music/Saki Kaskas/Callista/01 Callista.flac"

deluan commented 1 year ago

This is very strange indeed. I was not able to reproduce it locally. Regarding your PR, we could use that approach as a workaround, but still caching the values, so it would "re-add" the genres only once. I'm gonna work on something like this. Thanks for the investigation!

github-actions[bot] commented 1 year ago

This issue has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.

navidrome / navidrome