sentriz / gonic

music streaming server / free-software subsonic server API implementation
ircs://irc.libera.chat/#gonic
GNU General Public License v3.0
1.62k stars 115 forks source link

Incremental scan does not add new tracks #63

Closed Flameborn closed 3 years ago

Flameborn commented 4 years ago

I currently have a Gonic database with 83007 tracks. After Gonic finishes running an incremental scan, I get:

Apr 29 14:00:22 gonic[318]: 2020/04/29 14:00:22 finished scan in 4m33.9894
92757s, +727/83734 tracks (19 err)

The errors are related to tag reading from a few flac and m4a files.

After this, I see the new number of tracks as 83734 via the web interface, which is correct. Then, cleanup runs, and I get:

Apr 29 14:02:53 idris gonic[318]: 2020/04/29 14:02:53 finished clean in 2m30.910
381764s, -0 tracks

Right after this, the number of tracks reverts to 83007 tracks again.

What is interesting is that even if I run a full scan, Gonic does not seem to pick up all the tracks.

sentriz commented 4 years ago

ok having a look now. it seems for some reason the cleaning logic is deleting tracks it already added just before?

sentriz commented 4 years ago

good news, I can reproduce it

Flameborn commented 4 years ago

Awesome! Is it related to the cleaning step?

sentriz commented 4 years ago

hi! can you try sentriz/gonic:clean-refac please

Flameborn commented 4 years ago

Hello,

It does not seem like you've pushed the branch you specified, at least I can't see it among the remote branches.

sentriz commented 4 years ago

The branch is https://github.com/sentriz/gonic/tree/scan-clean-del

And the image the most recently updated https://hub.docker.com/r/sentriz/gonic/tags

Flameborn commented 4 years ago

Ah, thanks.

It seems that we have the same issue as before. Starting at 83004 via an incremental scan:

May 01 18:00:21 idris gonic[21949]: 2020/05/01 18:00:21 finished scan in 15m13.81595s, +730/83735 tracks (19 err)
May 01 18:00:33 idris gonic[21949]: 2020/05/01 18:00:33 finished clean tracks in 12.42918s, 0 removed
May 01 18:00:33 idris gonic[21949]: 2020/05/01 18:00:33 finished clean folders in 482.32ms, 0 removed
May 01 18:02:12 idris gonic[21949]: 2020/05/01 18:02:12 finished clean artists in 1m38.54148s, 403 removed

The web interface shows that we have 83004 tracks still.

sentriz commented 4 years ago

hmm that is strange indeed. also can't understand why your times are so slow. you only have less than 3x the tracks I have but mine are like

main_1  | 2020/05/01 16:39:28 finished scan in 6.20875s, +0/29123 tracks (0 err)
main_1  | 2020/05/01 16:39:28 finished clean tracks in 56.37ms, 0 removed
main_1  | 2020/05/01 16:39:28 finished clean folders in 7.01ms, 0 removed
main_1  | 2020/05/01 16:39:28 finished clean artists in 590µs, 0 removed

is your db file running on a spinning disk?

as for the 19 errors you're getting. can I email you about this?

Flameborn commented 4 years ago

Ah, I wouldn't worry about the scanning speed. I'm running Gonic on a Raspberry Pi 3 and the DB is indeed on a spinning disk. On top of that, I am running "flac -t" on a bunch of lossless files at the moment, so that's also a huge setback. It's a lot faster in a normal case.

Sure, feel free to drop me a mail and we can discuss specifics. They are mainly tag read errors for a few m4a/m4b/flac files.

sentriz commented 4 years ago

hey I just saw your matrix

sentriz commented 3 years ago

hey I think this may be fixed now after some scanner stuff that changed a few months ago, but let me know if not :+1:

Cherryblue commented 3 years ago

Hi @sentriz ,

I've been silently following this issue these last months as I began using Gonic around 1 year ago and have been seeing the same problems on my music folders.

You are partly right, I have been seeing some very appreciated progress on these few music files which weren't available through Gonic until now.

However, my instance seems to never stop rescanning my files, when no new file has changed. While doing so, some of my songs are not available. gonic webpage goes from 6022 songs to 6386 songs in a loop all day long. I just verified it doesn't stop and goes back to 6022.

This prevents the user from playing songs on a player (I mainly use jamstash) since they may be temporarly removed, and probably adds a good load on the processor all day long.

I do understand that this may happen because of bad music files or idk, but it is quite difficult to know which ones. Do you have something like a blacklist indexing which files seem to cause problems ? I did see more details in the logs of the last versions of gonic, but not the music filenames.

Thanks again for your work, this is awesome :).

sentriz commented 3 years ago

hey @Cherryblue @ygbillet

would you mind sending me a handful of audio files that aren't being scanned properly? and perhaps the file structure that they're in. my email is on my profile - thanks :)

Cherryblue commented 3 years ago

Hello,

After my last post I used the tool "mp3val" to go and repair/clean my files, and now have 0 file with error. Yet, there are still error messages concerning files which I don't know how to identify : TagLib: MPEG::Header::parse() -- Invalid sample rate. TagLib: MPEG::Header::parse() -- Invalid bit rate. TagLib: MPEG::Header::parse() -- Invalid MPEG layer bits. TagLib: MPEG::Header::parse() -- Invalid sample rate. TagLib: MPEG::Header::parse() -- Invalid MPEG version bits. TagLib: MPEG::Header::parse() -- Invalid MPEG layer bits. TagLib: ID3v2.4 no longer supports the frame type TDAT. It will be discarded from the tag. TagLib: MPEG::Header::parse() -- Invalid sample rate. TagLib: MPEG::Header::parse() -- Invalid MPEG layer bits. TagLib: MPEG::Header::parse() -- Invalid bit rate. TagLib: ID3v2.4 no longer supports the frame type TDAT. It will be discarded from the tag. TagLib: ID3v2.4 no longer supports the frame type TDAT. It will be discarded from the tag. TagLib: ID3v2.4 no longer supports the frame type RVAD. It will be discarded from the tag. TagLib: ID3v2.4 no longer supports the frame type TDAT. It will be discarded from the tag. TagLib: MPEG::Header::parse() -- Invalid MPEG version bits. 2021/06/17 22:15:43 processed folder . 2021/06/17 22:15:43 finished scan in 6m16.62333s, +322/5884 tracks (0 err) 2021/06/17 22:15:43 finished clean tracks in 118.79ms, 0 removed 2021/06/17 22:15:43 finished clean folders in 8ms, 0 removed 2021/06/17 22:15:43 finished clean artists in 441.18ms, 169 removed 2021/06/17 22:15:43 finished clean genres in 38.47ms, 12 removed 2021/06/17 22:15:43 starting scan TagLib: MPEG::Header::parse() -- Invalid MPEG layer bits. TagLib: MPEG::Header::parse() -- Invalid MPEG layer bits. TagLib: MPEG::Header::parse() -- Invalid MPEG layer bits. TagLib: MPEG::Header::parse() -- Invalid MPEG version bits. TagLib: MPEG::Header::parse() -- Invalid MPEG layer bits. TagLib: MPEG::Header::parse() -- Invalid MPEG version bits. TagLib: ID3v2.4 no longer supports the frame type RVAD. It will be discarded from the tag. TagLib: ID3v2.4 no longer supports the frame type RVAD. It will be discarded from the tag

@sentriz does gonic try to fix any file itself ? My setup uses a read-only music folder which I share from my personal seafile (a self hosted dropbox alternative). Apart from that, I can't seem to understand why the software would loop the scan this quick.

sentriz commented 3 years ago

@Cherryblue I also only give gonic read only access to my audio so there shouldn't be issue there I think

btw when you a scan again (not full scan), do you still get that "169 removed" artists?

Cherryblue commented 3 years ago

@sentriz OK, RO isn't the issue then ! I can never choose when to scan, as it loops. This means no command appears on the web portal to do a manual scan as it is scanning (commands for scan doesn't seem to appear if a scan is ongoing, which is good). I use a docker image on raspberry pi 4 started with docker-compose, and this starts scanning in a loop as soon as the container is up and running (and obviously never stops).

When refreshing the UI portal, I can see the number of tracks increasing, this should correspond to the +322 tracks being removed and readded again and again.

But I have no idea how to identify which files have the problem in the collection :(

sentriz commented 3 years ago

ah! sorry then I mis-read your message about the loops! that is very strange indeed

presuming you are using env vars to configure configure gonic docker compose, what do you have GONIC_SCAN_INTERVAL set to?

Cherryblue commented 3 years ago

I use GONIC_SCAN_INTERVAL=5 which is supposed to mean 5 minutes right ?

Here is my complete docker-compose : gonic: image: sentriz/gonic:v0.13.1 container_name: gonic environment:

ygbillet commented 3 years ago

@sentriz i remove my comment after i re-read the readme. My file structure is a large directory with all my music inside. So i have multiple artists and albums in the same directory. Which is not a supported use case of Gonic (too bad for me).

I will evaluate the feasibility of changing the organization of the files and directories in order to use Gonic !

In any case it is a great product according to my requirements (small footprint, fast, easy to deploy, simple to use).

sentriz commented 3 years ago

@ygbillet thanks for the nice words :) may I recommend something like https://picard.musicbrainz.org/ or https://beets.io/ to organise your filestructure (it can be any shape you like, with the except that albums must be one folder, like you mentioned)

@Cherryblue yeah 5 is 5 mins, and thanks for the docker compose. are you seeing any repeated requests in the logs for a startScan.view, start_scan_inc_do, or start_scan_full_do? PS I'm setting up a debug build that we could use to debug this, if you like

sentriz commented 3 years ago

@Cherryblue

I just made a debug build https://github.com/sentriz/gonic/runs/2853365581?check_suite_focus=true

when it's done the image should be at sentriz/gonic:issue-63 could you try it when it builds please?

Cherryblue commented 3 years ago

@sentriz hey,

I just sent you the logs by e-mail.

Following ygbillet post, I should tell you I have a few folders with multiple albums or artists in it, but it only represents something like 5% of my collection and I do understand that it is not supported.

I prefer to tell you in case it's linked to the behavior we see on my end.

Still, from my understanding :

Thanks again for your help, have a great day

spijet commented 3 years ago

Hmm, I never had this issue on my library, but there was another thing (that I'm kinda reluctant to reproduce at the moment, but will try a bit later after I file my other PRs): In 0.11.x track IDs could "drift" after (re)moving or replacing tracks.

In one case I moved one of albums in my library to another directory (found a typo in album name and fixed it), and it caused ALL tracks to change their IDs and messed up my playlist. :D I'll check if this still happens on new releases and will report back.

sentriz commented 3 years ago

should be fixed now! thanks for all your help