slimserver Server fills the entire disk with logs

I am running Raspberry Pi 4 Model B Rev 1.1

logitechmediaserver 8.5.2 deb package

In the last 6 years of running LMS, this happened to me for the second time:

thread 'main' panicked at 'Spotify servers returned an error. Restart librespot.', core/src/mercury/mod.rs:205:13 in syslog:

and then: Oct 15 07:00:40 LMS squeezeboxserver[421]: 0x712514810: - Oct 15 07:00:40 LMS squeezeboxserver[421]: 0x1325ac810: - Oct 15 07:00:40 LMS squeezeboxserver[421]: 0x713514810: - Oct 15 07:00:40 LMS squeezeboxserver[421]: 0x1335ac810: - Oct 15 07:00:40 LMS squeezeboxserver[421]: 0x514810 - 714: Oct 15 07:00:40 LMS squeezeboxserver[421]: 0x1345ac810: - Oct 15 07:00:40 LMS squeezeboxserver[421]: 0x 514810715 - : Oct 15 07:00:40 LMS squeezeboxserver[421]: 0x1355ac810: - Oct 15 07:00:40 LMS squeezeboxserver[421]: 0x 514810716 - : Oct 15 07:00:40 LMS squeezeboxserver[421]: 0x5ac810 - 136: Oct 15 07:00:40 LMS squeezeboxserver[421]: 7170x514810: - Oct 15 07:00:40 LMS squeezeboxserver[421]: 0x 5ac810137 - : Oct 15 07:00:40 LMS squeezeboxserver[421]: 7180x: 514810 - 0x Oct 15 07:00:40 LMS squeezeboxserver[421]: 5ac810 - 138: Oct 15 07:00:40 LMS squeezeboxserver[421]: 7190x: 514810 - 0x Oct 15 07:00:40 LMS squeezeboxserver[421]: 5ac810 139 - : Oct 15 07:00:40 LMS squeezeboxserver[421]: 7200x: 514810 - 0x Oct 15 07:00:40 LMS squeezeboxserver[421]: 5ac810 - 140: Oct 15 07:00:40 LMS squeezeboxserver[421]: 7210x: 514810 - 0x Oct 15 07:00:40 LMS squeezeboxserver[421]: 5ac810 - 141: Oct 15 07:00:40 LMS squeezeboxserver[421]: 7220x: 514810 - 0x Oct 15 07:00:40 LMS squeezeboxserver[421]: 5ac810 - 142: Oct 15 07:00:40 LMS squeezeboxserver[421]: 7230x: 514810 - 0x Oct 15 07:00:40 LMS squeezeboxserver[421]: 5ac810 - 143: Oct 15 07:00:40 LMS squeezeboxserver[421]: 0x724514810: - 0x Oct 15 07:00:40 LMS squeezeboxserver[421]: 5ac810 - 144: Oct 15 07:00:40 LMS squeezeboxserver[421]: 7250x: 514810 - 0x Oct 15 07:00:40 LMS squeezeboxserver[421]: 5ac810 - 145: Oct 15 07:00:40 LMS squeezeboxserver[421]: 0x726514810: - 0x Oct 15 07:00:40 LMS squeezeboxserver[421]: 5ac810 - 146: Oct 15 07:00:40 LMS squeezeboxserver[421]: 7270x: 514810 - 0x Oct 15 07:00:40 LMS squeezeboxserver[421]: 5ac810 - 147: Oct 15 07:00:40 LMS squeezeboxserver[421]: 0x728514810: - 0x

10GB of logs like this until the HDD was full on the server

Oct 16 '24 20:10 tbrandysky

LMS or the operating system should rotate the log files automatically. What log file is this? It doesn't look like one generated by LMS itself.

Oct 17 '24 04:10 michaelherger

This is daemon.log, managed by syslog (which also rotates logs automatically). It collects messages from LMS. The issue is some part in LMS crashed and LMS consequently generated 10GB of messages in just 2 days until it filled all free space with strange error messages.

It started with thread 'main' panicked at 'Spotify servers returned an error. Restart librespot.', core/src/mercury/mod.rs:205:13 and then 10GB of strange error messages like this for the rest of the free HDD space:

Another part of the messages (although it's still the same for the whole 10GB of logs):

Oct 16 21:01:58 LMS squeezeboxserver[421]: : 6156976 0x : 0x0x524810 51c8105ec810 - - - 0x Oct 16 21:01:58 LMS squeezeboxserver[421]: 5bc8106095475 Oct 16 21:01:58 LMS squeezeboxserver[421]: - : 61115506186716 : : Oct 16 21:01:58 LMS squeezeboxserver[421]: 61569770x : 5248100x0x - 51c8105ec810 - - Oct 16 21:01:58 LMS squeezeboxserver[421]: 6095476 Oct 16 21:01:58 LMS squeezeboxserver[421]: : 61115516186717 : : 0x 0x5248100x5bc8100x - 5ec810 - 51c810 - - Oct 16 21:01:58 LMS squeezeboxserver[421]: Oct 16 21:01:58 LMS squeezeboxserver[421]: Oct 16 21:01:58 LMS squeezeboxserver[421]: 6095477 Oct 16 21:01:58 LMS squeezeboxserver[421]: 615697861867186111552: : : : 0x0x0x0x52481051c8105bc8105ec810 - - - - Oct 16 21:01:58 LMS squeezeboxserver[421]: 6095478611155361569796186719: : : : 0x 0x0x5248100x5bc8105ec810 - - 51c810 - - Oct 16 21:01:58 LMS squeezeboxserver[421]: 6156980609547961867206111554: : : : - 0x Oct 16 21:01:58 LMS squeezeboxserver[421]: : 59c810 Oct 16 21:01:58 LMS squeezeboxserver[421]: - 61714066181876 Oct 16 21:01:58 LMS squeezeboxserver[421]: 0x: : 60c810 6177575 - : 0x 0x Oct 16 21:01:58 LMS squeezeboxserver[421]: 574810 54c810 - 0x - 616792359c810 Oct 16 21:01:58 LMS squeezeboxserver[421]: : - Oct 16 21:01:58 LMS squeezeboxserver[421]: 61714076181877 : : Oct 16 21:01:58 LMS squeezeboxserver[421]: 0x 60c8106177576 - : 0x0x 54c810 Oct 16 21:01:58 LMS squeezeboxserver[421]: 574810 - - 61679240x: 59c810 Oct 16 21:01:58 LMS squeezeboxserver[421]: - 6181878 6171408: 0x: Oct 16 21:01:58 LMS squeezeboxserver[421]: 60c810 6177577 - : 0x0x Oct 16 21:01:58 LMS squeezeboxserver[421]: 57481054c810 6167925 - - 0x: 59c810 Oct 16 21:01:58 LMS squeezeboxserver[421]: - 617140961818790x: : Oct 16 21:01:58 LMS squeezeboxserver[421]: 60c810 6177578 - : 0x0x Oct 16 21:01:58 LMS squeezeboxserver[421]: 54c810574810 6167926 - - 0x: 59c810 Oct 16 21:01:58 LMS squeezeboxserver[421]: - 618188061714100x: : Oct 16 21:01:58 LMS squeezeboxserver[421]: 60c810 6177579 - : 0x0x Oct 16 21:01:58 LMS squeezeboxserver[421]: 54c810574810 - 6167927 - 0x: 59c810 Oct 16 21:01:58 LMS squeezeboxserver[421]:
Oct 16 21:01:58 LMS squeezeboxserver[421]: - 6181881 6171411: 0x: Oct 16 21:01:58 LMS squeezeboxserver[421]: 60c810 - 6177580 0x0x: 54c810 Oct 16 21:01:58 LMS squeezeboxserver[421]: 574810 - 6167928 - : 0x Oct 16 21:01:58 LMS squeezeboxserver[421]: 59c810 Oct 16 21:01:58 LMS squeezeboxserver[421]: - 618188261714120x: : 60c810 Oct 16 21:01:58 LMS squeezeboxserver[421]: - 6177581 : 0x Oct 16 21:01:58 LMS squeezeboxserver[421]: 0x54c810 6167929574810 - : - 0x Oct 16 21:01:58 LMS squeezeboxserver[421]: 59c810

Oct 17 '24 09:10 tbrandysky

I also found this issue here:

https://forums.slimdevices.com/forum/user-forums/3rd-party-software/112342-spotty-4-7-0#post1514107

Oct 17 '24 09:10 tbrandysky

I also use your Spotty plugin (which is great btw ;), don't know whether it's related somehow.

Oct 17 '24 09:10 tbrandysky

I'd need more of that log file to understand where those numbers are coming from. They might be a stack trace or something. But if the spotty was failing all the time, you'd noticed that spotty wouldn't work. Maybe you can send me a compressed copy of the most recent few hundred lines?

Oct 17 '24 13:10 michaelherger

here is the link to the compressed log containing only messages from LMS: https://drive.google.com/file/d/1kts09-tdrz61isfqtOqqkF35AjNAKJc6/view?usp=sharing

maybe line 567 could be some lead:

567 Oct 15 07:00:40 LMS squeezeboxserver[421]: 564: thread ' 0xmain5ac810' panicked at ' - Spotify servers returned an error. Restart librespot.', 568 Oct 15 07:00:40 LMS squeezeboxserver[421]: core/src/mercury/mod.rs :565205: : 13 569 Oct 15 07:00:40 LMS squeezeboxserver[421]: 0x5ac810stack backtrace:

I've been using Spotty for many years on a few devices at home almost every day. I haven't noticed any hiccups or crashes until this occasional incident.

Oct 17 '24 14:10 tbrandysky

That file is massive (135M lines). But it looks more like a Spotty issue than LMS. If you have Spotty Connect mode enabled, please disable it. Did that even work? It looks as if the connect helper was constantly crashing.

Did you build the Spotty helper yourself? Or is this a regular installation?

Oct 18 '24 09:10 michaelherger

I've used Spotty Connect only occasionally, but it worked just fine. I can disable it as I don't use it often. I didn't build anything myself, I use only regular installation from packages.

As I mentioned before, this issue happened to me already once, maybe twice, in the last, let's say, 6-8 years using LMC on my RaspberryPi. It can be some coincidence because normally everything goes smoothly. But apparently, there is some hidden glitch somewhere.

Oct 18 '24 13:10 tbrandysky