Dec 26 13:30:05 volumio go-librespot[1779]: time="2025-12-26T13:30:05+03:00" level=trace msg="sent dealer ping" Dec 26 13:30:06 volumio go-librespot[1779]: time="2025-12-26T13:30:06+03:00" level=trace msg="received dealer pong" Dec 26 13:30:09 volumio go-librespot[1779]: time="2025-12-26T13:30:09+03:00" level=debug msg="fetched chunk 12/22, size: 524288" uri="spotify:track:0eSqyR8UbK38kT64KkRw0e" Dec 26 13:30:11 volumio volumio[1378]: info: Reading package lists... Dec 26 13:30:11 volumio sudo[23190]: pam_unix(sudo:session): session closed for user root Dec 26 13:30:11 volumio sudo[23372]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/chown -R volumio /data/plugins/user_interface/peppyspectrum /data/INTERNAL/PeppySpectrum/Templates Dec 26 13:30:11 volumio sudo[23372]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 26 13:30:11 volumio sudo[23372]: pam_unix(sudo:session): session closed for user root Dec 26 13:30:11 volumio sudo[23374]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/chgrp -R volumio /data/plugins/user_interface/peppyspectrum /data/INTERNAL/PeppySpectrum/Templates Dec 26 13:30:11 volumio sudo[23374]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 26 13:30:12 volumio sudo[23374]: pam_unix(sudo:session): session closed for user root Dec 26 13:30:12 volumio volumio[1378]: info: installing apt packages Dec 26 13:30:12 volumio sudo[23377]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/apt-get -y install python3-pygame python3-pillow libfftw3-dev Dec 26 13:30:12 volumio sudo[23377]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 26 13:30:13 volumio volumio[1378]: info: Reading package lists... Dec 26 13:30:13 volumio volumio[1378]: info: Building dependency tree... Dec 26 13:30:13 volumio volumio[1378]: info: Reading state information... Dec 26 13:30:14 volumio volumio[1378]: info: python3-pygame is already the newest version (2.1.2+dfsg-5). Dec 26 13:30:14 volumio volumio[1378]: info: libfftw3-dev is already the newest version (3.3.10-1). Dec 26 13:30:14 volumio volumio[1378]: info: The following additional packages will be installed: Dec 26 13:30:14 volumio volumio[1378]: info: bzip2 file libimagequant0 libraqm0 mailcap mime-support python3-olefile Dec 26 13:30:14 volumio volumio[1378]: info: Suggested packages: Dec 26 13:30:14 volumio volumio[1378]: info: bzip2-doc python-pil-doc Dec 26 13:30:14 volumio volumio[1378]: info: The following NEW packages will be installed: Dec 26 13:30:14 volumio volumio[1378]: info: bzip2 file libimagequant0 libraqm0 mailcap mime-support python3-olefile Dec 26 13:30:14 volumio volumio[1378]: info: python3-pil Dec 26 13:30:17 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Dec 26 13:30:18 volumio volumio[1378]: info: 0 upgraded, 8 newly installed, 0 to remove and 18 not upgraded. Dec 26 13:30:18 volumio volumio[1378]: info: Need to get 638 kB of archives. Dec 26 13:30:18 volumio volumio[1378]: info: After this operation, 2248 kB of additional disk space will be used. Dec 26 13:30:18 volumio volumio[1378]: info: Get:1 http://raspbian.raspberrypi.com/raspbian bookworm/main armhf bzip2 armhf 1.0.8-5+b2 [47.4 kB] Dec 26 13:30:19 volumio volumio[1378]: info: Get:2 http://raspbian.mirror.net.in/raspbian/raspbian bookworm/main armhf file armhf 1:5.44-3 [41.5 kB] Dec 26 13:30:19 volumio volumio[1378]: info: Get:3 http://raspbian.raspberrypi.com/raspbian bookworm/main armhf mailcap all 3.70+nmu1 [32.0 kB] Dec 26 13:30:19 volumio volumio[1378]: info: Get:4 http://raspbian.mirror.net.in/raspbian/raspbian bookworm/main armhf mime-support all 3.66 [10.9 kB] Dec 26 13:30:19 volumio volumio[1378]: info: Get:5 http://raspbian.mirror.net.in/raspbian/raspbian bookworm/main armhf libimagequant0 armhf 2.17.0-1 [28.0 kB] Dec 26 13:30:20 volumio volumio[1378]: info: Get:6 http://raspbian.mirror.net.in/raspbian/raspbian bookworm/main armhf libraqm0 armhf 0.7.0-4.1 [9176 B] Dec 26 13:30:20 volumio volumio[1378]: info: Get:7 http://raspbian.mirror.net.in/raspbian/raspbian bookworm/main armhf python3-olefile all 0.46-3 [36.1 kB] Dec 26 13:30:20 volumio volumio[1378]: info: Get:8 http://raspbian.raspberrypi.com/raspbian bookworm/main armhf python3-pil armhf 9.4.0-1.1+deb12u1 [433 kB] Dec 26 13:30:22 volumio volumio[1378]: info: Fetched 638 kB in 6s (105 kB/s) Dec 26 13:30:22 volumio volumio[1378]: info: Selecting previously unselected package bzip2. Dec 26 13:30:22 volumio go-librespot[1779]: time="2025-12-26T13:30:22+03:00" level=debug msg="fetched chunk 13/22, size: 524288" uri="spotify:track:0eSqyR8UbK38kT64KkRw0e" Dec 26 13:30:23 volumio volumio[1378]: [620B blob data] Dec 26 13:30:23 volumio volumio[1378]: info: Preparing to unpack .../0-bzip2_1.0.8-5+b2_armhf.deb ... Dec 26 13:30:23 volumio volumio[1378]: info: Unpacking bzip2 (1.0.8-5+b2) ... Dec 26 13:30:23 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Dec 26 13:30:23 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Dec 26 13:30:23 volumio volumio[1378]: info: Selecting previously unselected package file. Dec 26 13:30:23 volumio volumio[1378]: info: Preparing to unpack .../1-file_1%3a5.44-3_armhf.deb ... Dec 26 13:30:23 volumio volumio[1378]: info: Unpacking file (1:5.44-3) ... Dec 26 13:30:24 volumio volumio[1378]: info: Selecting previously unselected package mailcap. Dec 26 13:30:24 volumio volumio[1378]: info: Preparing to unpack .../2-mailcap_3.70+nmu1_all.deb ... Dec 26 13:30:24 volumio volumio[1378]: info: Unpacking mailcap (3.70+nmu1) ... Dec 26 13:30:24 volumio volumio[1378]: info: Selecting previously unselected package mime-support. Dec 26 13:30:24 volumio volumio[1378]: info: Preparing to unpack .../3-mime-support_3.66_all.deb ... Dec 26 13:30:24 volumio volumio[1378]: info: Unpacking mime-support (3.66) ... Dec 26 13:30:24 volumio volumio[1378]: info: Selecting previously unselected package libimagequant0:armhf. Dec 26 13:30:24 volumio volumio[1378]: info: Preparing to unpack .../4-libimagequant0_2.17.0-1_armhf.deb ... Dec 26 13:30:24 volumio volumio[1378]: info: Unpacking libimagequant0:armhf (2.17.0-1) ... Dec 26 13:30:24 volumio volumio[1378]: info: Selecting previously unselected package libraqm0:armhf. Dec 26 13:30:24 volumio volumio[1378]: info: Preparing to unpack .../5-libraqm0_0.7.0-4.1_armhf.deb ... Dec 26 13:30:24 volumio volumio[1378]: info: Unpacking libraqm0:armhf (0.7.0-4.1) ... Dec 26 13:30:24 volumio volumio[1378]: info: Selecting previously unselected package python3-olefile. Dec 26 13:30:24 volumio volumio[1378]: info: Preparing to unpack .../6-python3-olefile_0.46-3_all.deb ... Dec 26 13:30:24 volumio volumio[1378]: info: Unpacking python3-olefile (0.46-3) ... Dec 26 13:30:24 volumio volumio[1378]: info: Selecting previously unselected package python3-pil:armhf. Dec 26 13:30:24 volumio volumio[1378]: info: Preparing to unpack .../7-python3-pil_9.4.0-1.1+deb12u1_armhf.deb ... Dec 26 13:30:25 volumio volumio[1378]: info: Unpacking python3-pil:armhf (9.4.0-1.1+deb12u1) ... Dec 26 13:30:25 volumio ntpd[1061]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 26 13:30:25 volumio ntpd[1061]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Dec 26 13:30:25 volumio ntpd[1061]: DNS: Pool skipping: 178.61.152.98 Dec 26 13:30:25 volumio ntpd[1061]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 Dec 26 13:30:25 volumio volumio[1378]: info: Setting up python3-olefile (0.46-3) ... Dec 26 13:30:26 volumio ntpd[1061]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 26 13:30:26 volumio ntpd[1061]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Dec 26 13:30:26 volumio ntpd[1061]: DNS: Pool skipping: 178.61.152.98 Dec 26 13:30:26 volumio ntpd[1061]: DNS: Pool taking: 2401:c080:3400:2979:5400:5ff:fe35:2d0d Dec 26 13:30:26 volumio ntpd[1061]: DNS: Pool taking: 2a05:f480:2c00:1d51:9f31:83c:284a:2948 Dec 26 13:30:26 volumio ntpd[1061]: DNS: Pool taking: 2405:fc00::123 Dec 26 13:30:26 volumio ntpd[1061]: DNS: Pool taking: 2a01:4ff:2f0:21f5::1 Dec 26 13:30:26 volumio ntpd[1061]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 Dec 26 13:30:26 volumio volumio[1378]: info: Setting up file (1:5.44-3) ... Dec 26 13:30:26 volumio volumio[1378]: info: Setting up bzip2 (1.0.8-5+b2) ... Dec 26 13:30:26 volumio volumio[1378]: info: Setting up libraqm0:armhf (0.7.0-4.1) ... Dec 26 13:30:26 volumio volumio[1378]: info: Setting up libimagequant0:armhf (2.17.0-1) ... Dec 26 13:30:26 volumio volumio[1378]: info: Setting up mailcap (3.70+nmu1) ... Dec 26 13:30:26 volumio volumio[1378]: info: Setting up mime-support (3.66) ... Dec 26 13:30:26 volumio volumio[1378]: info: Setting up python3-pil:armhf (9.4.0-1.1+deb12u1) ... Dec 26 13:30:27 volumio ntpd[1061]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 26 13:30:27 volumio ntpd[1061]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Dec 26 13:30:27 volumio ntpd[1061]: DNS: Pool skipping: 178.61.152.98 Dec 26 13:30:27 volumio ntpd[1061]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 Dec 26 13:30:27 volumio volumio[1378]: info: Processing triggers for man-db (2.11.2-2) ... Dec 26 13:30:28 volumio ntpd[1061]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 26 13:30:28 volumio volumio[1378]: info: Processing triggers for libc-bin (2.36-9+rpt2+deb12u13) ... Dec 26 13:30:28 volumio ntpd[1061]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Dec 26 13:30:28 volumio ntpd[1061]: DNS: Pool skipping: 178.61.152.98 Dec 26 13:30:28 volumio ntpd[1061]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 Dec 26 13:30:30 volumio sudo[23377]: pam_unix(sudo:session): session closed for user root Dec 26 13:30:31 volumio volumio[1378]: info: Linked /data/plugins/user_interface/peppyspectrum/alsa-lib/armhf/libpeppyalsa.so.0.0.0 to /data/plugins/user_interface/peppyspectrum/alsa-lib/libpeppyalsa.so Dec 26 13:30:31 volumio volumio[1378]: info: Linked /data/plugins/user_interface/peppyspectrum/alsa-lib/armhf/libpeppyalsa.so.0.0.0 to /data/plugins/user_interface/peppyspectrum/alsa-lib/libpeppyalsa.so.0 Dec 26 13:30:31 volumio sudo[23578]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/chmod +x /data/plugins/user_interface/peppyspectrum/startpeppyspectrum.sh Dec 26 13:30:31 volumio sudo[23578]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 26 13:30:31 volumio sudo[23578]: pam_unix(sudo:session): session closed for user root Dec 26 13:30:31 volumio sudo[23580]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/systemctl daemon-reload Dec 26 13:30:31 volumio sudo[23580]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 26 13:30:31 volumio systemd[1]: Reloading. Dec 26 13:30:32 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 26 13:30:32 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 26 13:30:32 volumio sudo[23580]: pam_unix(sudo:session): session closed for user root Dec 26 13:30:32 volumio sudo[23181]: pam_unix(sudo:session): session closed for user root Dec 26 13:30:32 volumio volumio[1378]: Plugin install end detected on script Dec 26 13:30:32 volumio volumio[1378]: info: Install script completed Dec 26 13:30:32 volumio volumio[1378]: info: Adding reference to registry Dec 26 13:30:32 volumio volumio[1378]: info: Done installing plugin. Dec 26 13:30:32 volumio volumio[1378]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 26 13:30:32 volumio volumio[1378]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 26 13:30:32 volumio systemd[1]: Starting apt-daily.service - Daily apt download activities... Dec 26 13:30:32 volumio volumio[1378]: info: Folder /tmp/plugins removed Dec 26 13:30:32 volumio volumio[1378]: info: Folder /tmp/downloaded_plugin.zip removed Dec 26 13:30:32 volumio volumio[1378]: info: Folder /data/temp removed Dec 26 13:30:34 volumio systemd[1]: apt-daily.service: Deactivated successfully. Dec 26 13:30:34 volumio systemd[1]: Finished apt-daily.service - Daily apt download activities. Dec 26 13:30:34 volumio systemd[1]: apt-daily.service: Consumed 1.237s CPU time. Dec 26 13:30:34 volumio go-librespot[1779]: time="2025-12-26T13:30:34+03:00" level=debug msg="fetched chunk 14/22, size: 524288" uri="spotify:track:0eSqyR8UbK38kT64KkRw0e" Dec 26 13:30:34 volumio volumio[1378]: info: Enabling plugin peppyspectrum Dec 26 13:30:34 volumio volumio[1378]: info: Loading plugin "peppyspectrum"... Dec 26 13:30:35 volumio volumio[1378]: info: Preparing to generate the ALSA configuration file Dec 26 13:30:35 volumio volumio[1378]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Dec 26 13:30:35 volumio volumio[1378]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf Dec 26 13:30:35 volumio volumio[1378]: info: Reading ALSA contributions from plugins. Dec 26 13:30:35 volumio volumio[1378]: info: Asound.conf file written Dec 26 13:30:35 volumio sudo[23664]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 26 13:30:35 volumio sudo[23664]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 26 13:30:35 volumio sudo[23664]: pam_unix(sudo:session): session closed for user root Dec 26 13:30:35 volumio volumio[1378]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 26 13:30:35 volumio volumio[1378]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 26 13:30:35 volumio volumio[1378]: /usr/sbin/alsactl: set_control:1475: Cannot write control '2:0:0:Max Overclock PLL:0' : Device or resource busy Dec 26 13:30:35 volumio volumio[1378]: /usr/sbin/alsactl: set_control:1475: Cannot write control '2:0:0:Max Overclock DSP:0' : Device or resource busy Dec 26 13:30:35 volumio volumio[1378]: /usr/sbin/alsactl: set_control:1475: Cannot write control '2:0:0:Max Overclock DAC:0' : Device or resource busy Dec 26 13:30:35 volumio volumio[1378]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:7 use case configuration -2 Dec 26 13:30:35 volumio volumio[1378]: info: Output device has changed, restarting MPD Dec 26 13:30:35 volumio volumio[1378]: info: Output device has changed, restarting Shairport Sync Dec 26 13:30:35 volumio volumio[1378]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 26 13:30:35 volumio volumio[1378]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 26 13:30:35 volumio sudo[23672]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 26 13:30:35 volumio sudo[23672]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 26 13:30:35 volumio sudo[23672]: pam_unix(sudo:session): session closed for user root Dec 26 13:30:35 volumio sudo[23674]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 26 13:30:35 volumio sudo[23674]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 26 13:30:35 volumio volumio[1378]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 26 13:30:35 volumio volumio[1378]: info: PLUGIN START: peppyspectrum Dec 26 13:30:35 volumio volumio[1378]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Dec 26 13:30:35 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 26 13:30:35 volumio volumio[1378]: info: Preparing to generate the ALSA configuration file Dec 26 13:30:35 volumio sudo[23682]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/modprobe snd-aloop index=7 pcm_substreams=1 Dec 26 13:30:35 volumio sudo[23682]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 26 13:30:35 volumio volumio[1378]: info: Done. Dec 26 13:30:35 volumio volumio[1378]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf Dec 26 13:30:35 volumio volumio[1378]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Dec 26 13:30:35 volumio volumio[1378]: info: Reading ALSA contributions from plugins. Dec 26 13:30:35 volumio volumio[1378]: info: MPD Permissions set Dec 26 13:30:35 volumio sudo[23682]: pam_unix(sudo:session): session closed for user root Dec 26 13:30:35 volumio volumio[1378]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Dec 26 13:30:35 volumio volumio[1378]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 26 13:30:35 volumio volumio[1378]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 26 13:30:35 volumio volumio[1378]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 26 13:30:35 volumio volumio[1378]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 26 13:30:35 volumio volumio[1378]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 26 13:30:35 volumio volumio[1378]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 26 13:30:35 volumio volumio[1378]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 26 13:30:35 volumio volumio[1378]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 26 13:30:35 volumio volumio[1378]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 26 13:30:35 volumio volumio[1378]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 26 13:30:35 volumio go-librespot[1779]: time="2025-12-26T13:30:35+03:00" level=trace msg="sent dealer ping" Dec 26 13:30:35 volumio volumio[1378]: info: snd_dummy loaded Dec 26 13:30:35 volumio volumio[1378]: info: Starting Shairport Sync Dec 26 13:30:35 volumio volumio[1378]: info: Asound.conf file unchanged, so no further update is needed Dec 26 13:30:35 volumio volumio[1378]: info: Output device has changed, restarting MPD Dec 26 13:30:35 volumio sudo[23691]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 26 13:30:35 volumio sudo[23691]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 26 13:30:35 volumio volumio[1378]: info: Output device has changed, restarting Shairport Sync Dec 26 13:30:35 volumio volumio[1378]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 26 13:30:35 volumio volumio[1378]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 26 13:30:35 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 26 13:30:35 volumio sudo[23694]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 26 13:30:35 volumio sudo[23696]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 26 13:30:35 volumio sudo[23694]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 26 13:30:35 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 26 13:30:35 volumio sudo[23696]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 26 13:30:35 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 26 13:30:35 volumio systemd[1]: shairport-sync.service: Consumed 31.624s CPU time. Dec 26 13:30:35 volumio sudo[23694]: pam_unix(sudo:session): session closed for user root Dec 26 13:30:35 volumio volumio[1378]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 26 13:30:35 volumio volumio[1378]: info: MPD Permissions set Dec 26 13:30:35 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 26 13:30:35 volumio volumio[1378]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 26 13:30:35 volumio volumio[1378]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 26 13:30:35 volumio volumio[1378]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 26 13:30:35 volumio volumio[1378]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 26 13:30:35 volumio volumio[1378]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 26 13:30:35 volumio volumio[1378]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 26 13:30:35 volumio volumio[1378]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 26 13:30:35 volumio volumio[1378]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 26 13:30:35 volumio volumio[1378]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 26 13:30:35 volumio volumio[1378]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 26 13:30:35 volumio sudo[23691]: pam_unix(sudo:session): session closed for user root Dec 26 13:30:35 volumio volumio[1378]: info: Shairport-Sync Started Dec 26 13:30:35 volumio systemd[1]: mpd.service: Deactivated successfully. Dec 26 13:30:35 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 26 13:30:35 volumio systemd[1]: mpd.service: Consumed 1min 33.991s CPU time. Dec 26 13:30:35 volumio systemd[1]: mpd.socket: Deactivated successfully. Dec 26 13:30:35 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 26 13:30:35 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 26 13:30:35 volumio volumio[1378]: info: Starting Shairport Sync Dec 26 13:30:35 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 26 13:30:35 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 26 13:30:35 volumio sudo[23724]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 26 13:30:35 volumio sudo[23724]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 26 13:30:35 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 26 13:30:35 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 26 13:30:35 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 26 13:30:35 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 26 13:30:35 volumio sudo[23724]: pam_unix(sudo:session): session closed for user root Dec 26 13:30:35 volumio sudo[23729]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 26 13:30:35 volumio sudo[23729]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 26 13:30:36 volumio sudo[23729]: pam_unix(sudo:session): session closed for user root Dec 26 13:30:36 volumio volumio[1378]: info: Shairport-Sync Started Dec 26 13:30:36 volumio go-librespot[1779]: time="2025-12-26T13:30:36+03:00" level=trace msg="received dealer pong" Dec 26 13:30:37 volumio mpd[23737]: 2025-12-26T13:30:37 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 26 13:30:37 volumio systemd[1]: Started mpd.service - Music Player Daemon. Dec 26 13:30:37 volumio sudo[23674]: pam_unix(sudo:session): session closed for user root Dec 26 13:30:37 volumio sudo[23696]: pam_unix(sudo:session): session closed for user root Dec 26 13:30:37 volumio volumio[1378]: error: MPD error: The expression evaluated to a falsy value: Dec 26 13:30:37 volumio volumio[1378]: assert.ok(self.idling) Dec 26 13:30:37 volumio volumio[1378]: error: The expression evaluated to a falsy value: Dec 26 13:30:37 volumio volumio[1378]: assert.ok(self.idling) Dec 26 13:30:37 volumio volumio[1378]: error: updateQueue error: null Dec 26 13:30:40 volumio sudo[23761]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 26 13:30:40 volumio sudo[23761]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 26 13:30:40 volumio sudo[23766]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 26 13:30:40 volumio sudo[23766]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 26 13:30:40 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 26 13:30:40 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 26 13:30:40 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 26 13:30:40 volumio systemd[1]: mpd_monitor.service: Consumed 2.888s CPU time. Dec 26 13:30:40 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 26 13:30:40 volumio sudo[23761]: pam_unix(sudo:session): session closed for user root Dec 26 13:30:40 volumio mpd_monitor.sh[23774]: MPD Monitor Service: Starting MPD Monitor Service Dec 26 13:30:40 volumio volumio[1378]: info: Successfully started MPD Monitor Dec 26 13:30:40 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 26 13:30:40 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 26 13:30:40 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 26 13:30:40 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 26 13:30:40 volumio sudo[23766]: pam_unix(sudo:session): session closed for user root Dec 26 13:30:40 volumio volumio[1378]: info: Successfully started MPD Monitor Dec 26 13:30:40 volumio mpd_monitor.sh[23776]: MPD Monitor Service: Starting MPD Monitor Service Dec 26 13:30:43 volumio volumio[1378]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 26 13:30:43 volumio volumio[1378]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 26 13:30:45 volumio go-librespot[1779]: time="2025-12-26T13:30:45+03:00" level=debug msg="fetched chunk 15/22, size: 524288" uri="spotify:track:0eSqyR8UbK38kT64KkRw0e" Dec 26 13:30:48 volumio volumio[1378]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 26 13:30:55 volumio volumio[1378]: info: CALLMETHOD: user_interface peppyspectrum savepeppy [object Object] Dec 26 13:30:55 volumio volumio[1378]: info: CoreCommandRouter::executeOnPlugin: peppyspectrum , savepeppy Dec 26 13:30:55 volumio volumio[1378]: aaaaaaaaaaa 800,480 Dec 26 13:30:55 volumio volumio[1378]: info: PeppySpectrum ---800480 Dec 26 13:30:55 volumio volumio[1378]: error: Failed callmethod call: TypeError: Cannot read properties of undefined (reading 'then') Dec 26 13:30:55 volumio volumio[1378]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 26 13:30:55 volumio volumio[1378]: info: CoreCommandRouter::Close All Modals sent Dec 26 13:30:57 volumio go-librespot[1779]: time="2025-12-26T13:30:57+03:00" level=debug msg="fetched chunk 16/22, size: 524288" uri="spotify:track:0eSqyR8UbK38kT64KkRw0e" Dec 26 13:31:02 volumio volumio[1378]: info: CALLMETHOD: user_interface peppyspectrum savepeppy1 [object Object] Dec 26 13:31:02 volumio volumio[1378]: info: CoreCommandRouter::executeOnPlugin: peppyspectrum , savepeppy1 Dec 26 13:31:02 volumio volumio[1378]: error: Failed callmethod call: TypeError: Cannot read properties of undefined (reading 'then') Dec 26 13:31:02 volumio volumio[1378]: info: PeppySpectrum -----------------------spectrum Dec 26 13:31:02 volumio volumio[1378]: info: PeppySpectrum -----------------------$basefolder Dec 26 13:31:02 volumio volumio[1378]: info: PeppySpectrum -----------------------screensize800x480 Dec 26 13:31:02 volumio volumio[1378]: info: PeppySpectrum -----------------------screenwidth Dec 26 13:31:02 volumio volumio[1378]: info: PeppySpectrum -----------------------screenheight Dec 26 13:31:02 volumio volumio[1378]: info: PeppySpectrum -----------------------spectrumsize30 Dec 26 13:31:02 volumio volumio[1378]: error: PeppySpectrum ---Error writing config null Dec 26 13:31:02 volumio sudo[23816]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart peppyspectrum.service Dec 26 13:31:02 volumio sudo[23816]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 26 13:31:02 volumio systemd[1]: Started peppyspectrum.service - peppyspectrum Daemon. Dec 26 13:31:02 volumio sudo[23816]: pam_unix(sudo:session): session closed for user root Dec 26 13:31:02 volumio volumio[1378]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 26 13:31:02 volumio volumio[1378]: info: CoreCommandRouter::Close All Modals sent Dec 26 13:31:02 volumio volumio[1378]: info: peppyspectrum Daemon Started Dec 26 13:31:04 volumio startpeppyspectrum.sh[23819]: libpng warning: iCCP: known incorrect sRGB profile Dec 26 13:31:04 volumio startpeppyspectrum.sh[23819]: libpng warning: iCCP: known incorrect sRGB profile Dec 26 13:31:04 volumio startpeppyspectrum.sh[23819]: libpng warning: iCCP: known incorrect sRGB profile Dec 26 13:31:04 volumio startpeppyspectrum.sh[23819]: libpng warning: iCCP: known incorrect sRGB profile Dec 26 13:31:04 volumio startpeppyspectrum.sh[23819]: libpng warning: iCCP: known incorrect sRGB profile Dec 26 13:31:04 volumio startpeppyspectrum.sh[23819]: libpng warning: iCCP: known incorrect sRGB profile Dec 26 13:31:04 volumio startpeppyspectrum.sh[23819]: libpng warning: iCCP: known incorrect sRGB profile Dec 26 13:31:04 volumio startpeppyspectrum.sh[23819]: libpng warning: iCCP: known incorrect sRGB profile Dec 26 13:31:04 volumio startpeppyspectrum.sh[23819]: libpng warning: iCCP: known incorrect sRGB profile Dec 26 13:31:04 volumio startpeppyspectrum.sh[23819]: libpng warning: iCCP: known incorrect sRGB profile Dec 26 13:31:04 volumio startpeppyspectrum.sh[23819]: libpng warning: iCCP: known incorrect sRGB profile Dec 26 13:31:04 volumio go-librespot[1779]: time="2025-12-26T13:31:04+03:00" level=trace msg="received accesspoint ping" Dec 26 13:31:04 volumio go-librespot[1779]: time="2025-12-26T13:31:04+03:00" level=trace msg="received accesspoint pong ack" Dec 26 13:31:05 volumio go-librespot[1779]: time="2025-12-26T13:31:05+03:00" level=trace msg="sent dealer ping" Dec 26 13:31:05 volumio go-librespot[1779]: time="2025-12-26T13:31:05+03:00" level=trace msg="received dealer pong" Dec 26 13:31:10 volumio go-librespot[1779]: time="2025-12-26T13:31:10+03:00" level=debug msg="fetched chunk 17/22, size: 524288" uri="spotify:track:0eSqyR8UbK38kT64KkRw0e" Dec 26 13:31:22 volumio go-librespot[1779]: time="2025-12-26T13:31:22+03:00" level=debug msg="fetched chunk 18/22, size: 524288" uri="spotify:track:0eSqyR8UbK38kT64KkRw0e" Dec 26 13:31:35 volumio volumio[1378]: info: CALLMETHOD: user_interface peppyspectrum updatelist Dec 26 13:31:35 volumio volumio[1378]: info: CoreCommandRouter::executeOnPlugin: peppyspectrum , updatelist Dec 26 13:31:35 volumio volumio[1378]: info: PeppySpectrum --- wget 'https://github.com/balbuze/Spectrum-peppyspectrum/raw/main/spectrumslist.txt' Dec 26 13:31:35 volumio go-librespot[1779]: time="2025-12-26T13:31:35+03:00" level=debug msg="fetched chunk 19/22, size: 524288" uri="spotify:track:0eSqyR8UbK38kT64KkRw0e" Dec 26 13:31:35 volumio go-librespot[1779]: time="2025-12-26T13:31:35+03:00" level=trace msg="sent dealer ping" Dec 26 13:31:35 volumio go-librespot[1779]: time="2025-12-26T13:31:35+03:00" level=trace msg="received dealer pong" Dec 26 13:31:36 volumio volumio[1378]: --2025-12-26 13:31:35-- https://github.com/balbuze/Spectrum-peppyspectrum/raw/main/spectrumslist.txt Dec 26 13:31:36 volumio volumio[1378]: Resolving github.com (github.com)... 20.233.83.145 Dec 26 13:31:36 volumio volumio[1378]: Connecting to github.com (github.com)|20.233.83.145|:443... connected. Dec 26 13:31:36 volumio volumio[1378]: HTTP request sent, awaiting response... 302 Found Dec 26 13:31:36 volumio volumio[1378]: Location: https://raw.githubusercontent.com/balbuze/Spectrum-peppyspectrum/main/spectrumslist.txt [following] Dec 26 13:31:36 volumio volumio[1378]: --2025-12-26 13:31:36-- https://raw.githubusercontent.com/balbuze/Spectrum-peppyspectrum/main/spectrumslist.txt Dec 26 13:31:36 volumio volumio[1378]: Resolving raw.githubusercontent.com (raw.githubusercontent.com)... 185.199.110.133, 185.199.111.133, 185.199.109.133, ... Dec 26 13:31:36 volumio volumio[1378]: Connecting to raw.githubusercontent.com (raw.githubusercontent.com)|185.199.110.133|:443... connected. Dec 26 13:31:36 volumio volumio[1378]: HTTP request sent, awaiting response... 200 OK Dec 26 13:31:36 volumio volumio[1378]: Length: 471 [text/plain] Dec 26 13:31:36 volumio volumio[1378]: Saving to: ‘/data/plugins/user_interface/peppyspectrum/spectrumslist.txt’ Dec 26 13:31:36 volumio volumio[1378]: 0K 100% 7.68M=0s Dec 26 13:31:36 volumio volumio[1378]: 2025-12-26 13:31:36 (7.68 MB/s) - ‘/data/plugins/user_interface/peppyspectrum/spectrumslist.txt’ saved [471/471] Dec 26 13:31:37 volumio volumio[1378]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 26 13:31:37 volumio volumio[1378]: info: CoreCommandRouter::Close All Modals sent Dec 26 13:31:43 volumio volumio[1378]: info: CALLMETHOD: user_interface peppyspectrum dlspectrum [object Object] Dec 26 13:31:43 volumio volumio[1378]: info: CoreCommandRouter::executeOnPlugin: peppyspectrum , dlspectrum Dec 26 13:31:46 volumio volumio[1378]: --2025-12-26 13:31:43-- https://github.com/balbuze/Spectrum-peppyspectrum/raw/main/Zipped-folders/Choose Dec 26 13:31:46 volumio volumio[1378]: Resolving github.com (github.com)... 20.233.83.145 Dec 26 13:31:46 volumio volumio[1378]: Connecting to github.com (github.com)|20.233.83.145|:443... connected. Dec 26 13:31:46 volumio volumio[1378]: HTTP request sent, awaiting response... 404 Not Found Dec 26 13:31:46 volumio volumio[1378]: 2025-12-26 13:31:44 ERROR 404: Not Found. Dec 26 13:31:46 volumio volumio[1378]: --2025-12-26 13:31:44-- http://a/ Dec 26 13:31:46 volumio volumio[1378]: Resolving a (a)... failed: Device or resource busy. Dec 26 13:31:46 volumio volumio[1378]: wget: unable to resolve host address ‘a’ Dec 26 13:31:46 volumio volumio[1378]: --2025-12-26 13:31:44-- http://packet.zip/ Dec 26 13:31:46 volumio volumio[1378]: Resolving packet.zip (packet.zip)... 162.255.119.167 Dec 26 13:31:46 volumio volumio[1378]: Connecting to packet.zip (packet.zip)|162.255.119.167|:80... connected. Dec 26 13:31:46 volumio volumio[1378]: HTTP request sent, awaiting response... 302 Found Dec 26 13:31:46 volumio volumio[1378]: Location: http://www.packet.zip/ [following] Dec 26 13:31:46 volumio volumio[1378]: --2025-12-26 13:31:45-- http://www.packet.zip/ Dec 26 13:31:46 volumio volumio[1378]: Resolving www.packet.zip (www.packet.zip)... 91.195.240.19 Dec 26 13:31:46 volumio volumio[1378]: Connecting to www.packet.zip (www.packet.zip)|91.195.240.19|:80... connected. Dec 26 13:31:46 volumio volumio[1378]: HTTP request sent, awaiting response... 403 Forbidden Dec 26 13:31:46 volumio volumio[1378]: 2025-12-26 13:31:46 ERROR 403: Forbidden. Dec 26 13:31:46 volumio volumio[1378]: error: PeppySpectrum --- An error occurs while downloading or installing Spectrums Dec 26 13:31:46 volumio volumio[1378]: /bin/rm: cannot remove '/tmp/Choose': No such file or directory Dec 26 13:31:46 volumio volumio[1378]: /bin/rm: cannot remove 'a': No such file or directory Dec 26 13:31:46 volumio volumio[1378]: /bin/rm: cannot remove 'packet.zip*': No such file or directory Dec 26 13:31:46 volumio volumio[1378]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 26 13:31:46 volumio volumio[1378]: Error: Command failed: /bin/rm /tmp/Choose a packet.zip* Dec 26 13:31:46 volumio volumio[1378]: /bin/rm: cannot remove '/tmp/Choose': No such file or directory Dec 26 13:31:46 volumio volumio[1378]: /bin/rm: cannot remove 'a': No such file or directory Dec 26 13:31:46 volumio volumio[1378]: /bin/rm: cannot remove 'packet.zip*': No such file or directory Dec 26 13:31:46 volumio volumio[1378]: at checkExecSyncError (node:child_process:887:11) Dec 26 13:31:46 volumio volumio[1378]: at execSync (node:child_process:959:15) Dec 26 13:31:46 volumio volumio[1378]: at /data/plugins/user_interface/peppyspectrum/index.js:770:19 Dec 26 13:31:46 volumio volumio[1378]: at new Promise () Dec 26 13:31:46 volumio volumio[1378]: at peppyspectrum.dlspectrum (/data/plugins/user_interface/peppyspectrum/index.js:745:12) Dec 26 13:31:46 volumio volumio[1378]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1096:32) Dec 26 13:31:46 volumio volumio[1378]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:337:42) Dec 26 13:31:46 volumio volumio[1378]: at Socket.emit (node:events:514:28) Dec 26 13:31:46 volumio volumio[1378]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Dec 26 13:31:46 volumio volumio[1378]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) { Dec 26 13:31:46 volumio volumio[1378]: status: 1, Dec 26 13:31:46 volumio volumio[1378]: signal: null, Dec 26 13:31:46 volumio volumio[1378]: output: [ Dec 26 13:31:46 volumio volumio[1378]: null, Dec 26 13:31:46 volumio volumio[1378]: , Dec 26 13:31:46 volumio volumio[1378]: Dec 26 13:31:46 volumio volumio[1378]: ], Dec 26 13:31:46 volumio volumio[1378]: pid: 23905, Dec 26 13:31:46 volumio volumio[1378]: stdout: , Dec 26 13:31:46 volumio volumio[1378]: stderr: Dec 26 13:31:46 volumio volumio[1378]: } Dec 26 13:31:46 volumio volumio[1378]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 26 13:31:46 volumio sudo[23921]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-26 13:30' Dec 26 13:31:46 volumio sudo[23921]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="3a3cfe435f8bb2bc94a920662e91a4ef35bc8e7c" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="8bcc10c3dbcbcb349e9887dc0527d54876b32688" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Dec 2 11:51:19 UTC 2025" VOLUMIO_VERSION="4.072" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="e5001581b220b096097cf8f46a54d4f1"