mpd at 100% CPU, library not catalogued [rpi3, 2.348]

Hi - I’ve used Volumio for a while, but I had extra time over the Christmas holiday and decided to reinstall Volumio to a Raspberry Pi 3. Unfortunately, I took something that “ain’t broke” and now it is broke (stealing from the phrase “if it ain’t broke, don’t fix it”).

Volumio starts to catalog my library but hangs midway through the process. I reinstalled the image last night, and when I checked this morning, it’s still misbehaving. I can still play music. I can still access the web interface. It still shows a partial catalog of my music.

I’m using:

  • Raspberry Pi 3
  • built-in wifi
  • Volumio is on SD card (since Pi3’s can use USB drives directly, but that’s not what I’m doing)
  • music is on attached external 3tb HD (I actually also tried a different external 3tb drive with the same results)
  • latest Volumio image - VERSION: 2.348

See MPD at 100% CPU:

top - 17:45:22 up 10:04,  2 users,  load average: 1.23, 1.26, 1.21
Tasks: 147 total,   1 running, 146 sleeping,   0 stopped,   0 zombie
%Cpu(s): 14.1 us, 14.7 sy,  0.0 ni, 71.3 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem:   1000308 total,   850108 used,   150200 free,   224188 buffers
KiB Swap:        0 total,        0 used,        0 free.   165820 cached Mem

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
 1184 mpd       20   0  470896 241852  20732 S 107.4 24.2 611:19.48 mpd
 1075 volumio   20   0  204644  79920  21288 S   1.3  8.0   4:58.78 node
  935 headpho+  20   0  233840  27636   6012 S   0.7  2.8   2:01.04 python
   89 root     -51   0       0      0      0 S   0.3  0.0   2:32.00 irq/92-mmc1
  359 root      20   0       0      0      0 S   0.3  0.0   1:05.61 brcmf_wdog/mmc1
 1164 volumio   20   0  102640   7764   6728 S   0.3  0.8   2:18.58 upmpdcli
18652 root      20   0       0      0      0 S   0.3  0.0   0:00.07 kworker/3:2
20252 volumio   20   0    3452   2108   1732 R   0.3  0.2   0:00.12 top
20275 root      20   0       0      0      0 D   0.3  0.0   0:00.01 kworker/u8:3
    1 root      20   0    5432   4184   2860 S   0.0  0.4   0:20.78 systemd
    2 root      20   0       0      0      0 S   0.0  0.0   0:00.02 kthreadd
    3 root      20   0       0      0      0 S   0.0  0.0   0:02.98 ksoftirqd/0
    5 root       0 -20       0      0      0 S   0.0  0.0   0:00.00 kworker/0:0H
    7 root      20   0       0      0      0 S   0.0  0.0   0:29.80 rcu_sched
    8 root      20   0       0      0      0 S   0.0  0.0   0:00.00 rcu_bh
    9 root      rt   0       0      0      0 S   0.0  0.0   0:03.00 migration/0
   10 root       0 -20       0      0      0 S   0.0  0.0   0:00.00 lru-add-drain
   11 root      20   0       0      0      0 S   0.0  0.0   0:00.00 cpuhp/0
   12 root      20   0       0      0      0 S   0.0  0.0   0:00.00 cpuhp/1
   13 root      rt   0       0      0      0 S   0.0  0.0   0:03.20 migration/1
   14 root      20   0       0      0      0 S   0.0  0.0   0:01.86 ksoftirqd/1
   16 root       0 -20       0      0      0 S   0.0  0.0   0:00.00 kworker/1

(it’s pretty obvious that it’s been racing since the pi booted, too…)

/var/log/volumio.log is pretty uninteresting - it keeps repeating the same line:

volumio@music:/var/log$ tail volumio.log
2018-01-03T17:47:07.537Z - info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
2018-01-03T17:47:11.546Z - info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
2018-01-03T17:47:15.602Z - info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
2018-01-03T17:47:19.620Z - info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
2018-01-03T17:47:23.689Z - info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
2018-01-03T17:47:27.734Z - info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
2018-01-03T17:47:31.799Z - info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
2018-01-03T17:47:35.813Z - info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
2018-01-03T17:47:39.831Z - info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
2018-01-03T17:47:43.889Z - info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
volumio@music:/var/log$

Just in case boot.log helps…

volumio@music:/var/log$ cat boot.log
[  OK  ] Started Show Plymouth Boot Screen.
[  OK  ] Reached target Paths.
         Mounting /var/spool/cups/tmp...
         Mounting Configuration File System...
         Starting Apply Kernel Variables...
[  OK  ] Mounted /var/spool/cups/tmp.
[  OK  ] Mounted Configuration File System.
[  OK  ] Started Apply Kernel Variables.
[  OK  ] Started LSB: NFS support files common to client and server.
[  OK  ] Reached target Sound Card.
[  OK  ] Found device /dev/mmcblk0p1.
         Starting File System Check on /dev/mmcblk0p1...
[  OK  ] Created slice system-ifup.slice.
[   13.029102] systemd-fsck[343]: fsck.fat 3.0.27 (2014-11-12)
[   13.031002] systemd-fsck[343]: /dev/mmcblk0p1: 146 files, 70208/123044 clusters
[  OK  ] Started File System Check on /dev/mmcblk0p1.
         Mounting /boot...
[  OK  ] Mounted /boot.
[  OK  ] Reached target Local File Systems.
         Starting Tell Plymouth To Write Out Runtime Data...
[  OK  ] Reached target Remote File Systems.
         Starting Trigger Flushing of Journal to Persistent Storage...
         Starting Create Volatile Files and Directories...
         Starting LSB: Raise network interfaces....
[  OK  ] Started Tell Plymouth To Write Out Runtime Data.
[  OK  ] Started Trigger Flushing of Journal to Persistent Storage.
[  OK  ] Started Create Volatile Files and Directories.
[  OK  ] Created slice system-systemd\x2drfkill.slice.
         Starting Load/Save RF Kill Switch Status of rfkill0...
         Starting Update UTMP about System Boot/Shutdown...
[  OK  ] Started Load/Save RF Kill Switch Status of rfkill0.
[  OK  ] Started Update UTMP about System Boot/Shutdown.
[  OK  ] Started LSB: Raise network interfaces..
         Starting ifup for wlan0...
[  OK  ] Started ifup for wlan0.
         Starting ifup for eth0...
[  OK  ] Started ifup for eth0.
[  OK  ] Reached target System Initialization.
[  OK  ] Listening on Avahi mDNS/DNS-SD Stack Activation Socket.
[  OK  ] Listening on mpd.socket.
[  OK  ] Listening on D-Bus System Message Bus Socket.
[  OK  ] Reached target Sockets.
[  OK  ] Reached target Timers.
         Starting Restore Sound Card State...
[  OK  ] Reached target Basic System.
         Starting Entropy daemon using the HAVEGE algorithm...
[  OK  ] Started Entropy daemon using the HAVEGE algorithm.
         Starting hotspot.service...
[  OK  ] Started hotspot.service.
         Starting dhcpd.service...
         Starting dnsmasq.service...
         Starting Volumio Iptables Module...
[  OK  ] Started Volumio Iptables Module.
         Starting mount disks automatically with standby...
[  OK  ] Started mount disks automatically with standby.
         Starting UPnP Renderer front-end to MPD...
[  OK  ] Started UPnP Renderer front-end to MPD.
         Starting volumio-remote-updater.service...
[  OK  ] Started volumio-remote-updater.service.
         Starting Volumio SSH enabler...
[  OK  ] Started Volumio SSH enabler.
         Starting Wireless Services...
         Starting dhcpcd on all interfaces...
         Starting Login Service...
         Starting Restart Volumio Network...
[  OK  ] Started Restart Volumio Network.
         Starting LSB: Load kernel modules needed to enable cpufreq scaling...
         Starting Avahi mDNS/DNS-SD Stack...
         Starting D-Bus System Message Bus...
[  OK  ] Started D-Bus System Message Bus.
[  OK  ] Started Restore Sound Card State.
[  OK  ] Started dhcpcd on all interfaces.
[  OK  ] Started LSB: Load kernel modules needed to enable cpufreq scaling.
         Starting LSB: set CPUFreq kernel parameters...
[  OK  ] Reached target Network.
         Starting Transmission BitTorrent Daemon...
         Starting /etc/rc.local Compatibility...
         Starting Music Player Daemon...
         Starting Permit User Sessions...
[  OK  ] Reached target Network is Online.
         Starting LSB: starts instance of Headphones...
         Starting LSB: keep memory of all UPnP devices that a...d themselves...
         Starting LSB: start Winbind daemon...
         Starting LSB: start Samba daemons for the AD DC...
         Starting LSB: Start NTP daemon...
         Starting LSB: start Samba NetBIOS nameserver (nmbd)...
         Starting LSB: Brings up/down network automatically...
         Starting LSB: Brings up/down network automatically...
         Starting LSB: Advanced IEEE 802.11 management daemon...
[  OK  ] Started /etc/rc.local Compatibility.
[  OK  ] Started Permit User Sessions.
[  OK  ] Started LSB: Advanced IEEE 802.11 management daemon.
[  OK  ] Started LSB: Brings up/down network automatically.
[  OK  ] Started LSB: keep memory of all UPnP devices that an...ced themselves.
[  OK  ] Started LSB: set CPUFreq kernel parameters.
[  OK  ] Started Avahi mDNS/DNS-SD Stack.
[  OK  ] Started Login Service.
         Stopping Wireless Services...
         Starting OpenBSD Secure Shell server...
         Starting LSB: RPC portmapper replacement...
         Starting Disk Manager (legacy version)...
         Starting Hold until boot process finishes up...
         Starting Terminate Plymouth Boot Screen...
volumio@music:/var/log$

Ahh - reviewing bootlog reminds me - I installed Transmission and Headphones to the Volumio image, but neither should interfere with Volumio’s attempts to catalog, right? Right??? ha

Notice that it at least starts the cataloging process:

Here’s the list of a partially catalogued Volumio … notice it stops around “J” alphabetically:

Thoughts? Suggestions? Thank you!

Probably not related but I had to set Web Album Art:off in settings > My Music because MPD was running 100% for hours & UI unresponsive.

I turned off album art, but it doesn’t seem to have made a difference. Thanks for the suggestion though! I’m not a huge fan of album art anyway.