-- Logs begin at Tue 2026-01-20 13:02:50 GMT, end at Sat 2026-02-21 10:00:28 GMT. -- Feb 21 09:59:05 rpi0w1-audio volumio[842]: info: Loading plugin "network"... Feb 21 09:59:05 rpi0w1-audio volumio[842]: info: Refreshing Cached IP Addresses Feb 21 09:59:05 rpi0w1-audio sudo[1033]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 21 09:59:05 rpi0w1-audio sudo[1033]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 09:59:05 rpi0w1-audio sudo[1035]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 21 09:59:05 rpi0w1-audio sudo[1035]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 09:59:05 rpi0w1-audio sudo[1033]: pam_unix(sudo:session): session closed for user root Feb 21 09:59:05 rpi0w1-audio sudo[1035]: pam_unix(sudo:session): session closed for user root Feb 21 09:59:05 rpi0w1-audio volumio[842]: info: Loading plugin "services"... Feb 21 09:59:05 rpi0w1-audio volumio[842]: info: Loading plugin "alsa_controller"... Feb 21 09:59:05 rpi0w1-audio sudo[1046]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 21 09:59:05 rpi0w1-audio sudo[1046]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 09:59:06 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 21 09:59:06 rpi0w1-audio volumio[842]: info: Loading plugin "wizard"... Feb 21 09:59:06 rpi0w1-audio volumio[842]: info: Loading plugin "networkfs"... Feb 21 09:59:06 rpi0w1-audio volumio[842]: info: Starting Udev Watcher for removable devices Feb 21 09:59:06 rpi0w1-audio volumio[842]: info: Ignoring mount for partition: boot Feb 21 09:59:06 rpi0w1-audio volumio[842]: info: Ignoring mount for partition: volumio Feb 21 09:59:06 rpi0w1-audio volumio[842]: info: Ignoring mount for partition: volumio_data Feb 21 09:59:06 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 21 09:59:06 rpi0w1-audio volumio[842]: info: Loading plugin "volumio_command_line_client"... Feb 21 09:59:06 rpi0w1-audio volumio[842]: info: Loading plugin "upnp"... Feb 21 09:59:06 rpi0w1-audio volumio[842]: info: [1771667946486] Starting Upmpd Daemon Feb 21 09:59:06 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 21 09:59:06 rpi0w1-audio volumio[842]: info: Loading plugin "my_music"... Feb 21 09:59:06 rpi0w1-audio volumio[842]: info: Loading plugin "mpd"... Feb 21 09:59:06 rpi0w1-audio sudo[1046]: pam_unix(sudo:session): session closed for user root Feb 21 09:59:08 rpi0w1-audio volumio[842]: info: Loading plugin "upnp_browser"... Feb 21 09:59:09 rpi0w1-audio volumio[842]: info: Loading plugin "alarm-clock"... Feb 21 09:59:11 rpi0w1-audio volumio[842]: info: Loading plugin "airplay_emulation"... Feb 21 09:59:11 rpi0w1-audio volumio[842]: info: Starting Shairport Sync Feb 21 09:59:11 rpi0w1-audio volumio[842]: info: Loading plugin "last_100"... Feb 21 09:59:11 rpi0w1-audio volumio[842]: info: Loading plugin "webradio"... Feb 21 09:59:11 rpi0w1-audio volumio[842]: info: Loading plugin "i2s_dacs"... Feb 21 09:59:11 rpi0w1-audio volumio[842]: info: Loading plugin "volumiodiscovery"... Feb 21 09:59:11 rpi0w1-audio volumio[842]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 21 09:59:11 rpi0w1-audio node[842]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 21 09:59:11 rpi0w1-audio volumio[842]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 21 09:59:11 rpi0w1-audio volumio[842]: *** WARNING *** For more information see Feb 21 09:59:11 rpi0w1-audio volumio[842]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 21 09:59:11 rpi0w1-audio volumio[842]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 21 09:59:11 rpi0w1-audio volumio[842]: *** WARNING *** For more information see Feb 21 09:59:11 rpi0w1-audio node[842]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 21 09:59:11 rpi0w1-audio node[842]: *** WARNING *** For more information see Feb 21 09:59:11 rpi0w1-audio node[842]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 21 09:59:11 rpi0w1-audio node[842]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 21 09:59:11 rpi0w1-audio node[842]: *** WARNING *** For more information see Feb 21 09:59:11 rpi0w1-audio volumio[842]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 21 09:59:11 rpi0w1-audio volumio[842]: info: Discovery: Started advertising with name: rpi0w1-audio Feb 21 09:59:12 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 21 09:59:12 rpi0w1-audio volumio[842]: info: Loading plugin "spop"... Feb 21 09:59:13 rpi0w1-audio systemd[1]: systemd-timedated.service: Succeeded. Feb 21 09:59:13 rpi0w1-audio ntpd[547]: Soliciting pool server 217.114.59.66 Feb 21 09:59:13 rpi0w1-audio ntpd[547]: Soliciting pool server 194.213.3.203 Feb 21 09:59:14 rpi0w1-audio ntpd[547]: Soliciting pool server 213.5.132.231 Feb 21 09:59:14 rpi0w1-audio ntpd[547]: Soliciting pool server 178.79.150.226 Feb 21 09:59:14 rpi0w1-audio ntpd[547]: Soliciting pool server 139.162.224.201 Feb 21 09:59:14 rpi0w1-audio volumio-remote-updater[343]: [2026-02-21 09:59:14] [connect] Successful connection Feb 21 09:59:15 rpi0w1-audio ntpd[547]: Soliciting pool server 132.226.210.133 Feb 21 09:59:15 rpi0w1-audio ntpd[547]: Soliciting pool server 178.62.68.79 Feb 21 09:59:15 rpi0w1-audio ntpd[547]: Soliciting pool server 109.74.206.120 Feb 21 09:59:16 rpi0w1-audio ntpd[547]: Soliciting pool server 85.199.214.102 Feb 21 09:59:16 rpi0w1-audio ntpd[547]: Soliciting pool server 87.106.36.214 Feb 21 09:59:16 rpi0w1-audio ntpd[547]: Soliciting pool server 131.111.8.60 Feb 21 09:59:17 rpi0w1-audio ntpd[547]: Soliciting pool server 178.79.138.215 Feb 21 09:59:17 rpi0w1-audio ntpd[547]: Soliciting pool server 109.74.197.50 Feb 21 09:59:17 rpi0w1-audio volumio[842]: info: Loading plugin "outputs"... Feb 21 09:59:17 rpi0w1-audio volumio[842]: info: Loading plugin "albumart"... Feb 21 09:59:17 rpi0w1-audio volumio[842]: info: Plugin example_plugin is not enabled Feb 21 09:59:17 rpi0w1-audio volumio[842]: info: Loading plugin "inputs"... Feb 21 09:59:17 rpi0w1-audio volumio[842]: info: Loading plugin "updater_comm"... Feb 21 09:59:18 rpi0w1-audio ntpd[547]: Soliciting pool server 88.80.189.24 Feb 21 09:59:19 rpi0w1-audio ntpd[547]: Soliciting pool server 109.74.192.36 Feb 21 09:59:19 rpi0w1-audio volumio[842]: info: Plugin mpdemulation is not enabled Feb 21 09:59:19 rpi0w1-audio volumio[842]: info: Loading plugin "rest_api"... Feb 21 09:59:19 rpi0w1-audio volumio[842]: info: Loading plugin "websocket"... Feb 21 09:59:19 rpi0w1-audio volumio[842]: info: Starting Socket.io Server version 2.3.0 Feb 21 09:59:19 rpi0w1-audio volumio[842]: info: Loading i18n strings for locale en Feb 21 09:59:20 rpi0w1-audio volumio[842]: Updating browse sources language Feb 21 09:59:20 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 09:59:21 rpi0w1-audio volumio[842]: Forking 1 albumart workers Feb 21 09:59:23 rpi0w1-audio ntpd[547]: receive: Unexpected origin timestamp 0xed440079.6244d604 does not match aorg 0000000000.00000000 from server@109.74.197.50 xmt 0xed44007b.f643a182 Feb 21 09:59:23 rpi0w1-audio ntpd[547]: receive: Unexpected origin timestamp 0xed440079.62617748 does not match aorg 0000000000.00000000 from server@178.79.150.226 xmt 0xed44007b.f6149484 Feb 21 09:59:23 rpi0w1-audio ntpd[547]: receive: Unexpected origin timestamp 0xed440079.6237fc7c does not match aorg 0000000000.00000000 from server@178.79.138.215 xmt 0xed44007b.f5eb384c Feb 21 09:59:23 rpi0w1-audio ntpd[547]: receive: Unexpected origin timestamp 0xed440079.624b3eb1 does not match aorg 0000000000.00000000 from server@131.111.8.60 xmt 0xed44007b.f73d1f14 Feb 21 09:59:23 rpi0w1-audio ntpd[547]: receive: Unexpected origin timestamp 0xed440079.625c1ac5 does not match aorg 0000000000.00000000 from server@213.5.132.231 xmt 0xed44007b.f88ef454 Feb 21 09:59:23 rpi0w1-audio ntpd[547]: receive: Unexpected origin timestamp 0xed440079.6250e342 does not match aorg 0000000000.00000000 from server@87.106.36.214 xmt 0xed44007b.f9ea1676 Feb 21 09:59:24 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 21 09:59:24 rpi0w1-audio volumio[842]: info: CoreCommandRouter::initPlayerControls Feb 21 09:59:24 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 09:59:24 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 09:59:25 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 21 09:59:25 rpi0w1-audio volumio[842]: Express server listening on port 3000 Feb 21 09:59:25 rpi0w1-audio volumio[842]: [Metrics] WebUI: 32s 555.53ms Feb 21 09:59:25 rpi0w1-audio volumio[842]: info: CoreStateMachine::resetVolumioState Feb 21 09:59:25 rpi0w1-audio volumio[842]: info: CoreStateMachine::getcurrentVolume Feb 21 09:59:25 rpi0w1-audio volumio[842]: info: CoreCommandRouter::volumioRetrievevolume Feb 21 09:59:25 rpi0w1-audio sudo[1105]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 21 09:59:25 rpi0w1-audio sudo[1105]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 09:59:26 rpi0w1-audio sudo[1107]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 21 09:59:26 rpi0w1-audio sudo[1107]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 09:59:26 rpi0w1-audio sudo[1105]: pam_unix(sudo:session): session closed for user root Feb 21 09:59:26 rpi0w1-audio sudo[1107]: pam_unix(sudo:session): session closed for user root Feb 21 09:59:26 rpi0w1-audio volumio[842]: info: Volumio Network Manager: Network status updated: 2 Feb 21 09:59:27 rpi0w1-audio volumio[842]: info: CoreStateMachine::pushState Feb 21 09:59:27 rpi0w1-audio volumio[842]: info: CorePlayQueue::getTrack 0 Feb 21 09:59:27 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 21 09:59:27 rpi0w1-audio volumio[842]: info: CoreCommandRouter::volumioPushState Feb 21 09:59:27 rpi0w1-audio volumio[842]: info: CoreStateMachine::updateTrackBlock Feb 21 09:59:27 rpi0w1-audio volumio[842]: info: CorePlayQueue::getTrackBlock Feb 21 09:59:27 rpi0w1-audio volumio[842]: info: CoreCommandRouter::volumioRetrievevolume Feb 21 09:59:27 rpi0w1-audio volumio[842]: info: Reloading queue from file Feb 21 09:59:27 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 09:59:27 rpi0w1-audio volumio[842]: info: CoreStateMachine::setRepeat null single undefined Feb 21 09:59:27 rpi0w1-audio volumio[842]: info: CoreStateMachine::pushState Feb 21 09:59:27 rpi0w1-audio volumio[842]: info: CorePlayQueue::getTrack 0 Feb 21 09:59:27 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 21 09:59:27 rpi0w1-audio volumio[842]: info: CoreCommandRouter::volumioPushState Feb 21 09:59:27 rpi0w1-audio volumio[842]: info: CoreStateMachine::setRandom false Feb 21 09:59:27 rpi0w1-audio volumio[842]: info: CoreStateMachine::pushState Feb 21 09:59:27 rpi0w1-audio volumio[842]: info: CorePlayQueue::getTrack 0 Feb 21 09:59:27 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 21 09:59:27 rpi0w1-audio volumio[842]: info: CoreCommandRouter::volumioPushState Feb 21 09:59:27 rpi0w1-audio volumio[842]: info: Setting Device type: Raspberry PI Feb 21 09:59:28 rpi0w1-audio volumio[842]: info: Completed loading Core Plugins Feb 21 09:59:28 rpi0w1-audio volumio[842]: info: Preparing to generate the ALSA configuration file Feb 21 09:59:28 rpi0w1-audio volumio[842]: info: CoreStateMachine::pushState Feb 21 09:59:28 rpi0w1-audio volumio[842]: info: CorePlayQueue::getTrack 0 Feb 21 09:59:28 rpi0w1-audio volumio[842]: info: CoreCommandRouter::volumioPushState Feb 21 09:59:28 rpi0w1-audio volumio[842]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Feb 21 09:59:28 rpi0w1-audio volumio[842]: info: Reading ALSA contributions from plugins. Feb 21 09:59:28 rpi0w1-audio volumio[842]: info: Discovery: adding 91cdf007-48b3-4770-8127-aaa86be9d885 Feb 21 09:59:28 rpi0w1-audio volumio[842]: info: Discovery: Found device rpi0w1-audio Feb 21 09:59:28 rpi0w1-audio volumio[842]: info: CoreCommandRouter::volumioGetState Feb 21 09:59:28 rpi0w1-audio volumio[842]: info: CorePlayQueue::getTrack 0 Feb 21 09:59:28 rpi0w1-audio sudo[1124]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 21 09:59:28 rpi0w1-audio volumio[842]: info: Asound.conf file unchanged, so no further update is needed Feb 21 09:59:28 rpi0w1-audio volumio[842]: info: Output device has changed, restarting MPD Feb 21 09:59:28 rpi0w1-audio sudo[1124]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 09:59:28 rpi0w1-audio systemd[1]: Started UPnP Renderer front-end to MPD. Feb 21 09:59:28 rpi0w1-audio sudo[1124]: pam_unix(sudo:session): session closed for user root Feb 21 09:59:29 rpi0w1-audio volumio[842]: info: Output device has changed, restarting Shairport Sync Feb 21 09:59:29 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 09:59:29 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 09:59:29 rpi0w1-audio sudo[1127]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 21 09:59:29 rpi0w1-audio sudo[1127]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 09:59:29 rpi0w1-audio sudo[1127]: pam_unix(sudo:session): session closed for user root Feb 21 09:59:29 rpi0w1-audio sudo[1134]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 21 09:59:29 rpi0w1-audio sudo[1134]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 09:59:29 rpi0w1-audio systemd[1]: Stopping Music Player Daemon... Feb 21 09:59:30 rpi0w1-audio systemd[1]: mpd.service: Succeeded. Feb 21 09:59:30 rpi0w1-audio systemd[1]: Stopped Music Player Daemon. Feb 21 09:59:30 rpi0w1-audio systemd[1]: Starting Music Player Daemon... Feb 21 09:59:30 rpi0w1-audio volumio[842]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 21 09:59:30 rpi0w1-audio volumio[842]: info: ___________ START PLUGINS ___________ Feb 21 09:59:30 rpi0w1-audio volumio[842]: info: ControllerMpd::onStart: Initializing MPD Feb 21 09:59:30 rpi0w1-audio volumio[842]: info: Creating MPD Configuration file Feb 21 09:59:30 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 21 09:59:30 rpi0w1-audio volumio[842]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 21 09:59:30 rpi0w1-audio volumio[842]: info: [1771667970797] CoreMusicLibrary::Adding element Media Servers Feb 21 09:59:30 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 09:59:30 rpi0w1-audio sudo[1150]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 21 09:59:30 rpi0w1-audio sudo[1150]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 09:59:30 rpi0w1-audio sudo[1150]: pam_unix(sudo:session): session closed for user root Feb 21 09:59:31 rpi0w1-audio sudo[1152]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 21 09:59:31 rpi0w1-audio sudo[1152]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 09:59:31 rpi0w1-audio sudo[1154]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 21 09:59:31 rpi0w1-audio sudo[1154]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 09:59:31 rpi0w1-audio sudo[1152]: pam_unix(sudo:session): session closed for user root Feb 21 09:59:31 rpi0w1-audio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Feb 21 09:59:31 rpi0w1-audio systemd[1]: mpd.service: Succeeded. Feb 21 09:59:31 rpi0w1-audio systemd[1]: Stopped Music Player Daemon. Feb 21 09:59:31 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 09:59:31 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 09:59:31 rpi0w1-audio systemd[1]: Starting Music Player Daemon... Feb 21 09:59:32 rpi0w1-audio volumio[842]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 21 09:59:32 rpi0w1-audio sudo[1159]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 21 09:59:32 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 09:59:32 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 09:59:32 rpi0w1-audio sudo[1159]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 09:59:32 rpi0w1-audio sudo[1159]: pam_unix(sudo:session): session closed for user root Feb 21 09:59:32 rpi0w1-audio volumio-remote-updater[343]: [2026-02-21 09:59:32] [connect] Successful connection Feb 21 09:59:32 rpi0w1-audio volumio[842]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 21 09:59:32 rpi0w1-audio volumio[842]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 21 09:59:32 rpi0w1-audio volumio[842]: info: [1771667972869] CoreMusicLibrary::Adding element Last_100 Feb 21 09:59:32 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 09:59:32 rpi0w1-audio volumio[842]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 21 09:59:32 rpi0w1-audio volumio[842]: info: [1771667972912] CoreMusicLibrary::Adding element Webradio Feb 21 09:59:32 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 09:59:33 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 21 09:59:33 rpi0w1-audio volumio[842]: info: Initializing BBC Radios Feb 21 09:59:33 rpi0w1-audio volumio[842]: /usr/bin/md5sum: /sys/class/net/eth0/address: No such file or directory Feb 21 09:59:33 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 09:59:33 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 21 09:59:33 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 09:59:34 rpi0w1-audio volumio[842]: info: Creating Spotify config file Feb 21 09:59:34 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 09:59:35 rpi0w1-audio volumio[842]: Starting albumart workers Feb 21 09:59:35 rpi0w1-audio volumio[842]: info: Volumio Calling Home Feb 21 09:59:38 rpi0w1-audio volumio[842]: info: MPD Permissions set Feb 21 09:59:38 rpi0w1-audio volumio[842]: info: MPD Permissions set Feb 21 09:59:38 rpi0w1-audio volumio[842]: info: Upmpdcli Daemon Started Feb 21 09:59:38 rpi0w1-audio volumio[842]: info: Volumio called home Feb 21 09:59:38 rpi0w1-audio volumio[842]: info: Spotify config file written Feb 21 09:59:39 rpi0w1-audio sudo[1184]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 21 09:59:39 rpi0w1-audio sudo[1184]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 09:59:39 rpi0w1-audio systemd[1]: Started go-librespot Daemon. Feb 21 09:59:39 rpi0w1-audio go-librespot[1186]: go-librespot daemon starting... Feb 21 09:59:39 rpi0w1-audio sudo[1184]: pam_unix(sudo:session): session closed for user root Feb 21 09:59:40 rpi0w1-audio go-librespot[1186]: time="2026-02-21T09:59:40Z" level=info msg="running go-librespot 0.4.0" Feb 21 09:59:40 rpi0w1-audio go-librespot[1186]: time="2026-02-21T09:59:40Z" level=debug msg="app state loaded" Feb 21 09:59:40 rpi0w1-audio go-librespot[1186]: time="2026-02-21T09:59:40Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 09:59:42 rpi0w1-audio mpd_monitor.sh[357]: MPD Monitor Service: MPD Appears to be inactive, restarting Feb 21 09:59:42 rpi0w1-audio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Feb 21 09:59:42 rpi0w1-audio systemd[1]: mpd.service: Failed with result 'protocol'. Feb 21 09:59:42 rpi0w1-audio systemd[1]: Failed to start Music Player Daemon. Feb 21 09:59:43 rpi0w1-audio sudo[1154]: pam_unix(sudo:session): session closed for user root Feb 21 09:59:43 rpi0w1-audio sudo[1134]: pam_unix(sudo:session): session closed for user root Feb 21 09:59:43 rpi0w1-audio systemd[1]: Starting Music Player Daemon... Feb 21 09:59:43 rpi0w1-audio go-librespot[1186]: time="2026-02-21T09:59:43Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Feb 21 09:59:43 rpi0w1-audio go-librespot[1186]: time="2026-02-21T09:59:43Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 21 09:59:43 rpi0w1-audio go-librespot[1186]: time="2026-02-21T09:59:43Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 21 09:59:44 rpi0w1-audio go-librespot[1186]: time="2026-02-21T09:59:44Z" level=info msg="zeroconf server listening on port 42911" Feb 21 09:59:44 rpi0w1-audio sudo[1208]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 21 09:59:44 rpi0w1-audio sudo[1208]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 09:59:44 rpi0w1-audio go-librespot[1186]: time="2026-02-21T09:59:44Z" level=debug msg="obtained new client token: AAB5cbyOQtU0swJ8pYcOWsd1iRuXvPmzMeQLEmSzEW+ZTg6VxiitC3n4QuLBSE/uCY5NBX/dBQpx/MM0cD6WHccTZbiLk1RLY6h9JgD8tJPnzkxSi7MagVijpRPUtXwD/zfJt9Fzm1ipcbR4bfNv2Q4C698+mr2bH/WLUcrrTNkn8gGCZJIWxIez9Pm8o7vXejk+zUKKJ9kZFtW5HGzvFeUk1rh7gSLP7CZHQLWmykJdQyi2fh269A==" Feb 21 09:59:44 rpi0w1-audio sudo[1208]: pam_unix(sudo:session): session closed for user root Feb 21 09:59:44 rpi0w1-audio go-librespot[1186]: time="2026-02-21T09:59:44Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 21 09:59:44 rpi0w1-audio go-librespot[1186]: time="2026-02-21T09:59:44Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 21 09:59:44 rpi0w1-audio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 21 09:59:44 rpi0w1-audio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 21 09:59:44 rpi0w1-audio volumio[842]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Feb 21 09:59:44 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 09:59:44 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 09:59:45 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 09:59:45 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 09:59:45 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 09:59:45 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 09:59:45 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 09:59:45 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 09:59:45 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 09:59:45 rpi0w1-audio volumio[842]: info: No need to fix Spotify hosts Feb 21 09:59:47 rpi0w1-audio volumio-remote-updater[343]: [2026-02-21 09:59:47] [connect] Successful connection Feb 21 09:59:47 rpi0w1-audio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 21 09:59:47 rpi0w1-audio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 21 09:59:47 rpi0w1-audio systemd[1]: Stopped go-librespot Daemon. Feb 21 09:59:47 rpi0w1-audio systemd[1]: Started go-librespot Daemon. Feb 21 09:59:47 rpi0w1-audio go-librespot[1227]: go-librespot daemon starting... Feb 21 09:59:48 rpi0w1-audio go-librespot[1227]: time="2026-02-21T09:59:48Z" level=info msg="running go-librespot 0.4.0" Feb 21 09:59:48 rpi0w1-audio go-librespot[1227]: time="2026-02-21T09:59:48Z" level=debug msg="app state loaded" Feb 21 09:59:48 rpi0w1-audio go-librespot[1227]: time="2026-02-21T09:59:48Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 09:59:48 rpi0w1-audio volumio[842]: info: Cannot restart MPD: Error: Command failed: /usr/bin/sudo /bin/systemctl restart mpd.service Feb 21 09:59:48 rpi0w1-audio volumio[842]: Job for mpd.service failed because the service did not take the steps required by its unit configuration. Feb 21 09:59:48 rpi0w1-audio volumio[842]: See "systemctl status mpd.service" and "journalctl -xe" for details. Feb 21 09:59:48 rpi0w1-audio volumio[842]: error: Cannot start MPD on system Start: Error: Command failed: /usr/bin/sudo /bin/systemctl restart mpd.service Feb 21 09:59:48 rpi0w1-audio volumio[842]: Job for mpd.service failed because the service did not take the steps required by its unit configuration. Feb 21 09:59:48 rpi0w1-audio volumio[842]: See "systemctl status mpd.service" and "journalctl -xe" for details. Feb 21 09:59:48 rpi0w1-audio volumio[842]: info: Completed starting Core Plugins Feb 21 09:59:48 rpi0w1-audio volumio[842]: info: ------------------------------------------- Feb 21 09:59:48 rpi0w1-audio volumio[842]: info: ----- MyVolumio plugins startup ---- Feb 21 09:59:48 rpi0w1-audio volumio[842]: info: ------------------------------------------- Feb 21 09:59:48 rpi0w1-audio volumio[842]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 21 09:59:49 rpi0w1-audio volumio[842]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 21 09:59:49 rpi0w1-audio volumio[842]: SPOTIFY: BQAwIN1jNkeKWGVS_AxiZs69J3t-V43Ubo_MubriCruCQzg5E1fWkK6XGf2TrJwvPFPePO5J366Mik6ASzy8FQQ_uhJHpulex23UMnZvf5v8Mq63XxOt9Rkd2D9IOYPhX_8rcyTs-bXIy8LIsDKjrBo3smKj7C5mPt8THhFqm5_dIyIHwFl-BIJ-7ph67oRAGA-ZJBW18DdnnpTl0fmiUCIUZkmHd4_IRXV1RhteLVLakFIWiEqBsCB7XSBUPko_xgA0l2Uh8dZPrTWdcAPHiHiDHhu8gNuhCta22lGsdU-Wi3YlDax-qRHMguN0 Feb 21 09:59:49 rpi0w1-audio volumio[842]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 21 09:59:49 rpi0w1-audio volumio[842]: info: New Spotify access token = BQAwIN1jNkeKWGVS_AxiZs69J3t-V43Ubo_MubriCruCQzg5E1fWkK6XGf2TrJwvPFPePO5J366Mik6ASzy8FQQ_uhJHpulex23UMnZvf5v8Mq63XxOt9Rkd2D9IOYPhX_8rcyTs-bXIy8LIsDKjrBo3smKj7C5mPt8THhFqm5_dIyIHwFl-BIJ-7ph67oRAGA-ZJBW18DdnnpTl0fmiUCIUZkmHd4_IRXV1RhteLVLakFIWiEqBsCB7XSBUPko_xgA0l2Uh8dZPrTWdcAPHiHiDHhu8gNuhCta22lGsdU-Wi3YlDax-qRHMguN0 Feb 21 09:59:49 rpi0w1-audio volumio[842]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 21 09:59:49 rpi0w1-audio volumio-remote-updater[343]: [2026-02-21 09:59:49] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1771667987 101 Feb 21 09:59:49 rpi0w1-audio volumio[842]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 2 Feb 21 09:59:49 rpi0w1-audio volumio[842]: info: Starting Shairport Sync Feb 21 09:59:49 rpi0w1-audio volumio[842]: info: Starting Shairport Sync Feb 21 09:59:49 rpi0w1-audio volumio[842]: info: Starting Shairport Sync Feb 21 09:59:49 rpi0w1-audio sudo[1234]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 21 09:59:50 rpi0w1-audio sudo[1234]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 09:59:50 rpi0w1-audio go-librespot[1227]: time="2026-02-21T09:59:50Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 21 09:59:50 rpi0w1-audio go-librespot[1227]: time="2026-02-21T09:59:50Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 21 09:59:50 rpi0w1-audio go-librespot[1227]: time="2026-02-21T09:59:50Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 21 09:59:50 rpi0w1-audio sudo[1236]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 21 09:59:50 rpi0w1-audio go-librespot[1227]: time="2026-02-21T09:59:50Z" level=info msg="zeroconf server listening on port 46211" Feb 21 09:59:50 rpi0w1-audio sudo[1236]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 09:59:50 rpi0w1-audio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Feb 21 09:59:50 rpi0w1-audio systemd[1]: shairport-sync.service: Succeeded. Feb 21 09:59:50 rpi0w1-audio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Feb 21 09:59:50 rpi0w1-audio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Feb 21 09:59:50 rpi0w1-audio sudo[1239]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 21 09:59:50 rpi0w1-audio sudo[1234]: pam_unix(sudo:session): session closed for user root Feb 21 09:59:50 rpi0w1-audio go-librespot[1227]: time="2026-02-21T09:59:50Z" level=debug msg="obtained new client token: AACUPJkAwgn3Fb3lM1KzlT6QP/UwK9s7nkBqlamKedYq8uGW5CwM+NPk/ClWSr7peKcv08AwqYE/i/3WyfdNiItDETLNfii3VbfCk9Pq7lCNjPcKl614H1nxlyaiHIat2qFIIrF9cHDFQxqLueXznMbnqHFo1/3lCBUv2XcdAR7IjqWYPhDefdFm10cB1UcP4FW24uqZ24gpZP4YHplZpsnFAyYoLcieKEzQawaQ0iZ3IAJN7sD4PQ==" Feb 21 09:59:50 rpi0w1-audio sudo[1239]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 09:59:51 rpi0w1-audio volumio[842]: info: CoreCommandRouter::volumioGetState Feb 21 09:59:51 rpi0w1-audio volumio[842]: info: CorePlayQueue::getTrack 0 Feb 21 09:59:51 rpi0w1-audio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Feb 21 09:59:51 rpi0w1-audio go-librespot[1227]: time="2026-02-21T09:59:51Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 21 09:59:51 rpi0w1-audio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Feb 21 09:59:51 rpi0w1-audio go-librespot[1227]: time="2026-02-21T09:59:51Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 21 09:59:51 rpi0w1-audio systemd[1]: shairport-sync.service: Succeeded. Feb 21 09:59:51 rpi0w1-audio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Feb 21 09:59:51 rpi0w1-audio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 21 09:59:51 rpi0w1-audio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 21 09:59:51 rpi0w1-audio volumio[842]: info: go-librespot daemon successfully initialized Feb 21 09:59:51 rpi0w1-audio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Feb 21 09:59:51 rpi0w1-audio sudo[1236]: pam_unix(sudo:session): session closed for user root Feb 21 09:59:51 rpi0w1-audio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Feb 21 09:59:51 rpi0w1-audio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Feb 21 09:59:51 rpi0w1-audio systemd[1]: shairport-sync.service: Succeeded. Feb 21 09:59:51 rpi0w1-audio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Feb 21 09:59:51 rpi0w1-audio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Feb 21 09:59:51 rpi0w1-audio sudo[1239]: pam_unix(sudo:session): session closed for user root Feb 21 09:59:52 rpi0w1-audio volumio[842]: info: Shairport-Sync Started Feb 21 09:59:52 rpi0w1-audio volumio[842]: Error adding Membership: Error: addMembership EINVAL Feb 21 09:59:52 rpi0w1-audio volumio[842]: info: Shairport-Sync Started Feb 21 09:59:52 rpi0w1-audio volumio[842]: info: Shairport-Sync Started Feb 21 09:59:52 rpi0w1-audio volumio[842]: SPOTIFY: User informations: {"country":"GB","display_name":"Ben Luck","email":"benluck301@googlemail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/3132a7ta5ciucmgigi4yneds2iay"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/3132a7ta5ciucmgigi4yneds2iay","id":"3132a7ta5ciucmgigi4yneds2iay","images":[],"product":"premium","type":"user","uri":"spotify:user:3132a7ta5ciucmgigi4yneds2iay"} Feb 21 09:59:52 rpi0w1-audio volumio[842]: info: Spotify Successfully logged in Feb 21 09:59:52 rpi0w1-audio volumio[842]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 21 09:59:52 rpi0w1-audio volumio[842]: info: [1771667992785] CoreMusicLibrary::Adding element Spotify Feb 21 09:59:52 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 09:59:52 rpi0w1-audio volumio[842]: Cannot find translation for source Spotify Feb 21 09:59:54 rpi0w1-audio volumio[842]: info: Initializing connection to go-librespot Websocket Feb 21 09:59:54 rpi0w1-audio volumio[842]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 21 09:59:54 rpi0w1-audio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 21 09:59:54 rpi0w1-audio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 21 09:59:54 rpi0w1-audio systemd[1]: Stopped go-librespot Daemon. Feb 21 09:59:54 rpi0w1-audio systemd[1]: Started go-librespot Daemon. Feb 21 09:59:54 rpi0w1-audio go-librespot[1261]: go-librespot daemon starting... Feb 21 09:59:54 rpi0w1-audio go-librespot[1261]: time="2026-02-21T09:59:54Z" level=info msg="running go-librespot 0.4.0" Feb 21 09:59:54 rpi0w1-audio go-librespot[1261]: time="2026-02-21T09:59:54Z" level=debug msg="app state loaded" Feb 21 09:59:54 rpi0w1-audio go-librespot[1261]: time="2026-02-21T09:59:54Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 09:59:56 rpi0w1-audio go-librespot[1261]: time="2026-02-21T09:59:56Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 21 09:59:56 rpi0w1-audio go-librespot[1261]: time="2026-02-21T09:59:56Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 21 09:59:56 rpi0w1-audio go-librespot[1261]: time="2026-02-21T09:59:56Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 21 09:59:56 rpi0w1-audio go-librespot[1261]: time="2026-02-21T09:59:56Z" level=info msg="zeroconf server listening on port 33285" Feb 21 09:59:56 rpi0w1-audio go-librespot[1261]: time="2026-02-21T09:59:56Z" level=debug msg="obtained new client token: AAA87GeriwEBeByuUF1jUfLsMUSDe33XTTMp2a/yhWXb4RKZPpr2rma9bJOY5LbwQebIPa9ToFqTIoJbC4sa2nPtpwb4EiWpuk5P8d4ic6dfJVwOzHZjjNbIXBITc3u3A6RZrA2az1gI+iOM/vHRzpOWV00IVhEhHtAZth/ntqVcbATGejezryWvpte+kZ5uAFN9LOtfPC0aPV9cMR9fTN9tdrk4WE33X5wjK2/Du4Gov65Li28B8A==" Feb 21 09:59:56 rpi0w1-audio go-librespot[1261]: time="2026-02-21T09:59:56Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 21 09:59:56 rpi0w1-audio go-librespot[1261]: time="2026-02-21T09:59:56Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 21 09:59:56 rpi0w1-audio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 21 09:59:56 rpi0w1-audio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 21 09:59:57 rpi0w1-audio volumio[842]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 21 09:59:57 rpi0w1-audio volumio[842]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 21 09:59:57 rpi0w1-audio volumio[842]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 21 09:59:57 rpi0w1-audio volumio[842]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 21 09:59:57 rpi0w1-audio volumio[842]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 21 09:59:57 rpi0w1-audio volumio[842]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 21 09:59:57 rpi0w1-audio volumio[842]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 21 09:59:57 rpi0w1-audio volumio[842]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 21 09:59:57 rpi0w1-audio volumio[842]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 21 09:59:57 rpi0w1-audio volumio[842]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 21 09:59:57 rpi0w1-audio volumio[842]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 21 09:59:57 rpi0w1-audio volumio[842]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 21 09:59:57 rpi0w1-audio volumio[842]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 21 09:59:57 rpi0w1-audio volumio[842]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 21 09:59:57 rpi0w1-audio volumio[842]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 21 09:59:57 rpi0w1-audio volumio[842]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 21 09:59:57 rpi0w1-audio volumio[842]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 21 09:59:57 rpi0w1-audio volumio[842]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 21 09:59:57 rpi0w1-audio volumio[842]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 21 09:59:57 rpi0w1-audio volumio[842]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 21 09:59:57 rpi0w1-audio volumio[842]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 21 09:59:57 rpi0w1-audio volumio[842]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 21 09:59:57 rpi0w1-audio volumio[842]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 21 09:59:57 rpi0w1-audio volumio[842]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 21 09:59:57 rpi0w1-audio volumio[842]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 21 09:59:57 rpi0w1-audio volumio[842]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 21 09:59:57 rpi0w1-audio volumio[842]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 21 09:59:57 rpi0w1-audio volumio[842]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 21 09:59:57 rpi0w1-audio volumio[842]: info: Adding plugin bluetooth to MyMusic Plugins Feb 21 09:59:57 rpi0w1-audio volumio[842]: info: Adding plugin multiroom to MyMusic Plugins Feb 21 09:59:57 rpi0w1-audio volumio[842]: info: Adding plugin metavolumio to MyMusic Plugins Feb 21 09:59:57 rpi0w1-audio volumio[842]: info: Adding plugin cd_controller to MyMusic Plugins Feb 21 09:59:57 rpi0w1-audio volumio[842]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 21 09:59:57 rpi0w1-audio volumio[842]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 21 09:59:57 rpi0w1-audio volumio[842]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 21 09:59:59 rpi0w1-audio mpd[1210]: Feb 21 09:59 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 21 09:59:59 rpi0w1-audio systemd[1]: Started Music Player Daemon. Feb 21 09:59:59 rpi0w1-audio mpd_monitor.sh[357]: MPD Monitor Service: MPD restarted due to no mpc output. Feb 21 09:59:59 rpi0w1-audio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 21 09:59:59 rpi0w1-audio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 21 09:59:59 rpi0w1-audio systemd[1]: Stopped go-librespot Daemon. Feb 21 09:59:59 rpi0w1-audio systemd[1]: Started go-librespot Daemon. Feb 21 09:59:59 rpi0w1-audio go-librespot[1270]: go-librespot daemon starting... Feb 21 10:00:00 rpi0w1-audio go-librespot[1270]: time="2026-02-21T10:00:00Z" level=info msg="running go-librespot 0.4.0" Feb 21 10:00:00 rpi0w1-audio go-librespot[1270]: time="2026-02-21T10:00:00Z" level=debug msg="app state loaded" Feb 21 10:00:00 rpi0w1-audio go-librespot[1270]: time="2026-02-21T10:00:00Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 10:00:01 rpi0w1-audio go-librespot[1270]: time="2026-02-21T10:00:01Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 21 10:00:01 rpi0w1-audio go-librespot[1270]: time="2026-02-21T10:00:01Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 21 10:00:01 rpi0w1-audio go-librespot[1270]: time="2026-02-21T10:00:01Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 21 10:00:01 rpi0w1-audio go-librespot[1270]: time="2026-02-21T10:00:01Z" level=info msg="zeroconf server listening on port 40347" Feb 21 10:00:02 rpi0w1-audio go-librespot[1270]: time="2026-02-21T10:00:02Z" level=debug msg="obtained new client token: AAA3m8ARnJlTP9x5elsHKaT5V/K7GDQZ7VW/nvxnbbJIYOOAxq2GMpXq+viybYJn4+oE5aPXwJx2EV9hwIZVmhpWPh0UgkUTFry+RGIWh4RXSmuVTbuxcP0bX9BQlhDxVnxHdehQhVC44qY9NzHOzG7pLVAf0Z+yQtrW57yo5Ls4Y5+zTuelVlS9dPel/wj9wu/pTOz5p8fm5uAyO8zJqEgMSqFoBY+enuTCkDecZh6gtr/cebc=" Feb 21 10:00:02 rpi0w1-audio go-librespot[1270]: time="2026-02-21T10:00:02Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 21 10:00:02 rpi0w1-audio go-librespot[1270]: time="2026-02-21T10:00:02Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 21 10:00:02 rpi0w1-audio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 21 10:00:02 rpi0w1-audio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 21 10:00:05 rpi0w1-audio volumio[842]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 21 10:00:05 rpi0w1-audio volumio[842]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 21 10:00:05 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 10:00:05 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 10:00:05 rpi0w1-audio volumio[842]: info: Starting MyVolumio Remote Streaming Endpoints Feb 21 10:00:05 rpi0w1-audio volumio[842]: info: MyVolumio login type: Token Feb 21 10:00:05 rpi0w1-audio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 21 10:00:05 rpi0w1-audio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 21 10:00:05 rpi0w1-audio systemd[1]: Stopped go-librespot Daemon. Feb 21 10:00:05 rpi0w1-audio systemd[1]: Started go-librespot Daemon. Feb 21 10:00:05 rpi0w1-audio go-librespot[1328]: go-librespot daemon starting... Feb 21 10:00:05 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:05Z" level=info msg="running go-librespot 0.4.0" Feb 21 10:00:05 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:05Z" level=debug msg="app state loaded" Feb 21 10:00:05 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:05Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 10:00:05 rpi0w1-audio volumio[842]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 21 10:00:05 rpi0w1-audio volumio[842]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 21 10:00:07 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:07Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 21 10:00:07 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:07Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 21 10:00:07 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:07Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 21 10:00:07 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:07Z" level=info msg="zeroconf server listening on port 40359" Feb 21 10:00:07 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:07Z" level=debug msg="obtained new client token: AADdoS5yfIrxVntOmExPtNG0fUR8YO6B++Tl7CgvqJkUtxeXHSn5yNvpcXZEAb9jxNN5JHctUngzBm/KLT8dwQdn7XOxm3o906+ZBDUXkU8a2g4dgUYPuusQhb3ViMRP2yJnR9r2LBHj+uyfYD54yRGAz08G9nr21DWWGkSXZGXcKPmtpqQoLeymzRXE7fL8+yTTfUaNMTQ2RC9s7fu94slSXSPNly15QlzFwvs2s9+H3ZXVfCEXPA==" Feb 21 10:00:07 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:07Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 21 10:00:07 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:07Z" level=debug msg="completed keyexchange" Feb 21 10:00:07 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:07Z" level=debug msg="completed challenge" Feb 21 10:00:07 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:07Z" level=info msg="authenticated AP" username="31************************ay" Feb 21 10:00:08 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:08Z" level=info msg="authenticated Login5" username="31************************ay" Feb 21 10:00:08 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:08Z" level=debug msg="initializing zeroconf session" username="31************************ay" Feb 21 10:00:08 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:08Z" level=debug msg="dealer connection opened" Feb 21 10:00:08 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:08Z" level=trace msg="starting accesspoint recv loop" Feb 21 10:00:08 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:08Z" level=trace msg="starting dealer recv loop" Feb 21 10:00:08 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:08Z" level=trace msg="received accesspoint ping" Feb 21 10:00:08 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:08Z" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Feb 21 10:00:08 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:08Z" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Feb 21 10:00:08 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:08Z" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Feb 21 10:00:08 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:08Z" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Feb 21 10:00:08 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:08Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Feb 21 10:00:08 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:08Z" level=debug msg="received connection id: NjJmMDM0ZGQtZDdj...MTlEQTAyNDM1Rg==" Feb 21 10:00:08 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:08Z" level=trace msg="received accesspoint pong ack" Feb 21 10:00:08 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:08Z" level=debug msg="put connect state because NEW_DEVICE" Feb 21 10:00:11 rpi0w1-audio volumio[842]: info: Starting Streaming Service Transparent Proxy Feb 21 10:00:11 rpi0w1-audio volumio[842]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 21 10:00:11 rpi0w1-audio volumio[842]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 21 10:00:11 rpi0w1-audio volumio[842]: info: Streaming services startup Feb 21 10:00:11 rpi0w1-audio volumio[842]: info: Starting Streaming Daemon Feb 21 10:00:12 rpi0w1-audio sudo[1341]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 21 10:00:12 rpi0w1-audio sudo[1341]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 10:00:12 rpi0w1-audio volumio[842]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 21 10:00:12 rpi0w1-audio sudo[1341]: pam_unix(sudo:session): session closed for user root Feb 21 10:00:12 rpi0w1-audio volumio[842]: info: Initializing connection to go-librespot Websocket Feb 21 10:00:13 rpi0w1-audio volumio[842]: /usr/bin/md5sum: /sys/class/net/eth0/address: No such file or directory Feb 21 10:00:13 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 10:00:13 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 21 10:00:13 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 10:00:13 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 21 10:00:13 rpi0w1-audio volumio[842]: Upnp client error: Error: This socket has been ended by the other party Feb 21 10:00:13 rpi0w1-audio volumio[842]: error: MPD error: The expression evaluated to a falsy value: Feb 21 10:00:13 rpi0w1-audio volumio[842]: assert.ok(self.idling) Feb 21 10:00:14 rpi0w1-audio volumio[842]: error: The expression evaluated to a falsy value: Feb 21 10:00:14 rpi0w1-audio volumio[842]: assert.ok(self.idling) Feb 21 10:00:14 rpi0w1-audio volumio[842]: Upnp client error: Error: This socket has been ended by the other party Feb 21 10:00:14 rpi0w1-audio volumio[842]: Upnp client error: Error: This socket has been ended by the other party Feb 21 10:00:14 rpi0w1-audio volumio[842]: Upnp client error: Error: This socket has been ended by the other party Feb 21 10:00:14 rpi0w1-audio volumio[842]: error: Cannot start Volumio Streaming Daemon Feb 21 10:00:14 rpi0w1-audio volumio[842]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 21 10:00:14 rpi0w1-audio volumio[842]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 21 10:00:14 rpi0w1-audio volumio[842]: error: updateQueue error: null Feb 21 10:00:14 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:14Z" level=debug msg="new websocket client" Feb 21 10:00:14 rpi0w1-audio volumio[842]: verbose: New Socket.io Connection to 192.168.50.57:3000 from 192.168.50.114 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 3 Feb 21 10:00:14 rpi0w1-audio volumio[842]: verbose: New Socket.io Connection to 192.168.50.57:3000 from 192.168.50.114 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 4 Feb 21 10:00:14 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 10:00:14 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 10:00:14 rpi0w1-audio volumio[842]: info: Discovery: Getting this device information Feb 21 10:00:14 rpi0w1-audio volumio[842]: info: CoreCommandRouter::volumioGetState Feb 21 10:00:14 rpi0w1-audio volumio[842]: info: CorePlayQueue::getTrack 0 Feb 21 10:00:14 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 10:00:15 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 10:00:15 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 10:00:15 rpi0w1-audio volumio[842]: info: Discovery: Getting this device information Feb 21 10:00:15 rpi0w1-audio volumio[842]: info: CoreCommandRouter::volumioGetState Feb 21 10:00:15 rpi0w1-audio volumio[842]: info: CorePlayQueue::getTrack 0 Feb 21 10:00:15 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 10:00:15 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 10:00:15 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 10:00:15 rpi0w1-audio volumio[842]: info: Discovery: Getting this device information Feb 21 10:00:15 rpi0w1-audio volumio[842]: info: CoreCommandRouter::volumioGetState Feb 21 10:00:15 rpi0w1-audio volumio[842]: info: CorePlayQueue::getTrack 0 Feb 21 10:00:15 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 10:00:15 rpi0w1-audio volumio[842]: info: Connection to go-librespot Websocket established Feb 21 10:00:15 rpi0w1-audio volumio[842]: Upnp client error: Error: This socket has been ended by the other party Feb 21 10:00:15 rpi0w1-audio volumio[842]: error: MyVolumio Custom Token format not valid, refreshing it Feb 21 10:00:15 rpi0w1-audio volumio[842]: verbose: New Socket.io Connection to 192.168.50.57:3000 from 192.168.50.114 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 5 Feb 21 10:00:15 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 21 10:00:15 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 21 10:00:15 rpi0w1-audio volumio[842]: info: Discovery: Getting this device information Feb 21 10:00:15 rpi0w1-audio volumio[842]: info: CoreCommandRouter::volumioGetState Feb 21 10:00:15 rpi0w1-audio volumio[842]: info: CorePlayQueue::getTrack 0 Feb 21 10:00:16 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 21 10:00:16 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 21 10:00:16 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 21 10:00:16 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:16Z" level=debug msg="handling transfer player command from 7dfc46163d2e7a3fdfee0fa8797abe8aea1410f6" Feb 21 10:00:16 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:16Z" level=debug msg="resolved context of track" uri="spotify:playlist:0KKNidb5p3dXSwtWBXsWTL" Feb 21 10:00:16 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:16Z" level=trace msg="fetched new page 0 with 18 items (list: 18)" uri="spotify:playlist:0KKNidb5p3dXSwtWBXsWTL" Feb 21 10:00:16 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:16Z" level=debug msg="loading track (paused: false, position: 8594ms)" uri="spotify:track:6Awm7CReaVZaHlaRufcP78" Feb 21 10:00:16 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:16Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1135" Feb 21 10:00:16 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:16Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 411" Feb 21 10:00:16 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:16Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 21 10:00:16 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:16Z" level=trace msg="emitting websocket event: will_play" Feb 21 10:00:16 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:16Z" level=debug msg="selected format OGG_VORBIS_320 (b3920f5a0f23f7dfd16392a2024f95339ee02d81)" uri="spotify:track:6Awm7CReaVZaHlaRufcP78" Feb 21 10:00:16 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:16Z" level=debug msg="requested aes key for file b3920f5a0f23f7dfd16392a2024f95339ee02d81, gid: 6Awm7CReaVZaHlaRufcP78" Feb 21 10:00:17 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:17Z" level=trace msg="found 2 cdn urls" uri="spotify:track:6Awm7CReaVZaHlaRufcP78" Feb 21 10:00:17 rpi0w1-audio volumio-remote-updater[343]: No test mode Feb 21 10:00:17 rpi0w1-audio volumio-remote-updater[343]: No alpha test mode Feb 21 10:00:17 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Feb 21 10:00:17 rpi0w1-audio volumio[842]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:playlist:0KKNidb5p3dXSwtWBXsWTL","uri":"spotify:track:6Awm7CReaVZaHlaRufcP78","play_origin":"playlist/ondemand"}} Feb 21 10:00:18 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:18Z" level=debug msg="fetched first chunk of 14, total size is 7228496 bytes" uri="spotify:track:6Awm7CReaVZaHlaRufcP78" Feb 21 10:00:18 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:18Z" level=trace msg="seek to 8594ms (diff: 111ms, samples: 378995, bytes: 360915)" uri="spotify:track:6Awm7CReaVZaHlaRufcP78" Feb 21 10:00:18 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:18Z" level=debug msg="created new output device" Feb 21 10:00:18 rpi0w1-audio volumio[842]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"

FIXES

    • Fix for BT connection requests

 

NEW ADDITIONS

    • BLE-based onboarding setup
    • Update Tidal SDK

 

","title":"Update v3.908","updateavailable":true} Feb 21 10:00:19 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Feb 21 10:00:19 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:19Z" level=debug msg="fetched chunk 3/13, size: 524288" uri="spotify:track:6Awm7CReaVZaHlaRufcP78" Feb 21 10:00:19 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:19Z" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 100000 us, period size = 4410 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 5 frames, PCM format = FLOAT_LE" Feb 21 10:00:19 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:19Z" level=info msg="loaded track \"Very Big in Sheboygan\" (paused: false, position: 8594ms, duration: 170660ms, prefetched: false)" uri="spotify:track:6Awm7CReaVZaHlaRufcP78" Feb 21 10:00:19 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:19Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 21 10:00:20 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:20Z" level=debug msg="fetched chunk 1/13, size: 524288" uri="spotify:track:6Awm7CReaVZaHlaRufcP78" Feb 21 10:00:20 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:20Z" level=trace msg="scheduling prefetch in 132s" Feb 21 10:00:20 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:20Z" level=trace msg="emitting websocket event: metadata" Feb 21 10:00:20 rpi0w1-audio volumio[842]: info: Getting Spotify volume Feb 21 10:00:20 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:20Z" level=trace msg="emitting websocket event: active" Feb 21 10:00:20 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:20Z" level=debug msg="sending successful reply for dealer request" Feb 21 10:00:20 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:20Z" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Feb 21 10:00:20 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:20Z" level=debug msg="fetched chunk 2/13, size: 524288" uri="spotify:track:6Awm7CReaVZaHlaRufcP78" Feb 21 10:00:20 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:20Z" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Feb 21 10:00:20 rpi0w1-audio volumio[842]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 21 10:00:20 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:20Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 21 10:00:20 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:20Z" level=trace msg="emitting websocket event: playing" Feb 21 10:00:20 rpi0w1-audio volumio[842]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 21 10:00:21 rpi0w1-audio volumio[842]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:6Awm7CReaVZaHlaRufcP78","name":"Very Big in Sheboygan","artist_names":["Ben Quad"],"album_name":"Wisher","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02026d09ab795ce6954e851fb1","position":8594,"duration":170660,"release_date":"year:2025 month:11 day:14","track_number":6,"disc_number":1}} Feb 21 10:00:21 rpi0w1-audio volumio[842]: SPOTIFY: received: {"type":"active","data":null} Feb 21 10:00:21 rpi0w1-audio volumio[842]: info: Aligning Spotify Volume to Volumio Volume Feb 21 10:00:21 rpi0w1-audio volumio[842]: info: CoreCommandRouter::volumioGetState Feb 21 10:00:21 rpi0w1-audio volumio[842]: info: CorePlayQueue::getTrack 0 Feb 21 10:00:21 rpi0w1-audio volumio[842]: info: Setting Spotify Volume from Volumio: 86 Feb 21 10:00:21 rpi0w1-audio volumio[842]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:playlist:0KKNidb5p3dXSwtWBXsWTL","uri":"spotify:track:6Awm7CReaVZaHlaRufcP78","resume":false,"play_origin":"playlist/ondemand"}} Feb 21 10:00:21 rpi0w1-audio volumio[842]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 21 10:00:21 rpi0w1-audio volumio[842]: TypeError: Cannot read property 'service' of undefined Feb 21 10:00:21 rpi0w1-audio volumio[842]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:346:50) Feb 21 10:00:21 rpi0w1-audio volumio[842]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:272:18) Feb 21 10:00:21 rpi0w1-audio volumio[842]: at WebSocket.message (/data/plugins/music_service/spop/index.js:199:14) Feb 21 10:00:21 rpi0w1-audio volumio[842]: at WebSocket.emit (events.js:315:20) Feb 21 10:00:21 rpi0w1-audio volumio[842]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Feb 21 10:00:21 rpi0w1-audio volumio[842]: at Receiver.emit (events.js:315:20) Feb 21 10:00:21 rpi0w1-audio volumio[842]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Feb 21 10:00:21 rpi0w1-audio volumio[842]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Feb 21 10:00:21 rpi0w1-audio volumio[842]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Feb 21 10:00:21 rpi0w1-audio volumio[842]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Feb 21 10:00:21 rpi0w1-audio volumio[842]: at writeOrBuffer (internal/streams/writable.js:358:12) Feb 21 10:00:21 rpi0w1-audio volumio[842]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Feb 21 10:00:21 rpi0w1-audio volumio[842]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Feb 21 10:00:21 rpi0w1-audio volumio[842]: at Socket.emit (events.js:315:20) Feb 21 10:00:21 rpi0w1-audio volumio[842]: at addChunk (internal/streams/readable.js:309:12) Feb 21 10:00:21 rpi0w1-audio volumio[842]: at readableAddChunk (internal/streams/readable.js:284:9) Feb 21 10:00:21 rpi0w1-audio volumio[842]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 21 10:00:23 rpi0w1-audio go-librespot[1328]: time="2026-02-21T10:00:23Z" level=debug msg="fetched chunk 4/13, size: 524288" uri="spotify:track:6Awm7CReaVZaHlaRufcP78" Feb 21 10:00:27 rpi0w1-audio volumio[842]: STREAMING PROXY: Starting server on port 3245 Feb 21 10:00:27 rpi0w1-audio volumio[842]: Node JS runtime: 14 Feb 21 10:00:28 rpi0w1-audio sudo[1392]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-02-21 09:59 Feb 21 10:00:28 rpi0w1-audio sudo[1392]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="a01a833dd28483f88cb390596f5090b7187992af" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 27 Feb 2025 11:42:54 AM CET" VOLUMIO_VERSION="3.795" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="4049a67f1c09d4a94e033ba35a80a144"