[PROBLEM] Problems with MPD 0.22~git input_cache thread

[hestehandler]

Just had MPD crash for me. Version 0.22~git using 3GBs for cache.

Code:

Code:

Jul 22 17:03:59 moode sudo[8686]:     root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/local/bin/mediainfo --Inform=Audio;file:///var/www/mediainfo.tpl /var/lib/mpd/music/NAS/
Jul 22 17:03:59 moode sudo[8686]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 22 17:03:59 moode sudo[8686]: pam_unix(sudo:session): session closed for user root
Jul 22 17:03:59 moode sudo[8698]:     root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/local/bin/mediainfo --Inform=Audio;file:///var/www/mediainfo.tpl /var/lib/mpd/music/NAS/
Jul 22 17:03:59 moode sudo[8698]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 22 17:04:00 moode sudo[8698]: pam_unix(sudo:session): session closed for user root
Jul 22 17:07:52 moode nmbd[468]: [2020/07/22 17:07:52.217590,  0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response)
Jul 22 17:07:52 moode nmbd[468]:   query_name_response: Multiple (2) responses received for a query on subnet 192.168.1.5 for name WORKGROUP<1d>.
Jul 22 17:07:52 moode nmbd[468]:   This response was from IP 192.168.1.20, reporting an IP address of 192.168.1.20.
Jul 22 17:08:19 moode mpdscribble[353]: mpd error (5): Connection reset by peer
Jul 22 17:08:19 moode systemd[1]: mpd.service: Main process exited, code=killed, status=6/ABRT
Jul 22 17:08:19 moode systemd[1]: mpd.service: Failed with result 'signal'.
Jul 22 17:08:22 moode systemd[1]: Started Music Player Daemon.
Jul 22 17:08:24 moode sudo[9580]:     root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/local/bin/mediainfo --Inform=Audio;file:///var/www/mediainfo.tpl /var/lib/mpd/music/NAS/
Jul 22 17:08:24 moode sudo[9580]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 22 17:08:24 moode sudo[9580]: pam_unix(sudo:session): session closed for user root
Jul 22 17:08:41 moode sudo[9644]: www-data : TTY=unknown ; PWD=/var/www ; USER=root ; COMMAND=/usr/local/bin/mediainfo --Inform=Audio;file:///var/www/mediainfo.tpl /var/lib/mpd/mus
Jul 22 17:08:41 moode sudo[9644]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 22 17:08:41 moode sudo[9644]: pam_unix(sudo:session): session closed for user root
Jul 22 17:08:42 moode sudo[9657]:     root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/local/bin/mediainfo --Inform=Audio;file:///var/www/mediainfo.tpl /var/lib/mpd/music/NAS/
Jul 22 17:08:42 moode sudo[9657]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 22 17:08:42 moode sudo[9657]: pam_unix(sudo:session): session closed for user root

Jul 22 17:08:19 moode systemd[1]: mpd.service: Main process exited, code=killed, status=6/ABRT seems to be the salient point, but what caused this abort I don’t know. MPD log says this:


Code:

Code:

Jul 22 17:08 : player: played "NAS/Mother/The (Hypothetical) Prophets/Around the World With the Prophets/05 Person to Person.m4a"
terminate called after throwing an instance of 'std::bad_alloc'
 what():  std::bad_alloc

So something (likely the new input_cache functionality) was not able to allocate more memory (as I understand the error description), and aborted MPD.

[TheOldPresbyope]

I'm curious to know if you saw any "out of memory" messages in /var/log/kern.log

something like 

Code:

grep -i "out of memory" /var/log/kern.log

Regards,
Kent

[hestehandler]

kern.log is 0 bytes. Is kernel logging disabled by default?

[TheOldPresbyope]

kern.log is 0 bytes. Is kernel logging disabled by default?

Oops. I don't know about the default in Raspbian, actually. I'm more used to dealing with the OOM killer on other Debian-based systems.

Should also be possible to get at the same messages using dmesg or journalctl -k

Regards,
Kent

[hestehandler]

Yes I googled it and apparently it’s all in journalctl under RaspiOS (so you should probably delete that kern.log from Moode). However, there was nothing memory related logged there either. The only kernel messages were from the boot sequence, after that nothing.

[TheOldPresbyope]

As usual, the InterWeb™ is full of contradictory information. I can't find an authoritative statement for Raspberry Pi OS (aka Raspbian) of the maximum memory space addressable in a 32-bit process (our userland is still 32-bit [1]) running on a 64-bit kernel. However, 3GB is certainly up there and I was keying off the "std::bad-alloc" message. 

Were you watching the mem usage? Did it appear that MPD died when the cache was full?

I know this is a heat-it-and-beat-it solution but what happens if you dial the cache size down some and let the system run?

It should be clear I don't understand what the input_cache function really does. The cursory description in the manual doesn't make sense to me now on rereading.

In any case, I don't see the practical benefit of gigabytes of cache given the way we play tracks.

Just my 2 cents worth 

Regards,
Kent

[1] In separate effort I'm trying to build moOde in the current beta 64-bit Raspberry Pi OS.  It's early days yet.

[hestehandler]

As usual, the InterWeb™ is full of contradictory information. I can't find an authoritative statement for Raspberry Pi OS (aka Raspbian) of the maximum memory space addressable in a 32-bit process (our userland is still 32-bit [1]) running on a 64-bit kernel. However, 3GB is certainly up there and I was keying off the "std::bad-alloc" message. 

Were you watching the mem usage? Did it appear that MPD died when the cache was full?

I know this is a heat-it-and-beat-it solution but what happens if you dial the cache size down some and let the system run?

It should be clear I don't understand what the input_cache function really does. The cursory description in the manual doesn't make sense to me now on rereading.

In any case, I don't see the practical benefit of gigabytes of cache given the way we play tracks.

Just my 2 cents worth 

Regards,
Kent

[1] In separate effort I'm trying to build moOde in the current beta 64-bit Raspberry Pi OS.  It's early days yet.

I’m pretty sure that it crashed as the cache was overfilled. I had at other occasions been watching proceedings in htop, and it progressively fills the cache up track after track as they are loaded just-in-time before they are played, then (and I’m guessing now) prune the oldest tracks to make room for new ones as the cache gets near its limit. Probably just a bug in the functionality of cache if I were to make a guess.

NB: 32 bits can address 4,294,967,296 bytes.

[TheOldPresbyope]

NB: 32 bits can address 4,294,967,296 bytes.

Yes, mathematically that's true. In the world of real software it's a hard upper limit but not necessarily the actual limit for a process in an operating system. Use your favorite search engine.

Regards,
Kent