Image caching breaks when a large number of releases are loaded #446
Comments
|
Seems that there is some sort of file descriptor leakage... This may be caused by the upstream https://github.com/djherbis/fscache library. Will do more investigation. For now the solution is what you did: turn off the cache with |
|
I just hit this on 0.37.0. Same problem, same fix.
|
|
Will investigate, thanks for reporting it. |
|
Hey @vs49688 , can you try this build: https://github.com/deluan/navidrome/suites/1517769433/artifacts/26733088 ? (Remember to reenable the Image Cache) |
|
Am testing now. Should probably also mention I woke up to more of the same (this is after updating to 0.38.0): EDIT: This was with the image cache disabled..... |
|
Nope, still happens. Both with and without image cache. Full log attached.
EDIT: Seems email attachments are dropped: https://github.com/deluan/navidrome/files/5557147/navidrome.log.gz
|
|
Seeing the same navidrome 0.38.0 on arm64. |
|
Yes, this is definitely a file descriptor leaking. Can any of you guys try with version 0.36.0? |
|
restarted .38.0 again now with debug logging and suddenly cant reproduce anymore. deleted the caches/images folder and still can not reproduce. |
|
My issue may not be the same. See logs: Notice how the web client keeps reconnecting. |
|
Hummm, can you try disabling the Activity Panel with the config option |
|
Happens in 0.37.0. navidrome-0.37.0-cache.txt.gz. Testing in 0.36.1 shortly. This was reproduced by repeatedly hitting random and waiting for cover art to fail to load. When that didn't work, I switched to the Navidrome Kodi plugin. Navigating releases worked. Navigating artists (and failing to load the artist images) triggered it almost immediately. Perhaps something isn't being closed upon failure? |
|
Also happens in 0.36.1. navidrome-0.36.1-cache.txt.gz |
|
Thanks @vs49688! Is it too much to ask you to keep testing until you find the version it was last working? That would be extremely helpful, as I cannot seem to reproduce the issue here... |
|
To rule out the upgrade to Go 1.15 (introduced in version 0.35.0), I've built the current version from master using Go 1.14. If any of you guys can test it, it would be very helpful. Thanks! navidrome_v0.38.0-SNAPSHOT_Linux_arm64.tar.gz |
|
Just tried it on this (with Go 1.14) and it still happens. I could give you shell access if it'd help with debugging. |
|
Just reproduced it on 0.34.0 |
Thanks but I don't think that would help :( 0.34.0 only introduced UI changes, so the next logical candidate version (that introduced server changes) is 0.33.0, where the |
|
Done, still happens. Repro notes (personal):
|
|
I'm going to keep going back until I find one that's working, then I'll do a bisect on it. Probably won't get to this until tonight though. |
|
Well, that was several hours of my life I'll never get back. Bisected to 9f4f2f7. EDIT: Should probably note that was done by cherry-picking 16397e0 as needed. |
|
Hey @vs49688, really, really thanks for this. Are you in Discord? I'd like to chat about your finds. |
|
No worries. I'm not, but I could probably create an account. I see you have a matrix.org account, could we chat there? |
|
If you enable pprof debugging, we can probably heap/threaddump and make these much simpler to debug: |
I tried with the latest commit and I think the problem is indeed related to the activity panel. It may also be related to #640 since I also have that problem. I was able to reproduce the too many open files error like this:
|
|
Not sure if this is related, but calls to As an example, of a leak: Number of file descriptors when the server is sitting idle: Perform GET on While the call is running: Using Then after killing the The number of open file descriptors never goes back down: And the socket allocated in the The |
|
Hey @darkeststar, thanks for the detailed debugging! Yes, I can confirm that the Activity Panel is definitely add up to the issue, but it is not the main culprit. I'll release a new version today with the Activity Panel and the Image Cache disabled by default, that should alleviate the issue for new users, while I don't figure out the final solution for this issue EDIT: This particular FD leakage was just fixed in a8c5fa6, and will be in the next release |
|
I also think I had a old load balancer in front that did not play well with SSE. I think this caused numerous failed connections from some web clients, leaking connections much faster. I currently have no issues with caddy 2.2.0 |
|
I'll just say 'me too' and if there's anything I can do to help debug/test, I've got time. I'll be monitoring the open file descriptors closely, after disabling the image cache. |
|
I noticed my images weren't loading anymore, and so came here to see if I could find out why, and I guess it's due to the fact image cache has been disabled by default.. how can I turn image caching back on to see if it still works on my system? Thanks! |
|
Even with the Image Cache disabled, you should see the images. You can enable it with |
|
I do see some images, but strangely not some that I was seeing previously. And yeah I've actually already added that bit of code but didn't notice any difference. |
|
I had encountered the file descriptor bug. Now I'm on 0.39.0 but I'm encountering strange behaviour with album art. Sometimes I restart Navidrome and some covers that worked before will disappear. To fix, I trigger a scan of a particular folder by updating the file times, and the cover comes back. Should I create a new issue, or is it related to this one? |
|
Hey @izaak , seems like I missed your last comment, sorry. Do you have more info on this disappearing covers bug? This is only related to the fd bug if you see "too many opened files" messages in the logs for the You said that you found the bug. What exactly do you mean? Did you find where in the code this is being caused? |
That's what's happened to me too. Albums that used to have covers no longer do. I may try the file name change trick to see if that works for me too... |
Sorry for the confusion- my system does run into the bug but I have not found anything to help fix it. I used to run into the bug more often though, I wonder if it's aggrevated by crappy routers dropping connections. I used to get the 'too many opened files' error every ~4 days average, but since upgrading my network setup a few weeks ago, I've only seen the problem once... |
Eventually I just had to start a new database. |
|
File descriptor bug occurs on latest release as well. I ran into it while setting up the server, so importing folders might have exacerbated it. I had to set image cache to 0, will let you know if I continue to hit it. |
|
I'm not sure my issue is OPs, but since I see the issue of "covers that worked before will disappear" showing up, this seemed like the place for the bug I've found. If the cache is empty and I start navidrome with image caching enabled, everything works great. If I stop navidrome, completely delete the cache folder and restart navidrome, everything is fine. Disabling caching completely is what I've been forced to do. |
|
@whorfin this is a different issue, can you please open a new bug report in GH? I'll take a look ASAP |
|
In 0.42.0 I'm still having the "too many open files" error spammed in my logs. If it helps to reproduce it, it seems to happen every time I press the update collection button in Strawberry. |
|
@KingDuckZ A chunk of the log (loglevel=debug) can help. You can send it directly to me if it contains too much sensitive data (deluan at navidrome org) |
|
Sorry for the delay @deluan, I emailed you the logs. On a closer look at the cover cache in the Strawberry directory, I see it's 2.2 GiB and growing (update is still at 37%). It's clear there are a lot of duplicate covers in there, for example there are the first few lines printed by So I don't know if it's a bug with Strawberry or with Navidrome, but hash Edit: I deleted my local cover cache and re-started the update, watching the thumbnails in Dolphin as they get created it's immediately clear there are dozens of copies of the same images. I think there should be only 1 copy per disc, or ideally only 1 per album if all discs share the same cover art (same hash). I can report this to the Strawberry bug tracker if you believe it's an issue on their end. |
|
Hey folks! I finally found the cause of this bug and it is now fixed in the latest builds. If you still seeing this issue, please let me know. Thanks for your cooperation and patience! |
|
I had seemingly the same result on 0.44.0 (b16d473) using the mac binary on a mac mini server. I do not know if this is related so forgive me if this is just confusing the issue. The album images wouldn't load unless previously loaded as in the op, but eventually the UI became completely unresponsive until service restart. The log files were filling up with "too many open files". But in this case what seemed to solve it is moving the binary from the /opt folder to a ~/ folder. I am having a horrible time with permissions in this folder since a macOS upgrade and eventually just moved everything out of there. I did get the issue again this morning but a simple browser hard reload solved it. UPDATE: So moving out of /opt helped a lot but I am still getting missing covers and UI freezing needing service restart. too many open files |
|
Hey @TheFlatworm, can you try the latest release 0.44.1? Anyway, this seems to be unrelated, so if you are still having these issues after upgrading to 0.44.1, please open a new issue with all details, and I'll investigate it. Thanks! |
|
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. |
Hardware:
Steps to reproduce the bug:
At one point, the images will break, and will continue staying that way until a service restart. Only the images that had been cached beforehand will be visible. Affects the *sonic API as well. Disabling the image cache seems to circumvent the issue.
Excerpts from the log:
The text was updated successfully, but these errors were encountered: