Feb 27 07:34:40 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Feb 27 07:34:40 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Feb 27 07:34:40 volumio systemd[1]: setdatetime-helper.service: Consumed 2.862s CPU time. Feb 27 07:34:40 volumio systemd[1]: Reached target multi-user.target - Multi-User System. Feb 27 07:34:40 volumio systemd[1]: Reached target graphical.target - Graphical Interface. Feb 27 07:34:40 volumio volumio[1136]: info: Plugin folders cleanup Feb 27 07:34:40 volumio volumio[1136]: info: Scanning into folder /volumio/app/plugins/ Feb 27 07:34:40 volumio volumio[1136]: info: Scanning category audio_interface Feb 27 07:34:40 volumio volumio[1136]: info: Scanning category miscellanea Feb 27 07:34:40 volumio volumio[1136]: info: Scanning category music_service Feb 27 07:34:40 volumio volumio[1136]: info: Scanning category plugins.json Feb 27 07:34:40 volumio volumio[1136]: info: Scanning category system_controller Feb 27 07:34:40 volumio volumio[1136]: info: Scanning category user_interface Feb 27 07:34:40 volumio volumio[1136]: info: Scanning into folder /data/plugins/ Feb 27 07:34:40 volumio volumio[1136]: info: Scanning category music_service Feb 27 07:34:40 volumio volumio[1136]: info: Plugin folders cleanup completed Feb 27 07:34:40 volumio volumio[1136]: info: ------------------------------------------- Feb 27 07:34:40 volumio volumio[1136]: info: ----- Core plugins startup ---- Feb 27 07:34:40 volumio volumio[1136]: info: ------------------------------------------- Feb 27 07:34:40 volumio volumio[1136]: info: Loading plugins from folder /volumio/app/plugins/ Feb 27 07:34:40 volumio volumio[1136]: info: Adding plugin upnp to MyMusic Plugins Feb 27 07:34:40 volumio volumio[1136]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 27 07:34:40 volumio volumio[1136]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 27 07:34:40 volumio volumio[1136]: info: Loading plugins from folder /data/plugins/ Feb 27 07:34:40 volumio volumio[1136]: info: Loading plugin "system"... Feb 27 07:34:40 volumio systemd[1]: Starting dpkg-db-backup.service - Daily dpkg database backup service... Feb 27 07:34:40 volumio systemd[1]: Started ntpsec-rotate-stats.service - Rotate ntpd stats. Feb 27 07:34:40 volumio systemd[1]: Starting systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP... Feb 27 07:34:40 volumio volumio[1136]: info: Loading plugin "appearance"... Feb 27 07:34:40 volumio systemd[1]: ntpsec-rotate-stats.service: Deactivated successfully. Feb 27 07:34:40 volumio systemd[1]: systemd-update-utmp-runlevel.service: Deactivated successfully. Feb 27 07:34:40 volumio systemd[1]: Finished systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP. Feb 27 07:34:40 volumio systemd[1]: dpkg-db-backup.service: Deactivated successfully. Feb 27 07:34:40 volumio systemd[1]: Finished dpkg-db-backup.service - Daily dpkg database backup service. Feb 27 07:34:40 volumio systemd[1]: Startup finished in 16.157s (kernel) + 22.786s (userspace) = 38.944s. Feb 27 07:34:42 volumio volumio[1136]: info: Loading plugin "network"... Feb 27 07:34:42 volumio volumio[1136]: info: Refreshing Cached IP Addresses Feb 27 07:34:42 volumio volumio[1136]: info: Loading plugin "services"... Feb 27 07:34:42 volumio volumio[1136]: info: Loading plugin "alsa_controller"... Feb 27 07:34:42 volumio sudo[1214]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 27 07:34:42 volumio sudo[1214]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 27 07:34:42 volumio sudo[1212]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 27 07:34:42 volumio sudo[1212]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 27 07:34:42 volumio sudo[1220]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 27 07:34:42 volumio sudo[1220]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 27 07:34:42 volumio sudo[1214]: pam_unix(sudo:session): session closed for user root Feb 27 07:34:42 volumio sudo[1212]: pam_unix(sudo:session): session closed for user root Feb 27 07:34:42 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 27 07:34:42 volumio volumio[1136]: info: Loading plugin "wizard"... Feb 27 07:34:42 volumio volumio[1136]: info: Loading plugin "networkfs"... Feb 27 07:34:43 volumio volumio[1136]: info: Starting Udev Watcher for removable devices Feb 27 07:34:43 volumio volumio[1136]: info: Ignoring mount for partition: boot Feb 27 07:34:43 volumio volumio[1136]: info: Ignoring mount for partition: volumio Feb 27 07:34:43 volumio volumio[1136]: info: Ignoring mount for partition: volumio_data Feb 27 07:34:43 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 27 07:34:43 volumio volumio[1136]: info: Loading plugin "volumio_command_line_client"... Feb 27 07:34:43 volumio volumio[1136]: info: Loading plugin "upnp"... Feb 27 07:34:43 volumio volumio[1136]: info: [1772174083135] Starting Upmpd Daemon Feb 27 07:34:43 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 27 07:34:43 volumio volumio[1136]: info: Loading plugin "my_music"... Feb 27 07:34:43 volumio volumio[1136]: info: Loading plugin "mpd"... Feb 27 07:34:43 volumio sudo[1220]: pam_unix(sudo:session): session closed for user root Feb 27 07:34:43 volumio volumio[1136]: info: Loading plugin "upnp_browser"... Feb 27 07:34:46 volumio volumio[1136]: info: Loading plugin "alarm-clock"... Feb 27 07:34:46 volumio volumio[1136]: info: Loading plugin "airplay_emulation"... Feb 27 07:34:46 volumio volumio[1136]: info: Starting Shairport Sync Feb 27 07:34:46 volumio volumio[1136]: info: Loading plugin "last_100"... Feb 27 07:34:46 volumio volumio[1136]: info: Loading plugin "webradio"... Feb 27 07:34:46 volumio volumio[1136]: info: Loading plugin "i2s_dacs"... Feb 27 07:34:46 volumio volumio[1136]: info: I2S DAC not set, start Auto-detection Feb 27 07:34:46 volumio volumio[1136]: info: Loading plugin "volumiodiscovery"... Feb 27 07:34:46 volumio volumio[1136]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 27 07:34:46 volumio volumio[1136]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 27 07:34:46 volumio volumio[1136]: *** WARNING *** For more information see Feb 27 07:34:46 volumio volumio[1136]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 27 07:34:46 volumio volumio[1136]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 27 07:34:46 volumio volumio[1136]: *** WARNING *** For more information see Feb 27 07:34:46 volumio node[1136]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 27 07:34:46 volumio node[1136]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 27 07:34:46 volumio node[1136]: *** WARNING *** For more information see Feb 27 07:34:46 volumio node[1136]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 27 07:34:46 volumio node[1136]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 27 07:34:46 volumio node[1136]: *** WARNING *** For more information see Feb 27 07:34:46 volumio volumio[1136]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 27 07:34:46 volumio volumio[1136]: info: Discovery: Started advertising with name: Volumio Feb 27 07:34:47 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 27 07:34:47 volumio volumio[1136]: info: Loading plugin "spop"... Feb 27 07:34:50 volumio volumio[1136]: info: Loading plugin "outputs"... Feb 27 07:34:50 volumio volumio[1136]: info: Loading plugin "albumart"... Feb 27 07:34:50 volumio volumio[1136]: info: Plugin example_plugin is not enabled Feb 27 07:34:50 volumio volumio[1136]: info: Loading plugin "inputs"... Feb 27 07:34:50 volumio volumio[1136]: info: Loading plugin "updater_comm"... Feb 27 07:34:51 volumio volumio[1136]: info: Plugin mpdemulation is not enabled Feb 27 07:34:51 volumio volumio[1136]: info: Loading plugin "rest_api"... Feb 27 07:34:51 volumio volumio[1136]: info: Loading plugin "websocket"... Feb 27 07:34:51 volumio volumio[1136]: info: Starting Socket.io Server version 1.7.4 Feb 27 07:34:51 volumio volumio[1136]: info: Loading i18n strings for locale es Feb 27 07:34:51 volumio volumio[1136]: Updating browse sources language Feb 27 07:34:51 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 27 07:34:51 volumio systemd[1]: systemd-fsckd.service: Deactivated successfully. Feb 27 07:34:51 volumio volumio[1249]: Forking 3 albumart workers Feb 27 07:34:52 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 27 07:34:52 volumio volumio[1136]: info: CoreCommandRouter::initPlayerControls Feb 27 07:34:52 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:34:52 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:34:52 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:34:52 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:34:52 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:34:52 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:34:52 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:34:52 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:34:52 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 27 07:34:52 volumio volumio-remote-updater[788]: [2026-02-27 07:34:52] [connect] Successful connection Feb 27 07:34:52 volumio volumio[1136]: Express server listening on port 3000 Feb 27 07:34:52 volumio volumio[1136]: [Metrics] WebUI: 15s 720.46ms Feb 27 07:34:52 volumio volumio[1136]: info: CoreStateMachine::resetVolumioState Feb 27 07:34:52 volumio volumio[1136]: info: CoreStateMachine::getcurrentVolume Feb 27 07:34:52 volumio volumio[1136]: info: CoreCommandRouter::volumioRetrievevolume Feb 27 07:34:52 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 27 07:34:53 volumio volumio[1136]: info: Volumio Network Manager: Network status updated: 1 Feb 27 07:34:53 volumio sudo[1309]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 27 07:34:53 volumio sudo[1309]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 27 07:34:53 volumio sudo[1309]: pam_unix(sudo:session): session closed for user root Feb 27 07:34:53 volumio sudo[1311]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 27 07:34:53 volumio sudo[1311]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 27 07:34:53 volumio sudo[1311]: pam_unix(sudo:session): session closed for user root Feb 27 07:34:54 volumio volumio[1136]: info: VolumeController:: Volume=86 Mute =false Feb 27 07:34:54 volumio volumio[1136]: info: CoreStateMachine::pushState Feb 27 07:34:54 volumio volumio[1136]: info: CorePlayQueue::getTrack 0 Feb 27 07:34:54 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 27 07:34:54 volumio volumio[1136]: info: CoreCommandRouter::volumioPushState Feb 27 07:34:54 volumio volumio[1136]: info: CoreStateMachine::updateTrackBlock Feb 27 07:34:54 volumio volumio[1136]: info: CorePlayQueue::getTrackBlock Feb 27 07:34:54 volumio volumio[1136]: info: CoreCommandRouter::volumioRetrievevolume Feb 27 07:34:54 volumio volumio-remote-updater[788]: [2026-02-27 07:34:54] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1772174092 101 Feb 27 07:34:54 volumio volumio[1136]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 27 07:34:54 volumio volumio[1136]: info: Reloading queue from file Feb 27 07:34:55 volumio volumio[1136]: info: CoreStateMachine::setRepeat null single undefined Feb 27 07:34:55 volumio volumio[1136]: info: CoreStateMachine::pushState Feb 27 07:34:55 volumio volumio[1136]: info: CorePlayQueue::getTrack 0 Feb 27 07:34:55 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 27 07:34:55 volumio volumio[1136]: info: CoreCommandRouter::volumioPushState Feb 27 07:34:55 volumio volumio[1136]: info: CoreStateMachine::setRandom null Feb 27 07:34:55 volumio volumio[1136]: info: CoreStateMachine::pushState Feb 27 07:34:55 volumio volumio[1136]: info: CorePlayQueue::getTrack 0 Feb 27 07:34:55 volumio volumio[1136]: info: CoreCommandRouter::volumioPushState Feb 27 07:34:55 volumio volumio[1136]: info: Setting Device type: Raspberry PI Feb 27 07:34:55 volumio volumio[1136]: info: VolumeController:: Volume=86 Mute =false Feb 27 07:34:55 volumio volumio[1136]: info: CoreStateMachine::pushState Feb 27 07:34:55 volumio volumio[1136]: info: CorePlayQueue::getTrack 0 Feb 27 07:34:55 volumio volumio[1136]: info: CoreCommandRouter::volumioPushState Feb 27 07:34:55 volumio systemd[1]: systemd-hostnamed.service: Deactivated successfully. Feb 27 07:34:55 volumio volumio[1136]: info: Completed loading Core Plugins Feb 27 07:34:55 volumio volumio[1136]: info: Preparing to generate the ALSA configuration file Feb 27 07:34:55 volumio sudo[1325]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 27 07:34:55 volumio sudo[1325]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 27 07:34:55 volumio volumio[1136]: info: Discovery: adding 5fafa3e2-5c9a-4e73-bab3-7631e4d94913 Feb 27 07:34:55 volumio volumio[1136]: info: Discovery: Found device Volumio Feb 27 07:34:55 volumio volumio[1136]: info: CoreCommandRouter::volumioGetState Feb 27 07:34:55 volumio volumio[1136]: info: CorePlayQueue::getTrack 0 Feb 27 07:34:55 volumio volumio[1136]: info: Discovery: this is already registered, 5fafa3e2-5c9a-4e73-bab3-7631e4d94913 Feb 27 07:34:55 volumio volumio[1136]: info: Discovery: Found device Volumio Feb 27 07:34:55 volumio volumio[1136]: info: CoreCommandRouter::volumioGetState Feb 27 07:34:55 volumio volumio[1136]: info: CorePlayQueue::getTrack 0 Feb 27 07:34:55 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 27 07:34:55 volumio sudo[1325]: pam_unix(sudo:session): session closed for user root Feb 27 07:34:56 volumio volumio[1136]: info: Upmpdcli Daemon Started Feb 27 07:34:56 volumio volumio[1136]: info: Asound.conf file unchanged, so no further update is needed Feb 27 07:34:56 volumio volumio[1136]: info: Output device has changed, restarting MPD Feb 27 07:34:56 volumio volumio[1136]: info: Output device has changed, restarting Shairport Sync Feb 27 07:34:56 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:34:56 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 27 07:34:56 volumio sudo[1342]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 27 07:34:56 volumio sudo[1342]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 27 07:34:56 volumio sudo[1342]: pam_unix(sudo:session): session closed for user root Feb 27 07:34:56 volumio volumio[1136]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 27 07:34:56 volumio sudo[1344]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 27 07:34:56 volumio sudo[1344]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 27 07:34:56 volumio volumio[1136]: info: ___________ START PLUGINS ___________ Feb 27 07:34:56 volumio volumio[1136]: info: ControllerMpd::onStart: Initializing MPD Feb 27 07:34:56 volumio volumio[1136]: info: Creating MPD Configuration file Feb 27 07:34:56 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 27 07:34:56 volumio volumio[1136]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 27 07:34:56 volumio volumio[1136]: info: [1772174096762] CoreMusicLibrary::Adding element Media Servers Feb 27 07:34:56 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 27 07:34:56 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 27 07:34:56 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 27 07:34:56 volumio sudo[1355]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 27 07:34:56 volumio sudo[1355]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 27 07:34:56 volumio sudo[1353]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 27 07:34:56 volumio sudo[1353]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 27 07:34:56 volumio sudo[1355]: pam_unix(sudo:session): session closed for user root Feb 27 07:34:57 volumio sudo[1356]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 27 07:34:57 volumio sudo[1356]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 27 07:34:57 volumio sudo[1359]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Feb 27 07:34:57 volumio sudo[1356]: pam_unix(sudo:session): session closed for user root Feb 27 07:34:57 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:34:57 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 27 07:34:57 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 27 07:34:57 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 27 07:34:57 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 27 07:34:57 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 27 07:34:57 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 27 07:34:57 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 27 07:34:57 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 27 07:34:57 volumio volumio[1136]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 27 07:34:57 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:34:57 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 27 07:34:57 volumio sudo[1366]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 27 07:34:57 volumio sudo[1366]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 27 07:34:57 volumio sudo[1371]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Feb 27 07:34:57 volumio sudo[1366]: pam_unix(sudo:session): session closed for user root Feb 27 07:34:57 volumio volumio[1136]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 27 07:34:57 volumio volumio[1136]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 27 07:34:57 volumio volumio[1136]: info: [1772174097543] CoreMusicLibrary::Adding element Last_100 Feb 27 07:34:57 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 27 07:34:57 volumio volumio[1136]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 27 07:34:57 volumio volumio[1136]: info: [1772174097547] CoreMusicLibrary::Adding element Webradio Feb 27 07:34:57 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 27 07:34:57 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 27 07:34:57 volumio volumio[1136]: info: Initializing BBC Radios Feb 27 07:34:58 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 27 07:34:58 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 27 07:34:58 volumio volumio[1136]: info: Creating Spotify config file Feb 27 07:34:58 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:35:02 volumio volumio[1136]: info: Volumio Calling Home Feb 27 07:35:02 volumio volumio[1259]: Starting albumart workers Feb 27 07:35:02 volumio volumio[1260]: Starting albumart workers Feb 27 07:35:03 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Feb 27 07:35:04 volumio volumio[1261]: Starting albumart workers Feb 27 07:35:05 volumio volumio[1136]: error: Upnp client error: Error: connect ECONNREFUSED 127.0.0.1:6600 Feb 27 07:35:05 volumio volumio[1136]: info: MPD Permissions set Feb 27 07:35:05 volumio volumio[1136]: info: MPD Permissions set Feb 27 07:35:05 volumio volumio[1136]: info: Volumio called home Feb 27 07:35:05 volumio volumio[1136]: info: Spotify config file written Feb 27 07:35:05 volumio systemd[1]: Starting e2scrub_all.service - Online ext4 Metadata Check for All Filesystems... Feb 27 07:35:05 volumio systemd[1]: e2scrub_all.service: Deactivated successfully. Feb 27 07:35:05 volumio systemd[1]: Finished e2scrub_all.service - Online ext4 Metadata Check for All Filesystems. Feb 27 07:35:05 volumio volumio[1136]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 27 07:35:05 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:35:05 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:35:05 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:35:05 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:35:05 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:35:05 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:35:05 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:35:05 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:35:05 volumio sudo[1431]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 27 07:35:05 volumio sudo[1431]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 27 07:35:05 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 27 07:35:05 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:35:05 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Feb 27 07:35:05 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Feb 27 07:35:05 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:35:05 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:35:05 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:35:05 volumio systemd[1]: setdatetime-helper.service: Consumed 1.110s CPU time. Feb 27 07:35:05 volumio mpd[1372]: 2026-02-27T07:35:05 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 27 07:35:05 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:35:05 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:35:05 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:35:05 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:35:05 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:35:05 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 27 07:35:05 volumio sudo[1344]: pam_unix(sudo:session): session closed for user root Feb 27 07:35:05 volumio sudo[1353]: pam_unix(sudo:session): session closed for user root Feb 27 07:35:05 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. Feb 27 07:35:05 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. Feb 27 07:35:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 27 07:35:06 volumio go-librespot[1445]: go-librespot daemon starting... Feb 27 07:35:06 volumio sudo[1431]: pam_unix(sudo:session): session closed for user root Feb 27 07:35:06 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 27 07:35:06 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:35:06 volumio volumio[1136]: info: No need to fix Spotify hosts Feb 27 07:35:06 volumio go-librespot[1450]: time="2026-02-27T07:35:06+01:00" level=info msg="running go-librespot 0.4.0" Feb 27 07:35:06 volumio go-librespot[1450]: time="2026-02-27T07:35:06+01:00" level=debug msg="app state loaded" Feb 27 07:35:06 volumio go-librespot[1450]: time="2026-02-27T07:35:06+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 27 07:35:07 volumio go-librespot[1450]: time="2026-02-27T07:35:07+01:00" 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 27 07:35:07 volumio go-librespot[1450]: time="2026-02-27T07:35:07+01:00" 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 27 07:35:07 volumio go-librespot[1450]: time="2026-02-27T07:35:07+01:00" 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 27 07:35:07 volumio go-librespot[1450]: time="2026-02-27T07:35:07+01:00" level=info msg="zeroconf server listening on port 45353" Feb 27 07:35:07 volumio go-librespot[1450]: time="2026-02-27T07:35:07+01:00" level=debug msg="obtained new client token: AABUp9lD0+j8Xk2bA9lbYRqPjZOyLku6s8LR4McsR+ELLA56+TF+dKx3ZnN//9Bcg64EUWmRDlQnkf90Qx7W3hqs5qApQ3BK6yiBqbfP9XCgND4uTo7Ra5VstdSli4z5YnuSln57aw4NiE50lTNG3K0CtcM+StaFykdIuMG21jlbhDAwzfxXWpA3TImiCLzkcHipoaso7JCn0L+2TyW3U9EtwiiZxi8ON16LZTQEoiPefY9G4+5kLMmCkQ==" Feb 27 07:35:07 volumio go-librespot[1450]: time="2026-02-27T07:35:07+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 27 07:35:07 volumio go-librespot[1450]: time="2026-02-27T07:35:07+01:00" 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 27 07:35:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 27 07:35:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 27 07:35:08 volumio volumio[1136]: info: Completed starting Core Plugins Feb 27 07:35:08 volumio volumio[1136]: info: ------------------------------------------- Feb 27 07:35:08 volumio volumio[1136]: info: ----- MyVolumio plugins startup ---- Feb 27 07:35:08 volumio volumio[1136]: info: ------------------------------------------- Feb 27 07:35:08 volumio volumio[1136]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 27 07:35:08 volumio volumio[1136]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 27 07:35:08 volumio volumio[1136]: SPOTIFY: BQBU3gdCUn2N3x3-GA1pYU-0RiA0f47Ntj_VVh9rPMKkB-UdZ99he9beDaSJyFCGlzXM8cTA9Kp6nSgttGavCi8QYnjaxh8r940rQeHUGblSncXjTKRyD34UbNarFUIvE8I_lN61Pn1W5OvK0_Cel53wukxKGJQfMiH4Smbihi0Q6Bynw2r6kB_OqsZqBCL8Vtp9hHk7Wgr805x9njSiqHalG4UjWj9HTFuSW9haUsTAnSQ3EIhSJhcJZnvVkCIF19BxHYpGJGIv-ww_6-g97iLriwvDAUkGnWrRB-8ACvydhmXUNOWHcvyJTGx2hlWiqS7fOin17s4xi8ifvVL9hlapUU5h5E50NnZ6pZbs3CCjGdkd1aghyg Feb 27 07:35:08 volumio volumio[1136]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 27 07:35:08 volumio volumio[1136]: info: New Spotify access token = BQBU3gdCUn2N3x3-GA1pYU-0RiA0f47Ntj_VVh9rPMKkB-UdZ99he9beDaSJyFCGlzXM8cTA9Kp6nSgttGavCi8QYnjaxh8r940rQeHUGblSncXjTKRyD34UbNarFUIvE8I_lN61Pn1W5OvK0_Cel53wukxKGJQfMiH4Smbihi0Q6Bynw2r6kB_OqsZqBCL8Vtp9hHk7Wgr805x9njSiqHalG4UjWj9HTFuSW9haUsTAnSQ3EIhSJhcJZnvVkCIF19BxHYpGJGIv-ww_6-g97iLriwvDAUkGnWrRB-8ACvydhmXUNOWHcvyJTGx2hlWiqS7fOin17s4xi8ifvVL9hlapUU5h5E50NnZ6pZbs3CCjGdkd1aghyg Feb 27 07:35:08 volumio volumio[1136]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 27 07:35:09 volumio volumio[1136]: error: MPD error: The expression evaluated to a falsy value: Feb 27 07:35:09 volumio volumio[1136]: assert.ok(self.idling) Feb 27 07:35:09 volumio volumio[1136]: error: The expression evaluated to a falsy value: Feb 27 07:35:09 volumio volumio[1136]: assert.ok(self.idling) Feb 27 07:35:09 volumio volumio[1136]: info: MPD running with PID1372 Feb 27 07:35:09 volumio volumio[1136]: ,establishing connection Feb 27 07:35:09 volumio volumio[1136]: info: Starting Shairport Sync Feb 27 07:35:09 volumio volumio[1136]: info: Starting Shairport Sync Feb 27 07:35:09 volumio volumio[1136]: info: Starting Shairport Sync Feb 27 07:35:09 volumio volumio[1136]: error: updateQueue error: null Feb 27 07:35:09 volumio sudo[1475]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 27 07:35:09 volumio sudo[1477]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 27 07:35:09 volumio sudo[1477]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 27 07:35:09 volumio sudo[1475]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 27 07:35:09 volumio sudo[1480]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 27 07:35:09 volumio sudo[1480]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 27 07:35:09 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 27 07:35:09 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 27 07:35:09 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 27 07:35:09 volumio systemd[1]: shairport-sync.service: Consumed 2.049s CPU time. Feb 27 07:35:09 volumio volumio[1136]: error: updateQueue error: null Feb 27 07:35:10 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 27 07:35:10 volumio sudo[1477]: pam_unix(sudo:session): session closed for user root Feb 27 07:35:10 volumio sudo[1475]: pam_unix(sudo:session): session closed for user root Feb 27 07:35:10 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 27 07:35:10 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 27 07:35:10 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 27 07:35:10 volumio volumio[1136]: info: CoreCommandRouter::volumioGetState Feb 27 07:35:10 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 27 07:35:10 volumio volumio[1136]: info: CorePlayQueue::getTrack 0 Feb 27 07:35:10 volumio sudo[1480]: pam_unix(sudo:session): session closed for user root Feb 27 07:35:10 volumio volumio[1136]: info: Shairport-Sync Started Feb 27 07:35:10 volumio volumio[1136]: Error adding Membership: Error: addMembership EINVAL Feb 27 07:35:10 volumio volumio[1136]: info: Shairport-Sync Started Feb 27 07:35:10 volumio volumio[1136]: info: Shairport-Sync Started Feb 27 07:35:10 volumio volumio[1136]: SPOTIFY: User informations: {"country":"ES","display_name":"joanfra66","email":"joanfra@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/joanfra66"},"followers":{"href":null,"total":2},"href":"https://api.spotify.com/v1/users/joanfra66","id":"joanfra66","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee852ceb15001a09b1b501131ac9","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b822ceb15001a09b1b501131ac9","width":64}],"product":"premium","type":"user","uri":"spotify:user:joanfra66"} Feb 27 07:35:10 volumio volumio[1136]: info: Spotify Successfully logged in Feb 27 07:35:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 27 07:35:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 27 07:35:10 volumio volumio[1136]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 27 07:35:10 volumio volumio[1136]: info: [1772174110802] CoreMusicLibrary::Adding element Spotify Feb 27 07:35:10 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 27 07:35:10 volumio volumio[1136]: Cannot find translation for source Spotify Feb 27 07:35:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 27 07:35:10 volumio go-librespot[1504]: go-librespot daemon starting... Feb 27 07:35:10 volumio go-librespot[1505]: time="2026-02-27T07:35:10+01:00" level=info msg="running go-librespot 0.4.0" Feb 27 07:35:10 volumio go-librespot[1505]: time="2026-02-27T07:35:10+01:00" level=debug msg="app state loaded" Feb 27 07:35:10 volumio go-librespot[1505]: time="2026-02-27T07:35:10+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 27 07:35:11 volumio volumio[1136]: info: go-librespot daemon successfully initialized Feb 27 07:35:11 volumio sudo[1516]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 27 07:35:11 volumio sudo[1516]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 27 07:35:11 volumio sudo[1512]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 27 07:35:11 volumio sudo[1512]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 27 07:35:11 volumio go-librespot[1505]: time="2026-02-27T07:35:11+01:00" 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 27 07:35:11 volumio go-librespot[1505]: time="2026-02-27T07:35:11+01:00" 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 27 07:35:11 volumio go-librespot[1505]: time="2026-02-27T07:35:11+01:00" 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 27 07:35:11 volumio go-librespot[1505]: time="2026-02-27T07:35:11+01:00" level=info msg="zeroconf server listening on port 37593" Feb 27 07:35:11 volumio go-librespot[1505]: time="2026-02-27T07:35:11+01:00" level=debug msg="obtained new client token: AADo+rgbVlIlHNISU3L+jo+yhCo/DQN4Q1li/9/SEV10merZioxtREVrX5at8lLTsxku33wlEmqFAHJLGt9DsZHqHany4Ud8rPGFnz6rPk9ema0hRkX24dtJQEM5x04UcAXgYr6fNVlopNBUMfkQz/23ngYQMpVGP4PPu0t1cdvN22S+n5Vul5g0FbNN5b7mDTZ4pI+2D0hDe4H6aXDlyQO4y3vGYgElYzyQQxDZLcdg3tYtPZbHWJSbNQ==" Feb 27 07:35:11 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 27 07:35:11 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 27 07:35:11 volumio sudo[1516]: pam_unix(sudo:session): session closed for user root Feb 27 07:35:11 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 27 07:35:11 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 27 07:35:11 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 27 07:35:11 volumio go-librespot[1505]: time="2026-02-27T07:35:11+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 27 07:35:11 volumio mpd_monitor.sh[1520]: MPD Monitor Service: Starting MPD Monitor Service Feb 27 07:35:11 volumio sudo[1512]: pam_unix(sudo:session): session closed for user root Feb 27 07:35:11 volumio volumio[1136]: info: Successfully started MPD Monitor Feb 27 07:35:11 volumio go-librespot[1505]: time="2026-02-27T07:35:11+01:00" 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 27 07:35:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 27 07:35:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 27 07:35:11 volumio volumio[1136]: info: Successfully started MPD Monitor Feb 27 07:35:14 volumio volumio[1136]: info: Initializing connection to go-librespot Websocket Feb 27 07:35:14 volumio volumio[1136]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 27 07:35:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 27 07:35:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 27 07:35:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 27 07:35:15 volumio go-librespot[1538]: go-librespot daemon starting... Feb 27 07:35:15 volumio go-librespot[1539]: time="2026-02-27T07:35:15+01:00" level=info msg="running go-librespot 0.4.0" Feb 27 07:35:15 volumio go-librespot[1539]: time="2026-02-27T07:35:15+01:00" level=debug msg="app state loaded" Feb 27 07:35:15 volumio go-librespot[1539]: time="2026-02-27T07:35:15+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 27 07:35:15 volumio go-librespot[1539]: time="2026-02-27T07:35:15+01:00" 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 27 07:35:15 volumio go-librespot[1539]: time="2026-02-27T07:35:15+01:00" 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 27 07:35:15 volumio go-librespot[1539]: time="2026-02-27T07:35:15+01:00" 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 27 07:35:15 volumio go-librespot[1539]: time="2026-02-27T07:35:15+01:00" level=info msg="zeroconf server listening on port 45763" Feb 27 07:35:15 volumio go-librespot[1539]: time="2026-02-27T07:35:15+01:00" level=debug msg="obtained new client token: AAAfnn9Y3OnuURmDq/Ykd9d5jqUyULUHuAp1QE76/8i5a61u9YlzauyIM+MP24+7tfDoLdAl0meovhItDO3BFTHA8F/yaB/S6AYZZlX1ZEovSePFAUIr3OR7M4gWFkGHjeyxOpzrbRwCxLs0MlQchueZOBypZ5gfkrpeeJNVoQ9BLN0u4MYL6JL4kj+uY8so6L/4Km1HB3iPMhiC/ym4Eigr1WJHJaEgcSDnwtn5eevQRLZxpjtNY+c=" Feb 27 07:35:15 volumio go-librespot[1539]: time="2026-02-27T07:35:15+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 27 07:35:15 volumio go-librespot[1539]: time="2026-02-27T07:35:15+01:00" 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 27 07:35:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 27 07:35:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 27 07:35:16 volumio volumio[1136]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 27 07:35:16 volumio volumio[1136]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 27 07:35:16 volumio volumio[1136]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 27 07:35:16 volumio volumio[1136]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 27 07:35:16 volumio volumio[1136]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 27 07:35:16 volumio volumio[1136]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 27 07:35:16 volumio volumio[1136]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 27 07:35:16 volumio volumio[1136]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 27 07:35:16 volumio volumio[1136]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 27 07:35:16 volumio volumio[1136]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 27 07:35:16 volumio volumio[1136]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 27 07:35:16 volumio volumio[1136]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 27 07:35:16 volumio volumio[1136]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 27 07:35:16 volumio volumio[1136]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 27 07:35:16 volumio volumio[1136]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 27 07:35:16 volumio volumio[1136]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 27 07:35:16 volumio volumio[1136]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 27 07:35:16 volumio volumio[1136]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 27 07:35:16 volumio volumio[1136]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 27 07:35:16 volumio volumio[1136]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 27 07:35:16 volumio volumio[1136]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 27 07:35:16 volumio volumio[1136]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 27 07:35:16 volumio volumio[1136]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 27 07:35:16 volumio volumio[1136]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 27 07:35:16 volumio volumio[1136]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 27 07:35:16 volumio volumio[1136]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 27 07:35:16 volumio volumio[1136]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 27 07:35:16 volumio volumio[1136]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 27 07:35:16 volumio volumio[1136]: info: Adding plugin bluetooth to MyMusic Plugins Feb 27 07:35:16 volumio volumio[1136]: info: Adding plugin multiroom to MyMusic Plugins Feb 27 07:35:17 volumio volumio[1136]: info: Adding plugin metavolumio to MyMusic Plugins Feb 27 07:35:17 volumio volumio[1136]: info: Adding plugin cd_controller to MyMusic Plugins Feb 27 07:35:17 volumio volumio[1136]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 27 07:35:17 volumio volumio[1136]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 27 07:35:17 volumio volumio[1136]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 27 07:35:17 volumio volumio[1136]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 27 07:35:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 27 07:35:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 27 07:35:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 27 07:35:19 volumio go-librespot[1553]: go-librespot daemon starting... Feb 27 07:35:19 volumio go-librespot[1554]: time="2026-02-27T07:35:19+01:00" level=info msg="running go-librespot 0.4.0" Feb 27 07:35:19 volumio go-librespot[1554]: time="2026-02-27T07:35:19+01:00" level=debug msg="app state loaded" Feb 27 07:35:19 volumio go-librespot[1554]: time="2026-02-27T07:35:19+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 27 07:35:19 volumio go-librespot[1554]: time="2026-02-27T07:35:19+01:00" 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 27 07:35:19 volumio go-librespot[1554]: time="2026-02-27T07:35:19+01:00" 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 27 07:35:19 volumio go-librespot[1554]: time="2026-02-27T07:35:19+01:00" 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 27 07:35:19 volumio go-librespot[1554]: time="2026-02-27T07:35:19+01:00" level=info msg="zeroconf server listening on port 36997" Feb 27 07:35:19 volumio go-librespot[1554]: time="2026-02-27T07:35:19+01:00" level=debug msg="obtained new client token: AADA8xjWM3JhjZ0GBmCyEsZX347XutE9c8D36I9ezepryAdgaHMme68NlfIIdHLr80HOiFOEM4nBsTGgTThQeNev5CDuTBtcjHEyQbZZsk0D0BSxWUY1/js6cr1vM6JCwVYokUx+vGdh9NuBXIhHCBHLOs3ma7wQZ7c/wfvs3ChSHKqtgHu78SFPIQ6OTrcQPrgHkQMskwboKniUMnVxVyu1jt+MuE/1rbgDVUiIQ48zQC/ib3CwISk=" Feb 27 07:35:19 volumio go-librespot[1554]: time="2026-02-27T07:35:19+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 27 07:35:20 volumio go-librespot[1554]: time="2026-02-27T07:35:20+01:00" 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 27 07:35:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 27 07:35:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 27 07:35:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 27 07:35:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 27 07:35:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 27 07:35:23 volumio go-librespot[1562]: go-librespot daemon starting... Feb 27 07:35:23 volumio go-librespot[1563]: time="2026-02-27T07:35:23+01:00" level=info msg="running go-librespot 0.4.0" Feb 27 07:35:23 volumio go-librespot[1563]: time="2026-02-27T07:35:23+01:00" level=debug msg="app state loaded" Feb 27 07:35:23 volumio go-librespot[1563]: time="2026-02-27T07:35:23+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 27 07:35:23 volumio go-librespot[1563]: time="2026-02-27T07:35:23+01:00" 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-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Feb 27 07:35:23 volumio go-librespot[1563]: time="2026-02-27T07:35:23+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 27 07:35:23 volumio go-librespot[1563]: time="2026-02-27T07:35:23+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 27 07:35:23 volumio go-librespot[1563]: time="2026-02-27T07:35:23+01:00" level=info msg="zeroconf server listening on port 36821" Feb 27 07:35:24 volumio go-librespot[1563]: time="2026-02-27T07:35:24+01:00" level=debug msg="obtained new client token: AADAg3yTNKzH/uzorX6LjCvFy3owS5xOBoCasXCpyvdj0g01xVc64YuA3YS/7Kz1fB8pwpjs9rHx0YlvX3hq711wtpdqV6/+IVqoqkV9zz3f21dmlxBc6dHQCvT6eRMAm0MPCICnGxyFmlSPvJ9um3U3d58giTiE/u6kHoaH0pjvuNnjVdI/SgXDQL2z6VnNzsQGBTWwfqZzbkt5ks0deqP2CKyN7GEkRtw8L+bsBC3WXB4N5Wc8P76Axg==" Feb 27 07:35:24 volumio go-librespot[1563]: time="2026-02-27T07:35:24+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 27 07:35:24 volumio go-librespot[1563]: time="2026-02-27T07:35:24+01:00" 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 27 07:35:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 27 07:35:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 27 07:35:25 volumio volumio[1136]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 27 07:35:25 volumio volumio[1136]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 27 07:35:25 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 27 07:35:25 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 27 07:35:25 volumio volumio[1136]: info: Starting MyVolumio Remote Streaming Endpoints Feb 27 07:35:26 volumio volumio[1136]: info: MyVolumio login type: Token Feb 27 07:35:26 volumio volumio[1136]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 27 07:35:26 volumio volumio[1136]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 27 07:35:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 27 07:35:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 27 07:35:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 27 07:35:27 volumio go-librespot[1584]: go-librespot daemon starting... Feb 27 07:35:27 volumio go-librespot[1585]: time="2026-02-27T07:35:27+01:00" level=info msg="running go-librespot 0.4.0" Feb 27 07:35:27 volumio go-librespot[1585]: time="2026-02-27T07:35:27+01:00" level=debug msg="app state loaded" Feb 27 07:35:27 volumio go-librespot[1585]: time="2026-02-27T07:35:27+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 27 07:35:27 volumio go-librespot[1585]: time="2026-02-27T07:35:27+01:00" 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 27 07:35:27 volumio go-librespot[1585]: time="2026-02-27T07:35:27+01:00" 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 27 07:35:27 volumio go-librespot[1585]: time="2026-02-27T07:35:27+01:00" 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 27 07:35:27 volumio go-librespot[1585]: time="2026-02-27T07:35:27+01:00" level=info msg="zeroconf server listening on port 39209" Feb 27 07:35:28 volumio go-librespot[1585]: time="2026-02-27T07:35:28+01:00" level=debug msg="obtained new client token: AABmfIcpxno93FVI9yP8HsUiI9dzbHPkvHky8Aer9ezJMWwHBYrfp/Z4/VDQ2bVFxNr6j+IlfsJBLdG6ZZS44NH9lgdxDooMUYMOi4tLXC2uWvNFvYtTe9VtADvvTJ/u793coHQiS4bht3GwXYShvAm3q9qXI0xFwltiCUC9sdwqs4fwVvG2CQKWHSp1jVDQ27P6mfYisgxYbYgptlQ3d256Im3NfAHM4G1dYFVyLnn+RmRzSYNZiP+pJQ==" Feb 27 07:35:28 volumio go-librespot[1585]: time="2026-02-27T07:35:28+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 27 07:35:28 volumio go-librespot[1585]: time="2026-02-27T07:35:28+01:00" 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 27 07:35:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 27 07:35:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 27 07:35:28 volumio upmpdcli[1593]: writing RSA key Feb 27 07:35:31 volumio volumio[1136]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 27 07:35:31 volumio volumio[1136]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 27 07:35:31 volumio volumio[1136]: info: Streaming services startup Feb 27 07:35:31 volumio volumio[1136]: info: Starting Streaming Daemon Feb 27 07:35:31 volumio volumio[1136]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 27 07:35:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 27 07:35:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 27 07:35:31 volumio sudo[1601]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 27 07:35:31 volumio sudo[1601]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 27 07:35:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 27 07:35:31 volumio go-librespot[1605]: go-librespot daemon starting... Feb 27 07:35:31 volumio go-librespot[1607]: time="2026-02-27T07:35:31+01:00" level=info msg="running go-librespot 0.4.0" Feb 27 07:35:31 volumio go-librespot[1607]: time="2026-02-27T07:35:31+01:00" level=debug msg="app state loaded" Feb 27 07:35:31 volumio go-librespot[1607]: time="2026-02-27T07:35:31+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 27 07:35:31 volumio sudo[1601]: pam_unix(sudo:session): session closed for user root Feb 27 07:35:31 volumio volumio[1136]: info: Initializing connection to go-librespot Websocket Feb 27 07:35:31 volumio volumio[1136]: error: Cannot start Volumio Streaming Daemon Feb 27 07:35:31 volumio volumio[1136]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 27 07:35:31 volumio volumio[1136]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 27 07:35:31 volumio go-librespot[1607]: time="2026-02-27T07:35:31+01:00" 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 27 07:35:31 volumio go-librespot[1607]: time="2026-02-27T07:35:31+01:00" 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 27 07:35:31 volumio go-librespot[1607]: time="2026-02-27T07:35:31+01:00" 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 27 07:35:31 volumio go-librespot[1607]: time="2026-02-27T07:35:31+01:00" level=info msg="zeroconf server listening on port 42629" Feb 27 07:35:31 volumio go-librespot[1607]: time="2026-02-27T07:35:31+01:00" level=debug msg="new websocket client" Feb 27 07:35:31 volumio volumio[1136]: info: Connection to go-librespot Websocket established Feb 27 07:35:32 volumio go-librespot[1607]: time="2026-02-27T07:35:32+01:00" level=debug msg="obtained new client token: AABTBf7I9/+6OC4O7zNoiC62QzFGagWLLUyJswymWRqAcBp2VsIk2amBwhc64P2STFX0owEzvuS9m32vx1I4hJw6Y1xxTKXXR6Sr05XxKR7x8X2LNJqNh3e6xBJkry8RKIPC8L/EGHUu1HR//LnYPeWsmQao/BxH016dX8MAs5UAHwYNZaPEzCEHYsTb3J+8iHVZ7ikIo/DnrrEf6xZnx1i9jEveogxCGfBRADBNPsA81PGYB7igX0nPCQ==" Feb 27 07:35:32 volumio go-librespot[1607]: time="2026-02-27T07:35:32+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 27 07:35:32 volumio go-librespot[1607]: time="2026-02-27T07:35:32+01:00" 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 27 07:35:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 27 07:35:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 27 07:35:32 volumio volumio[1136]: info: Connection to go-librespot Websocket closed Feb 27 07:35:32 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 27 07:35:32 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 27 07:35:32 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 27 07:35:32 volumio volumio[1136]: error: MyVolumio Custom Token format not valid, refreshing it Feb 27 07:35:33 volumio volumio-remote-updater[788]: Test mode disabled Feb 27 07:35:33 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Feb 27 07:35:33 volumio volumio-remote-updater[788]: Alpha mode disabled Feb 27 07:35:33 volumio volumio-remote-updater[788]: Alpha legacy test mode disabled Feb 27 07:35:33 volumio volumio[1136]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"

FIXES

\n
    \n
  • Fix for CPU utilization spike
    • \n
  • Fix for triggerhappy input permission
    • \n
\n

NEW ADDITIONS

\n
    \n
  • Add BLE onboarding plugin
    • \n
  • Enable vc4-kms-v3d for all compatible RPi models
    • \n
  • Update Tidal SDK
    • \n
\n","title":"Update v4.096","updateavailable":true} Feb 27 07:35:33 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Feb 27 07:35:34 volumio volumio[1136]: info: MyVolumio login type: Token Feb 27 07:35:35 volumio volumio[1136]: info: Getting Spotify volume Feb 27 07:35:35 volumio volumio[1136]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 27 07:35:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 27 07:35:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 27 07:35:35 volumio volumio[1136]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 27 07:35:35 volumio volumio[1136]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 27 07:35:35 volumio volumio[1136]: errno: -111, Feb 27 07:35:35 volumio volumio[1136]: code: 'ECONNREFUSED', Feb 27 07:35:35 volumio volumio[1136]: syscall: 'connect', Feb 27 07:35:35 volumio volumio[1136]: address: '127.0.0.1', Feb 27 07:35:35 volumio volumio[1136]: port: 9879, Feb 27 07:35:35 volumio volumio[1136]: response: undefined Feb 27 07:35:35 volumio volumio[1136]: } Feb 27 07:35:35 volumio volumio[1136]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 27 07:35:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 27 07:35:35 volumio go-librespot[1635]: go-librespot daemon starting... Feb 27 07:35:35 volumio go-librespot[1639]: time="2026-02-27T07:35:35+01:00" level=info msg="running go-librespot 0.4.0" Feb 27 07:35:35 volumio go-librespot[1639]: time="2026-02-27T07:35:35+01:00" level=debug msg="app state loaded" Feb 27 07:35:35 volumio go-librespot[1639]: time="2026-02-27T07:35:35+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 27 07:35:35 volumio go-librespot[1639]: time="2026-02-27T07:35:35+01:00" 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-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Feb 27 07:35:35 volumio go-librespot[1639]: time="2026-02-27T07:35:35+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 27 07:35:35 volumio go-librespot[1639]: time="2026-02-27T07:35:35+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 27 07:35:35 volumio go-librespot[1639]: time="2026-02-27T07:35:35+01:00" level=info msg="zeroconf server listening on port 41663" Feb 27 07:35:36 volumio go-librespot[1639]: time="2026-02-27T07:35:36+01:00" level=debug msg="obtained new client token: AAD2cn8bcKkWRHemN9jXv6zIg+SXXOnC15k9azRAGE/Um9ue+KJfzRMStVCCvZzs8wCEskF4PYzvVcHVSwsSHlLeBG2qq9dlwBN/xhCtpvjEkKmFsBK63S51GSd7iCECAPMe64KkJpF/pIaZzLNwL+4Bu9E38UaOF+9eE+7T3QB6XHKq3ysaB1UAoFTgNyBaE/rRLyolNedA97FZLa9Oo9xLCVEnGKG9hpSrO+LwocYYbiaO/sPlh8/bXQ==" Feb 27 07:35:36 volumio go-librespot[1639]: time="2026-02-27T07:35:36+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 27 07:35:36 volumio go-librespot[1639]: time="2026-02-27T07:35:36+01:00" level=debug msg="completed keyexchange" Feb 27 07:35:36 volumio go-librespot[1639]: time="2026-02-27T07:35:36+01:00" level=debug msg="completed challenge" Feb 27 07:35:36 volumio go-librespot[1639]: time="2026-02-27T07:35:36+01:00" level=info msg="authenticated AP" username="jo*****66" Feb 27 07:35:36 volumio go-librespot[1639]: time="2026-02-27T07:35:36+01:00" level=info msg="authenticated Login5" username="jo*****66" Feb 27 07:35:36 volumio go-librespot[1639]: time="2026-02-27T07:35:36+01:00" level=debug msg="initializing zeroconf session" username="jo*****66" Feb 27 07:35:36 volumio go-librespot[1639]: time="2026-02-27T07:35:36+01:00" level=debug msg="dealer connection opened" Feb 27 07:35:36 volumio go-librespot[1639]: time="2026-02-27T07:35:36+01:00" level=trace msg="starting accesspoint recv loop" Feb 27 07:35:36 volumio go-librespot[1639]: time="2026-02-27T07:35:36+01:00" level=trace msg="starting dealer recv loop" Feb 27 07:35:36 volumio go-librespot[1639]: time="2026-02-27T07:35:36+01:00" level=trace msg="received accesspoint ping" Feb 27 07:35:36 volumio go-librespot[1639]: time="2026-02-27T07:35:36+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Feb 27 07:35:36 volumio go-librespot[1639]: time="2026-02-27T07:35:36+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Feb 27 07:35:36 volumio go-librespot[1639]: time="2026-02-27T07:35:36+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Feb 27 07:35:36 volumio go-librespot[1639]: time="2026-02-27T07:35:36+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Feb 27 07:35:36 volumio go-librespot[1639]: time="2026-02-27T07:35:36+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Feb 27 07:35:36 volumio go-librespot[1639]: time="2026-02-27T07:35:36+01:00" level=debug msg="received connection id: NTA3OGNjMGYtZmI4...MzJCRTIyRDRDMw==" Feb 27 07:35:36 volumio go-librespot[1639]: time="2026-02-27T07:35:36+01:00" level=trace msg="received accesspoint pong ack" Feb 27 07:35:36 volumio go-librespot[1639]: time="2026-02-27T07:35:36+01:00" level=debug msg="put connect state because NEW_DEVICE" Feb 27 07:35:41 volumio sudo[1657]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-27 07:34' Feb 27 07:35:41 volumio sudo[1657]: 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="ec1ce6b3390e13e82b9cc0453f957c4f5298419e" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="8bcc10c3dbcbcb349e9887dc0527d54876b32688" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon Nov 17 16:31:40 UTC 2025" VOLUMIO_VERSION="4.071" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5fbe1bcf6936184712979c0bfaf061f2"