search

epoupon / lms

Lightweight Music Server. Access your self-hosted music using a web interface.
http://lms-demo.poupon.dev
GNU General Public License v3.0
1.14k stars 62 forks source link

not able to scan new albums #531

Closed eddyizm closed 1 month ago

eddyizm commented 1 month ago

Running the docker container and moved over from one system to a new system. Restored everything successfully, eg the db, files, permissions. I am not having any other issues besides when I scan, nothing new comes up after adding new files/albums.

I'm a little stumped on where to look, I don't believe i had any changes in my conf file that i Need to bring over but perhaps I hit some kind of limit or there was a db issue? A scan just produces a few normal errors, a few dupes and a few corrupt audio/jpg files but less than 20 in total out of thousands of files.

Any ideas of where to look or any way I can dig into it to provide more detailed info? Just point me in the right direction.

epoupon commented 1 month ago

Hello! What about logs? Is there some error? Are you sure of the permissions set?

eddyizm commented 1 month ago

I am not seeing anything obvious, maybe I need to turn on debug logs?

As far as permissions, the music folder only needs read, that is how i had it before and that is how the example shows it. I am able to listen to music no problem. Could the problem be in the data side, eg not the music reading? I am surprised this would not show up as an error if it could not write to it. Gonna try to write to that directory from within the container to validate...

I am running a rootless container and I was able to create a new file in that directory. 

~ $ touch /var/lms/test.file
~ $ ls -ahl /var/lms
total 34M    
drwxr-xrwx    3 root     root        4.0K Oct  4 04:49 .
drwxr-xr-x   13 root     root        4.0K Aug 31 00:44 ..
-rwxr-xrwx    1 root     root       10.8K Sep  8 17:57 access.log
drwxr-xrwx    2 root     root        4.0K Sep  8 17:57 cache
-rwxr-xrwx    1 root     root       27.6M Oct  3 00:00 lms.db
-rwxr-xrwx    1 1000     1000       32.0K Oct  4 04:33 lms.db-shm
-rwxr-xrwx    1 1000     1000        4.2M Oct  4 04:33 lms.db-wal
-rwxr-xrwx    1 root     root        1.9M Sep  8 17:57 lms.log
-rw-r--r--    1 1000     1000           0 Oct  4 04:49 test.file
-rwxr-xrwx    1 root     root         366 Oct  1 22:14 wt_config.xml
~ $ whoami
1000

Inspecting the container ->

                    "-v",                      
                    "/media/daily/Music:/music:ro",                                            
                    "-v",                      
                    "/media/daily/Data/lms:/var/lms:rw",                                       
                    "docker.io/epoupon/lms

docker logs when I run the scan: 


[2024-Oct-04 04:38:49.776] 1 - [info] - 548070312936 [DB UPDATER] Scheduling next scan right now                                                                           
[2024-Oct-04 04:38:49.776] 1 [/ NAh9GwV3jkehnthW] [info] - 548070136808 [UI] Notifying message 'Scan launched!' for category '??Lms.Admin.Database.database??'
[2024-Oct-04 04:38:49.777] 1 - [info] "wthttp: 10.0.2.100   POST /?wtd=NAh9GwV3jkehnthW HTTP/1.1 200 47"                                                                    
[2024-Oct-04 04:38:49.777] 1 - [info] "WebRequest: took 2.217 ms"
[2024-Oct-04 04:38:49.777] 1 - [info] - 548070312936 [UI] New scan started!                                                                                                 
[2024-Oct-04 04:38:49.881] 1 - [info] "wthttp: 10.0.2.100   POST /?wtd=NAh9GwV3jkehnthW HTTP/1.1 200 509"
[2024-Oct-04 04:38:49.881] 1 - [info] "WebRequest: took 3.572 ms"                                                                                                           
[2024-Oct-04 04:38:50.028] 1 - [info] "wthttp: 10.0.2.100   POST /?wtd=NAh9GwV3jkehnthW HTTP/1.1 200 147"
[2024-Oct-04 04:38:50.028] 1 - [info] "WebRequest: took 30.177 ms"                                                                                                          
[2024-Oct-04 04:38:51.871] 1 - [info] "wthttp: 10.0.2.100   POST /?wtd=NAh9GwV3jkehnthW HTTP/1.1 200 145"
[2024-Oct-04 04:38:51.871] 1 - [info] "WebRequest: took 1771.11 ms"                                                                                                         
[2024-Oct-04 04:38:51.908] 1 - [info] "wthttp: 10.0.2.100   POST /?wtd=NAh9GwV3jkehnthW HTTP/1.1 200 47"
[2024-Oct-04 04:38:51.909] 1 - [info] "WebRequest: took 1.093 ms"                                                                                                           
[2024-Oct-04 04:38:53.871] 1 - [info] "wthttp: 10.0.2.100   POST /?wtd=NAh9GwV3jkehnthW HTTP/1.1 200 128"
[2024-Oct-04 04:38:53.871] 1 - [info] "WebRequest: took 1921.69 ms"                                                                                                         
[2024-Oct-04 04:38:55.398] 1 - [info] "wthttp: 10.0.2.100   POST /?wtd=NAh9GwV3jkehnthW HTTP/1.1 200 0"
[2024-Oct-04 04:38:55.398] 1 - [info] "WebRequest: took 1465.02 ms"                                                                                                         
[2024-Oct-04 04:38:55.399] 1 - [info] "wthttp: 10.0.2.100   POST /?wtd=NAh9GwV3jkehnthW HTTP/1.1 200 97"
[2024-Oct-04 04:38:55.400] 1 - [info] "WebRequest: took 2.934 ms"                                                                                                           
[2024-Oct-04 04:38:55.871] 1 - [info] "wthttp: 10.0.2.100   POST /?wtd=NAh9GwV3jkehnthW HTTP/1.1 200 128"
[2024-Oct-04 04:38:55.872] 1 - [info] "WebRequest: took 362.811 ms"                                                                                                         
[2024-Oct-04 04:38:57.901] 1 - [info] "wthttp: 10.0.2.100   POST /?wtd=NAh9GwV3jkehnthW HTTP/1.1 200 129"
[2024-Oct-04 04:38:56.285] 1 - [error] - 548070464488 [DB UPDATER] Cannot read image in file '/music/R/Regina Spektor/Regina Spektor-What We Saw From The Cheap Seats (2012) 320Kbit(mp3) DMT/dmt.png': Cannot load image from file: Corrupt JPEG
[2024-Oct-04 04:38:57.901] 1 - [info] "wthttp: 10.0.2.100   POST /?wtd=NAh9GwV3jkehnthW HTTP/1.1 200 129"
[2024-Oct-04 04:38:57.901] 1 - [info] "WebRequest: took 1970.63 ms"
[2024-Oct-04 04:38:59.622] 1 - [info] "wthttp: 10.0.2.100   POST /?wtd=NAh9GwV3jkehnthW HTTP/1.1 200 153"
[2024-Oct-04 04:38:59.622] 1 - [info] "WebRequest: took 1661.59 ms"
[2024-Oct-04 04:38:59.682] 1 - [info] "wthttp: 10.0.2.100   POST /?wtd=NAh9GwV3jkehnthW HTTP/1.1 200 47"
[2024-Oct-04 04:38:59.683] 1 - [info] "WebRequest: took 3.899 ms"
[2024-Oct-04 04:39:01.597] 1 - [info] "wthttp: 10.0.2.100   POST /?wtd=NAh9GwV3jkehnthW HTTP/1.1 200 152"
[2024-Oct-04 04:39:01.597] 1 - [info] "WebRequest: took 1870.63 ms"
[2024-Oct-04 04:39:01.644] 1 - [info] "wthttp: 10.0.2.100   POST /?wtd=NAh9GwV3jkehnthW HTTP/1.1 200 155"
[2024-Oct-04 04:39:01.645] 1 - [info] "WebRequest: took 1.943 ms"
[2024-Oct-04 04:39:01.741] 1 - [info] "wthttp: 10.0.2.100   POST /?wtd=NAh9GwV3jkehnthW HTTP/1.1 200 157"
[2024-Oct-04 04:39:01.741] 1 - [info] "WebRequest: took 63.391 ms"
[2024-Oct-04 04:39:01.768] 1 - [info] - 548070312936 [DB UPDATER] Found duplicated track MBID [fe6f2f92-29ba-3dd6-aebf-551a5a0db7c1], file: /music/H/Hepcat/08 Hepcat - Penny Reel-Hepcat.mp3 - Penny Reel
[2024-Oct-04 04:39:01.769] 1 - [info] - 548070312936 [DB UPDATER] Found duplicated track MBID [fe6f2f92-29ba-3dd6-aebf-551a5a0db7c1], file: /music/V/Various Artists/SKA_ISLAND_COMP/08 Hepcat - Penny Reel-Hepcat.mp3 - Penny Reel
[2024-Oct-04 04:39:01.769] 1 - [info] - 548070312936 [DB UPDATER] Found duplicated track MBID [0bddbf16-952b-3f0b-ae15-a36aeafa0b57], file: /music/T/That Dog/DGC Rarities Vol.1/08 that dog. - Grunge Couple-that dog..mp3 - Grunge Couple
[2024-Oct-04 04:39:01.770] 1 - [info] - 548070312936 [DB UPDATER] Found duplicated track MBID [0bddbf16-952b-3f0b-ae15-a36aeafa0b57], file: /music/V/Various Artists/va - 1994 DGC Rarities Vol. 1 (dgcd-24704)/08 that dog. - Grunge Couple-that dog..mp3 - Grunge Couple
[2024-Oct-04 04:39:01.771] 1 - [info] - 548070312936 [DB UPDATER] Found duplicated track MBID [096a2c4a-8860-3713-8291-c5e4fa94a2b1], file: /music/A/Aphex Twin - Drukqs/2-04 Mt Saint Michel Mix + St Michaels Mount-Aphex Twin (1).mp3 - Mt Saint Michel Mix + St Michaels Mount
[2024-Oct-04 04:39:01.771] 1 - [info] - 548070312936 [DB UPDATER] Found duplicated track MBID [096a2c4a-8860-3713-8291-c5e4fa94a2b1], file: /music/A/Aphex Twin - Drukqs/2-04 Mt Saint Michel Mix + St Michaels Mount-Aphex Twin.mp3 - Mt Saint Michel Mix + St Michaels Mount
[2024-Oct-04 04:39:01.772] 1 - [info] - 548070312936 [DB UPDATER] Scan complete. Changes = 0 (added = 0, removed = 0, updated = 0), Not changed = 20927, Scanned = 5 (errors = 5), features fetched = 0,  duplicates = 6
[2024-Oct-04 04:39:01.773] 1 - [info] - 548070312936 [DB UPDATER] Scheduling next scan at Sat Oct  5 00:00:00 2024
[2024-Oct-04 04:39:01.776] 1 [/ NAh9GwV3jkehnthW] [info] - 548076469224 [UI] Notifying message 'Scan complete: 20927 total files, 0 additions, 0 updates, 0 deletions, 6 duplicates, 5 errors' for category '??Lms.Admin.Database.database??'
epoupon commented 1 month ago

What about the permissions of the directories you don't manage to scan? (both users and access bits)

eddyizm commented 1 month ago

so from within the container the new directory is the Black Dhalia which does seem to have a difference than the previous folders. The music data though is read only so this shouldn't matter right? 

~ $ ls -ahl music/B/ | grep Black
drwxrwxrwx    2 root     root        4.0K Jan  5  2016 Black Flag -1st 4 Years
drwxrwxrwx    5 root     root        4.0K Nov 15  2020 Black Sabbath
drwxrwxrwx    2 root     root        4.0K Jan  5  2016 Black Sheep
drwxrwxrwx    6 root     root        4.0K Oct  7  2023 The Black Dalia Murder
drwxr-xr-x    3 root     root        4.0K Sep 25 03:17 The.Black.Dahlia.Murder

Second one is the the other data directory for lms From the host: 

 eddyizm   data    la Data/lms/
total 34M
drwxr-xrwx 3 eddyizm eddyizm 4.0K Oct  3 21:49 .
drwxr-xr-x 4 eddyizm eddyizm 4.0K Sep  8 15:18 ..
-rwxr-xrwx 1 eddyizm eddyizm  11K Sep  8 10:57 access.log
drwxr-xrwx 2 eddyizm eddyizm 4.0K Sep  8 10:57 cache
-rwxr-xrwx 1 eddyizm eddyizm  28M Oct  4 11:52 lms.db
-rwxr-xrwx 1  100999  100999  32K Oct  4 15:24 lms.db-shm
-rwxr-xrwx 1  100999  100999 4.3M Oct  4 14:28 lms.db-wal
-rwxr-xrwx 1 eddyizm eddyizm 2.0M Sep  8 10:57 lms.log
-rw-r--r-- 1  100999  100999    0 Oct  3 21:49 test.file
-rwxr-xrwx 1 eddyizm eddyizm  366 Oct  1 15:14 wt_config.x

The other directory with another new album doesn't seen to have that difference from the host: 

drwxrwxrwx  2 eddyizm eddyizm 4.0K Jul 14  2021 Slightly Stoopid_self titled
drwxrwxrwx  2 eddyizm eddyizm 4.0K Jul 14  2021 Slightly Stoopid - The Longest Barrel Ride
drwxrwxrwx  2 eddyizm eddyizm 4.0K Jan  5  2016 SS skunkfest

Is there a flag I can turn on in the logs to get more details? I am surprised it is not show any other errors. Thanks for your help!

epoupon commented 1 month ago

I suspect LMS silently drops some errors, will make some tests and tell you

epoupon commented 1 month ago

Well, forbidden folders are reported in the scan report like this:

/storage/emeric/lms-dev-data/issue-531-permissions/forbidden_folder - Cannot read file: Permission denied

Forbidden files are reported in the scan report like this:

/storage/emeric/lms-dev-data/issue-531-permissions/forbidden_file.mp3 - Cannot parse audio file

In the logs:

[2024-Oct-05 14:30:44.682] 3144565 - [error] - 139856944555712 [DB UPDATER] Cannot scan file '/storage/emeric/lms-dev-data/issue-531-permissions/forbidden_folder': Permission denied
[2024-Oct-05 14:30:44.682] 3144565 - [info] - 139856952948416 [DB UPDATER] Failed to parse audio file '/storage/emeric/lms-dev-data/issue-531-permissions/forbidden_file.mp3'

So you should get some errors for this kind of problem.

By the way, are you sure about the user you use to run the container? looks like some discrepancy between eddyizm and 100999?

eddyizm commented 1 month ago

looking into that discrepancy, not sure what that is about. I did notice that the /var/lms/lms.log is not actually writing since 2023 so I am going to look into that.