Feb 12 13:44:00 volumio volumio[17726]: info: Plugin mpdemulation is not enabled Feb 12 13:44:00 volumio volumio[17726]: info: Loading plugin "rest_api"... Feb 12 13:44:00 volumio volumio[17726]: info: Loading plugin "websocket"... Feb 12 13:44:00 volumio volumio[17726]: info: Starting Socket.io Server version 1.7.4 Feb 12 13:44:00 volumio volumio[17726]: info: Loading plugin "RoonBridge"... Feb 12 13:44:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Feb 12 13:44:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:00 volumio go-librespot[17848]: go-librespot daemon starting... Feb 12 13:44:00 volumio volumio[17726]: info: Applying required configuration parameters for plugin RoonBridge Feb 12 13:44:00 volumio go-librespot[17849]: time="2026-02-12T13:44:00+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:44:00 volumio go-librespot[17849]: time="2026-02-12T13:44:00+07:00" level=debug msg="app state loaded" Feb 12 13:44:00 volumio go-librespot[17849]: time="2026-02-12T13:44:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:44:00 volumio volumio[17726]: info: Loading i18n strings for locale en Feb 12 13:44:00 volumio volumio[17726]: Updating browse sources language Feb 12 13:44:00 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:44:00 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 13:44:00 volumio volumio[17726]: info: CoreCommandRouter::initPlayerControls Feb 12 13:44:00 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:00 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:00 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:00 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:00 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:00 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:00 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:00 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:01 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 13:44:01 volumio volumio[17838]: Forking 3 albumart workers Feb 12 13:44:01 volumio volumio[17726]: Express server listening on port 3000 Feb 12 13:44:01 volumio volumio[17726]: [Metrics] WebUI: 15s 969.35ms Feb 12 13:44:01 volumio volumio[17726]: info: CoreStateMachine::resetVolumioState Feb 12 13:44:01 volumio volumio[17726]: info: CoreStateMachine::getcurrentVolume Feb 12 13:44:01 volumio volumio[17726]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 13:44:01 volumio go-librespot[17849]: time="2026-02-12T13:44:01+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 13:44:01 volumio go-librespot[17849]: time="2026-02-12T13:44:01+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 13:44:01 volumio go-librespot[17849]: time="2026-02-12T13:44:01+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 13:44:01 volumio sudo[17888]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 12 13:44:01 volumio sudo[17888]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:01 volumio go-librespot[17849]: time="2026-02-12T13:44:01+07:00" level=info msg="zeroconf server listening on port 34337" Feb 12 13:44:01 volumio sudo[17888]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:01 volumio sudo[17890]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 12 13:44:01 volumio sudo[17890]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:01 volumio sudo[17890]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:01 volumio volumio[17726]: info: Volumio Network Manager: Network status updated: 1 Feb 12 13:44:01 volumio go-librespot[17849]: time="2026-02-12T13:44:01+07:00" level=debug msg="obtained new client token: AAAbWKDZBMPGZ7W6cPe3wZ+oT/4Jy2342kp9iO4KcCxs92NSJ3ixAkFOHdctU5ObQUTcPaWKxauYHvfdRoDZUZVWcNbrYUtL0J0LHmQW4XdipxClpqecHov106bhIDWeUxq96fBl706RCWoCaPTMacwNvYroIJl8Y32cpFmCJxxMbq4NWQLdPztloRAO+w0QT+NZuNts/EpI/CmQ3KXEhTAMamTywZFtx2GfqgJKvL6F0HpiiA3dT0OHWQ==" Feb 12 13:44:01 volumio go-librespot[17849]: time="2026-02-12T13:44:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 13:44:01 volumio volumio[17726]: info: VolumeController:: Volume=100 Mute =false Feb 12 13:44:01 volumio volumio[17726]: info: CoreStateMachine::pushState Feb 12 13:44:01 volumio volumio[17726]: info: CorePlayQueue::getTrack 0 Feb 12 13:44:01 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 13:44:01 volumio volumio[17726]: info: CoreCommandRouter::volumioPushState Feb 12 13:44:01 volumio volumio[17726]: info: CoreStateMachine::updateTrackBlock Feb 12 13:44:01 volumio volumio[17726]: info: CorePlayQueue::getTrackBlock Feb 12 13:44:01 volumio volumio[17726]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 13:44:01 volumio go-librespot[17849]: time="2026-02-12T13:44:01+07: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 12 13:44:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:44:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:44:01 volumio volumio-remote-updater[643]: [2026-02-12 13:44:01] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770878639 101 Feb 12 13:44:01 volumio volumio[17726]: 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 12 13:44:01 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:44:01 volumio volumio[17726]: info: Reloading queue from file Feb 12 13:44:01 volumio volumio[17726]: info: CoreStateMachine::setRepeat null single undefined Feb 12 13:44:01 volumio volumio[17726]: info: CoreStateMachine::pushState Feb 12 13:44:01 volumio volumio[17726]: info: CorePlayQueue::getTrack 0 Feb 12 13:44:01 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 13:44:01 volumio volumio[17726]: info: CoreCommandRouter::volumioPushState Feb 12 13:44:01 volumio volumio[17726]: info: CoreStateMachine::setRandom null Feb 12 13:44:01 volumio volumio[17726]: info: CoreStateMachine::pushState Feb 12 13:44:01 volumio volumio[17726]: info: CorePlayQueue::getTrack 0 Feb 12 13:44:01 volumio volumio[17726]: info: CoreCommandRouter::volumioPushState Feb 12 13:44:02 volumio volumio[17726]: info: Setting Device type: Raspberry PI Feb 12 13:44:02 volumio volumio[17726]: info: Completed loading Core Plugins Feb 12 13:44:02 volumio volumio[17726]: info: Preparing to generate the ALSA configuration file Feb 12 13:44:02 volumio volumio[17726]: info: VolumeController:: Volume=100 Mute =false Feb 12 13:44:02 volumio volumio[17726]: info: CoreStateMachine::pushState Feb 12 13:44:02 volumio volumio[17726]: info: CorePlayQueue::getTrack 0 Feb 12 13:44:02 volumio volumio[17726]: info: CoreCommandRouter::volumioPushState Feb 12 13:44:02 volumio volumio[17726]: info: Asound.conf file unchanged, so no further update is needed Feb 12 13:44:02 volumio volumio[17726]: info: Output device has changed, restarting MPD Feb 12 13:44:02 volumio volumio[17726]: info: Output device has changed, restarting Shairport Sync Feb 12 13:44:02 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:02 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:44:02 volumio sudo[17907]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 12 13:44:02 volumio sudo[17907]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:02 volumio sudo[17911]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 13:44:02 volumio sudo[17911]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:02 volumio sudo[17909]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 13:44:02 volumio sudo[17909]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:02 volumio volumio[17726]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 13:44:02 volumio volumio[17726]: info: ___________ START PLUGINS ___________ Feb 12 13:44:02 volumio sudo[17909]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:02 volumio volumio[17726]: info: ControllerMpd::onStart: Initializing MPD Feb 12 13:44:02 volumio volumio[17726]: info: Creating MPD Configuration file Feb 12 13:44:02 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 12 13:44:02 volumio sudo[17907]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:02 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 13:44:02 volumio volumio[17726]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 13:44:02 volumio volumio[17726]: info: [1770878642562] CoreMusicLibrary::Adding element Media Servers Feb 12 13:44:02 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:44:02 volumio sudo[17920]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 13:44:02 volumio sudo[17920]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:02 volumio sudo[17920]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:02 volumio volumio[17726]: info: UPNP Browser: Client initialized successfully Feb 12 13:44:02 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 12 13:44:02 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 12 13:44:02 volumio systemd[1]: mpd.service: Consumed 7.074s CPU time. Feb 12 13:44:02 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 12 13:44:02 volumio sudo[17922]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 13:44:02 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 12 13:44:02 volumio sudo[17922]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:02 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 12 13:44:02 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:02 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:44:02 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 12 13:44:02 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 12 13:44:02 volumio volumio[17726]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 13:44:02 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:02 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:44:02 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 12 13:44:02 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 12 13:44:02 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 12 13:44:02 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 12 13:44:02 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 12 13:44:02 volumio volumio[17726]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 13:44:02 volumio volumio[17726]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 13:44:02 volumio volumio[17726]: info: [1770878642952] CoreMusicLibrary::Adding element Last_100 Feb 12 13:44:02 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:44:02 volumio volumio[17726]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 13:44:02 volumio volumio[17726]: info: [1770878642968] CoreMusicLibrary::Adding element Webradio Feb 12 13:44:02 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:44:02 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 13:44:02 volumio volumio[17726]: info: Initializing BBC Radios Feb 12 13:44:03 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 12 13:44:03 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 12 13:44:03 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 13:44:03 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:44:03 volumio volumio[17726]: info: Creating Spotify config file Feb 12 13:44:03 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:03 volumio sudo[17938]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 12 13:44:03 volumio sudo[17938]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 12 13:44:03 volumio sudo[17938]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:04 volumio volumio[17726]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 13:44:04 volumio volumio[17726]: info: [1770878644283] CoreMusicLibrary::Adding element YouTube Music Feb 12 13:44:04 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:44:04 volumio volumio[17726]: Cannot find translation for source YouTube Music Feb 12 13:44:04 volumio volumio[17857]: Starting albumart workers Feb 12 13:44:04 volumio volumio[17861]: Starting albumart workers Feb 12 13:44:04 volumio volumio[17726]: info: Volumio Calling Home Feb 12 13:44:04 volumio sudo[17953]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 12 13:44:04 volumio sudo[17953]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:04 volumio volumio[17860]: Starting albumart workers Feb 12 13:44:04 volumio sudo[17953]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Feb 12 13:44:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:04 volumio go-librespot[17958]: go-librespot daemon starting... Feb 12 13:44:04 volumio go-librespot[17959]: time="2026-02-12T13:44:04+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:44:05 volumio volumio[17726]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 12 13:44:05 volumio volumio[17726]: info: Discovery: Found device Volumio Feb 12 13:44:05 volumio volumio[17726]: info: CoreCommandRouter::volumioGetState Feb 12 13:44:05 volumio volumio[17726]: info: CorePlayQueue::getTrack 0 Feb 12 13:44:05 volumio volumio[17726]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 12 13:44:05 volumio volumio[17726]: info: Discovery: Found device Volumio Feb 12 13:44:05 volumio volumio[17726]: info: CoreCommandRouter::volumioGetState Feb 12 13:44:05 volumio volumio[17726]: info: CorePlayQueue::getTrack 0 Feb 12 13:44:05 volumio volumio[17726]: info: MPD Permissions set Feb 12 13:44:05 volumio volumio[17726]: info: MPD Permissions set Feb 12 13:44:05 volumio volumio[17726]: info: Upmpdcli Daemon Started Feb 12 13:44:05 volumio volumio[17726]: info: Spotify config file written Feb 12 13:44:05 volumio sudo[17968]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 12 13:44:05 volumio sudo[17968]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:05 volumio go-librespot[17959]: time="2026-02-12T13:44:05+07:00" level=info msg="zeroconf server listening on port 36563" Feb 12 13:44:05 volumio volumio[17726]: 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 12 13:44:05 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 12 13:44:05 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 12 13:44:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:05 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:05 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:05 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:05 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:05 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:05 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:05 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:05 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:05 volumio go-librespot[17970]: go-librespot daemon starting... Feb 12 13:44:05 volumio sudo[17968]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:05 volumio go-librespot[17972]: time="2026-02-12T13:44:05+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:44:05 volumio go-librespot[17972]: time="2026-02-12T13:44:05+07:00" level=debug msg="app state loaded" Feb 12 13:44:05 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:44:05 volumio go-librespot[17972]: time="2026-02-12T13:44:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:44:05 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:05 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:05 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:05 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:06 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:06 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:06 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:06 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:06 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:06 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:44:06 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:06 volumio volumio[17726]: info: No need to fix Spotify hosts Feb 12 13:44:06 volumio go-librespot[17972]: time="2026-02-12T13:44:06+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 13:44:06 volumio go-librespot[17972]: time="2026-02-12T13:44:06+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 13:44:06 volumio go-librespot[17972]: time="2026-02-12T13:44:06+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 13:44:06 volumio go-librespot[17972]: time="2026-02-12T13:44:06+07:00" level=info msg="zeroconf server listening on port 35087" Feb 12 13:44:06 volumio volumio[17726]: info: Volumio called home Feb 12 13:44:07 volumio go-librespot[17972]: time="2026-02-12T13:44:07+07:00" level=debug msg="obtained new client token: AAAUAO6dMKcisXh33qjAX2TxW/MVNy+MZVwQxkw/2SYw8/KOiroWbEqEdWyokFzXBowLWL2q1GzNEMDBgCccWiedgfhA4nKkm65vb2HM2vWDiZDhiMiKpfSuKPwcaz2MAsIGHWArJzgav07kcqX/uyx05ZZRmLE6y+0opZeuIvyajfzZn338nKawiKgJR/trSQQktR+WBQbwSRKRFTmkMbBWXDEFOkim5+fCl367NVVXDrSX5q8JNfNMEQ==" Feb 12 13:44:07 volumio go-librespot[17972]: time="2026-02-12T13:44:07+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 12 13:44:07 volumio go-librespot[17972]: time="2026-02-12T13:44:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 12 13:44:07 volumio volumio[17726]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 13:44:07 volumio volumio[17726]: SPOTIFY: BQB35vGKcHnlr81pQDvvYLfzeqMLFtg1B1qbOk6H-l1NLqsBxCTQsjv3gFT3kZIVk_x17yAXdg6vLg7GS2R4mwXYrpm7M7dKGmM7TVPhofE8fL4amVqsUJi9Uo78w3Z7Y9LL36pT2Kb1sMpoNlGPRnzpi6AKlFCM_s-b91PK8f4cS22akRItimMBIJZja226qn5H8Say8Fbtfl84OjQZtpR8Qh8XVklU4oQhqnmlhEvzcmV-gLfglMZckwDzEuiVpjgIaG9QLKut2zf5m-iAIslyGSW2lpa82Y2oWAsbBj7ZgSOkSiP88Mix Feb 12 13:44:07 volumio volumio[17726]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 13:44:07 volumio volumio[17726]: info: New Spotify access token = BQB35vGKcHnlr81pQDvvYLfzeqMLFtg1B1qbOk6H-l1NLqsBxCTQsjv3gFT3kZIVk_x17yAXdg6vLg7GS2R4mwXYrpm7M7dKGmM7TVPhofE8fL4amVqsUJi9Uo78w3Z7Y9LL36pT2Kb1sMpoNlGPRnzpi6AKlFCM_s-b91PK8f4cS22akRItimMBIJZja226qn5H8Say8Fbtfl84OjQZtpR8Qh8XVklU4oQhqnmlhEvzcmV-gLfglMZckwDzEuiVpjgIaG9QLKut2zf5m-iAIslyGSW2lpa82Y2oWAsbBj7ZgSOkSiP88Mix Feb 12 13:44:07 volumio volumio[17726]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 12 13:44:07 volumio volumio[17726]: info: Starting Shairport Sync Feb 12 13:44:07 volumio go-librespot[17972]: time="2026-02-12T13:44:07+07:00" level=debug msg="completed keyexchange" Feb 12 13:44:07 volumio volumio[17726]: info: Starting Shairport Sync Feb 12 13:44:07 volumio go-librespot[17972]: time="2026-02-12T13:44:07+07:00" level=debug msg="completed challenge" Feb 12 13:44:07 volumio volumio[17726]: info: Starting Shairport Sync Feb 12 13:44:07 volumio sudo[18009]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 13:44:07 volumio sudo[18009]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:07 volumio go-librespot[17972]: time="2026-02-12T13:44:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 13:44:07 volumio sudo[18010]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 13:44:07 volumio sudo[18010]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:44:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:44:07 volumio sudo[18012]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 13:44:07 volumio sudo[18012]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:07 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 12 13:44:07 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 12 13:44:07 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 13:44:07 volumio systemd[1]: shairport-sync.service: Consumed 2.308s CPU time. Feb 12 13:44:07 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 13:44:07 volumio sudo[18009]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:07 volumio sudo[18010]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:07 volumio sudo[18012]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:07 volumio volumio[17726]: info: Shairport-Sync Started Feb 12 13:44:07 volumio volumio[17726]: Error adding Membership: Error: addMembership EINVAL Feb 12 13:44:07 volumio volumio[17726]: info: Shairport-Sync Started Feb 12 13:44:07 volumio volumio[17726]: info: Shairport-Sync Started Feb 12 13:44:07 volumio volumio[17726]: info: CoreCommandRouter::volumioGetState Feb 12 13:44:07 volumio volumio[17726]: info: CorePlayQueue::getTrack 0 Feb 12 13:44:08 volumio volumio[17726]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 12 13:44:08 volumio volumio[17726]: info: Spotify Successfully logged in Feb 12 13:44:08 volumio volumio[17726]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 13:44:08 volumio volumio[17726]: info: [1770878648071] CoreMusicLibrary::Adding element Spotify Feb 12 13:44:08 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:44:08 volumio volumio[17726]: Cannot find translation for source YouTube Music Feb 12 13:44:08 volumio volumio[17726]: Cannot find translation for source Spotify Feb 12 13:44:08 volumio volumio[17726]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 12 13:44:08 volumio volumio[17726]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 13:44:08 volumio volumio[17726]: info: VolumeController:: Volume=100 Mute =false Feb 12 13:44:08 volumio volumio[17726]: info: CoreCommandRouter::volumioGetState Feb 12 13:44:08 volumio volumio[17726]: info: CorePlayQueue::getTrack 0 Feb 12 13:44:08 volumio volumio[17726]: info: CoreStateMachine::pushState Feb 12 13:44:08 volumio volumio[17726]: info: CorePlayQueue::getTrack 0 Feb 12 13:44:08 volumio volumio[17726]: info: CoreCommandRouter::volumioPushState Feb 12 13:44:10 volumio volumio[17726]: info: go-librespot daemon successfully initialized Feb 12 13:44:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 12 13:44:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:10 volumio mpd[17951]: 2026-02-12T13:44:10 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 12 13:44:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:10 volumio go-librespot[18048]: go-librespot daemon starting... Feb 12 13:44:10 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 12 13:44:10 volumio sudo[17911]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:10 volumio sudo[17922]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:10 volumio go-librespot[18051]: time="2026-02-12T13:44:10+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:44:10 volumio go-librespot[18051]: time="2026-02-12T13:44:10+07:00" level=debug msg="app state loaded" Feb 12 13:44:10 volumio go-librespot[18051]: time="2026-02-12T13:44:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:44:10 volumio volumio[17726]: error: MPD error: The expression evaluated to a falsy value: Feb 12 13:44:10 volumio volumio[17726]: assert.ok(self.idling) Feb 12 13:44:10 volumio volumio[17726]: error: The expression evaluated to a falsy value: Feb 12 13:44:10 volumio volumio[17726]: assert.ok(self.idling) Feb 12 13:44:10 volumio volumio[17726]: info: MPD running with PID17951 Feb 12 13:44:10 volumio volumio[17726]: ,establishing connection Feb 12 13:44:10 volumio volumio[17726]: error: updateQueue error: null Feb 12 13:44:11 volumio volumio[17726]: info: Completed starting Core Plugins Feb 12 13:44:11 volumio volumio[17726]: info: ------------------------------------------- Feb 12 13:44:11 volumio volumio[17726]: info: ----- MyVolumio plugins startup ---- Feb 12 13:44:11 volumio volumio[17726]: info: ------------------------------------------- Feb 12 13:44:11 volumio volumio[17726]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 12 13:44:11 volumio volumio[17726]: error: updateQueue error: null Feb 12 13:44:11 volumio go-librespot[18051]: time="2026-02-12T13:44:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 13:44:11 volumio go-librespot[18051]: time="2026-02-12T13:44:11+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 13:44:11 volumio go-librespot[18051]: time="2026-02-12T13:44:11+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 13:44:11 volumio go-librespot[18051]: time="2026-02-12T13:44:11+07:00" level=info msg="zeroconf server listening on port 38329" Feb 12 13:44:11 volumio go-librespot[18051]: time="2026-02-12T13:44:11+07:00" level=debug msg="obtained new client token: AADShgPTliY8wWMz4+Sk8tes2X/QcVa6rezPVWhINAJy7Skz5MGLwIHDxlRaCzR3Tnjt08gYwFQq70phiNQb7tYRHRt/TyOMaVPYxIxmdTCxMeloqFCMP/yXJDBU7SADigDaTkz7JlQ+R3rvR4v7vDjtEWW/Mv1IxcLfcQkpMOPiKcdhHeWdDeILVeoh1QWjzFujhiakV0Fvw1MHeS+/BIo+TWJ81f1K1AcMTfKqbtN7Gg+ixn67OMQNnQ==" Feb 12 13:44:11 volumio go-librespot[18051]: time="2026-02-12T13:44:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 13:44:11 volumio go-librespot[18051]: time="2026-02-12T13:44:11+07: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 12 13:44:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:44:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:44:13 volumio volumio[17726]: info: Initializing connection to go-librespot Websocket Feb 12 13:44:13 volumio volumio[17726]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 13:44:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 12 13:44:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:15 volumio go-librespot[18060]: go-librespot daemon starting... Feb 12 13:44:15 volumio go-librespot[18061]: time="2026-02-12T13:44:15+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:44:15 volumio go-librespot[18061]: time="2026-02-12T13:44:15+07:00" level=debug msg="app state loaded" Feb 12 13:44:15 volumio go-librespot[18061]: time="2026-02-12T13:44:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:44:15 volumio go-librespot[18061]: time="2026-02-12T13:44:15+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 13:44:15 volumio go-librespot[18061]: time="2026-02-12T13:44:15+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 13:44:15 volumio go-librespot[18061]: time="2026-02-12T13:44:15+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 13:44:15 volumio go-librespot[18061]: time="2026-02-12T13:44:15+07:00" level=info msg="zeroconf server listening on port 39503" Feb 12 13:44:15 volumio volumio[17726]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 12 13:44:15 volumio go-librespot[18061]: time="2026-02-12T13:44:15+07:00" level=debug msg="obtained new client token: AACkLYpuUgwiJDXFLluquK70vAI8B9ozFq+V1o8sqPCrrmdgI+rrj4BiVdNhsWDqPptwlrUNqZdEpZnS925XMDQxqojY2su86swO6OKixK7dPoQDHFrdNhb5ZKduwSyIdw9jUbC3pjvaWqdhgmUcnI0U/H+2+Knw/Rp76bUeZ7BNocWrK0NPSvr21cePh5W7atD95502ydOPicLSV/MU76mhAcJx7eqIojeVeDJE7lwdxGY5rrNbFFBMtA==" Feb 12 13:44:15 volumio go-librespot[18061]: time="2026-02-12T13:44:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 13:44:16 volumio go-librespot[18061]: time="2026-02-12T13:44:16+07: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 12 13:44:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:44:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:44:16 volumio volumio[17726]: info: Initializing connection to go-librespot Websocket Feb 12 13:44:16 volumio volumio[17726]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 13:44:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 12 13:44:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:19 volumio go-librespot[18069]: go-librespot daemon starting... Feb 12 13:44:19 volumio go-librespot[18070]: time="2026-02-12T13:44:19+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:44:19 volumio go-librespot[18070]: time="2026-02-12T13:44:19+07:00" level=debug msg="app state loaded" Feb 12 13:44:19 volumio go-librespot[18070]: time="2026-02-12T13:44:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:44:19 volumio volumio[17726]: info: Initializing connection to go-librespot Websocket Feb 12 13:44:19 volumio go-librespot[18070]: time="2026-02-12T13:44:19+07:00" level=debug msg="new websocket client" Feb 12 13:44:19 volumio volumio[17726]: info: Connection to go-librespot Websocket established Feb 12 13:44:19 volumio go-librespot[18070]: time="2026-02-12T13:44:19+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 12 13:44:19 volumio go-librespot[18070]: time="2026-02-12T13:44:19+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 12 13:44:19 volumio go-librespot[18070]: time="2026-02-12T13:44:19+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 12 13:44:19 volumio go-librespot[18070]: time="2026-02-12T13:44:19+07:00" level=info msg="zeroconf server listening on port 45979" Feb 12 13:44:19 volumio volumio[17726]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 12 13:44:19 volumio volumio[17726]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 12 13:44:19 volumio volumio[17726]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 12 13:44:19 volumio volumio[17726]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 12 13:44:19 volumio volumio[17726]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 12 13:44:19 volumio volumio[17726]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 12 13:44:19 volumio volumio[17726]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 12 13:44:19 volumio volumio[17726]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 12 13:44:19 volumio volumio[17726]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 12 13:44:19 volumio volumio[17726]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 12 13:44:19 volumio volumio[17726]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 12 13:44:19 volumio volumio[17726]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 12 13:44:19 volumio volumio[17726]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 12 13:44:19 volumio volumio[17726]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 12 13:44:19 volumio volumio[17726]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 12 13:44:19 volumio volumio[17726]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 12 13:44:19 volumio volumio[17726]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 12 13:44:19 volumio volumio[17726]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 12 13:44:19 volumio volumio[17726]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 12 13:44:19 volumio volumio[17726]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 12 13:44:19 volumio volumio[17726]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 12 13:44:19 volumio volumio[17726]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 12 13:44:19 volumio volumio[17726]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 12 13:44:19 volumio volumio[17726]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 12 13:44:19 volumio volumio[17726]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 12 13:44:19 volumio volumio[17726]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 12 13:44:19 volumio volumio[17726]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 12 13:44:19 volumio volumio[17726]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 12 13:44:19 volumio volumio[17726]: info: Adding plugin bluetooth to MyMusic Plugins Feb 12 13:44:19 volumio volumio[17726]: info: Adding plugin multiroom to MyMusic Plugins Feb 12 13:44:19 volumio volumio[17726]: info: Adding plugin metavolumio to MyMusic Plugins Feb 12 13:44:19 volumio volumio[17726]: info: Adding plugin cd_controller to MyMusic Plugins Feb 12 13:44:19 volumio volumio[17726]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 12 13:44:19 volumio volumio[17726]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 12 13:44:19 volumio volumio[17726]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 12 13:44:19 volumio volumio[17726]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 12 13:44:19 volumio go-librespot[18070]: time="2026-02-12T13:44:19+07:00" level=debug msg="obtained new client token: AAA1vDN3+OcYzQ3bgls38pShDHmiZmopcNRyjfrlQD4cu4HkRi77Hw12Uqxe6zMnHTDImyTgCAhh8OjpLIZ0twNhVgYzqQB5UCH3JHlUHrRDJZ8ciYy5NTaw0qktTJjv8Rlqa26NYvkUgrafAdC+Jw+1WXm/RP97JnSnLqgv41XEVyzc6b1mhMcrbheOQKrbjDUQ2P505tU6nhAV4aeobzH0XXSy2GGWYg8KO5n5uToEyddzBgUGCXaekQ==" Feb 12 13:44:20 volumio go-librespot[18070]: time="2026-02-12T13:44:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 13:44:20 volumio go-librespot[18070]: time="2026-02-12T13:44:20+07: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 12 13:44:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:44:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:44:21 volumio volumio[17726]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 12 13:44:21 volumio volumio[17726]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 12 13:44:21 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:44:21 volumio volumio[17726]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:44:21 volumio volumio[17726]: info: Starting MyVolumio Remote Streaming Endpoints Feb 12 13:44:21 volumio volumio[17726]: info: MyVolumio login type: Token Feb 12 13:44:21 volumio volumio[17726]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 12 13:44:21 volumio volumio[17726]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 12 13:44:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 12 13:44:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:23 volumio go-librespot[18091]: go-librespot daemon starting... Feb 12 13:44:23 volumio go-librespot[18092]: time="2026-02-12T13:44:23+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:44:23 volumio go-librespot[18092]: time="2026-02-12T13:44:23+07:00" level=debug msg="app state loaded" Feb 12 13:44:23 volumio go-librespot[18092]: time="2026-02-12T13:44:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:44:23 volumio volumio[17726]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 12 13:44:23 volumio volumio[17726]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 12 13:44:23 volumio volumio[17726]: info: Streaming services startup Feb 12 13:44:23 volumio volumio[17726]: info: Starting Streaming Daemon Feb 12 13:44:23 volumio sudo[18100]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 12 13:44:23 volumio volumio[17726]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 12 13:44:23 volumio sudo[18100]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:23 volumio sudo[18100]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:23 volumio volumio[17726]: info: Getting Spotify volume Feb 12 13:44:23 volumio volumio[17726]: info: Connection to go-librespot Websocket closed Feb 12 13:44:23 volumio volumio[17726]: error: Cannot start Volumio Streaming Daemon Feb 12 13:44:23 volumio volumio[17726]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 12 13:44:23 volumio volumio[17726]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 12 13:44:23 volumio volumio[17726]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 12 13:44:24 volumio go-librespot[18092]: time="2026-02-12T13:44:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 13:44:24 volumio go-librespot[18092]: time="2026-02-12T13:44:24+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 13:44:24 volumio go-librespot[18092]: time="2026-02-12T13:44:24+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 13:44:24 volumio volumio[17726]: info: CoreCommandRouter::volumioGetState Feb 12 13:44:24 volumio volumio[17726]: info: CorePlayQueue::getTrack 0 Feb 12 13:44:24 volumio go-librespot[18092]: time="2026-02-12T13:44:24+07:00" level=info msg="zeroconf server listening on port 46503" Feb 12 13:44:24 volumio volumio[17726]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 12 13:44:24 volumio volumio[17726]: SPOTIFY: SPOTIFY VOLUME undefined Feb 12 13:44:24 volumio volumio[17726]: SPOTIFY: VOLUMIO VOLUME 100 Feb 12 13:44:24 volumio volumio[17726]: info: Aligning Spotify Volume to Volumio Volume Feb 12 13:44:24 volumio volumio[17726]: info: CoreCommandRouter::volumioGetState Feb 12 13:44:24 volumio volumio[17726]: info: CorePlayQueue::getTrack 0 Feb 12 13:44:24 volumio volumio[17726]: info: Setting Spotify Volume from Volumio: 100 Feb 12 13:44:24 volumio go-librespot[18092]: time="2026-02-12T13:44:24+07:00" level=debug msg="obtained new client token: AADF5RSVVO43dbT+iBenJ55MJZH//SBTi2zjyH479BUwzIKj2+gEK99anT5LgEsI1nvk6im20KPTwNIwZ/RvigszePnT7oNs2A4NyAAXdeTK/GwZD9x29SPmhz9ycW2tJlIzueD0bPbo1lXdBX9w1iPZBDTN/4yz/zjjNu2iw47WeIVcHcM/Uakbg46sCgqLOdO6SapY6fg/ul3N5CZMEDwT1AhpcMCUd8ZQMuhPYjX7HTRD76M+ssA=" Feb 12 13:44:24 volumio go-librespot[18092]: time="2026-02-12T13:44:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 13:44:24 volumio go-librespot[18092]: time="2026-02-12T13:44:24+07: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 12 13:44:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:44:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:44:24 volumio volumio[17726]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 13:44:24 volumio volumio[17726]: Error: socket hang up Feb 12 13:44:24 volumio volumio[17726]: at connResetException (node:internal/errors:720:14) Feb 12 13:44:24 volumio volumio[17726]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 12 13:44:24 volumio volumio[17726]: at Socket.emit (node:events:526:35) Feb 12 13:44:24 volumio volumio[17726]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 12 13:44:24 volumio volumio[17726]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 12 13:44:24 volumio volumio[17726]: code: 'ECONNRESET', Feb 12 13:44:24 volumio volumio[17726]: response: undefined Feb 12 13:44:24 volumio volumio[17726]: } Feb 12 13:44:24 volumio volumio[17726]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 13:44:25 volumio sudo[18122]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-12 13:43' Feb 12 13:44:25 volumio sudo[18122]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:26 volumio sudo[18122]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:26 volumio volumio-remote-updater[643]: [2026-02-12 13:44:26] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 12 13:44:26 volumio volumio-remote-updater[643]: [2026-02-12 13:44:26] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 12 13:44:26 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:44:26 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 12 13:44:26 volumio systemd[1]: volumio.service: Consumed 55.637s CPU time. Feb 12 13:44:26 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 12 13:44:26 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 12 13:44:26 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 13253. Feb 12 13:44:26 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 12 13:44:26 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 12 13:44:26 volumio systemd[1]: volumio.service: Consumed 55.637s CPU time. Feb 12 13:44:26 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 12 13:44:26 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 12 13:44:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 12 13:44:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:27 volumio go-librespot[18149]: go-librespot daemon starting... Feb 12 13:44:27 volumio go-librespot[18150]: time="2026-02-12T13:44:27+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:44:27 volumio go-librespot[18150]: time="2026-02-12T13:44:27+07:00" level=debug msg="app state loaded" Feb 12 13:44:27 volumio go-librespot[18150]: time="2026-02-12T13:44:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:44:28 volumio go-librespot[18150]: time="2026-02-12T13:44:28+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 13:44:28 volumio go-librespot[18150]: time="2026-02-12T13:44:28+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 13:44:28 volumio go-librespot[18150]: time="2026-02-12T13:44:28+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 13:44:28 volumio go-librespot[18150]: time="2026-02-12T13:44:28+07:00" level=info msg="zeroconf server listening on port 43663" Feb 12 13:44:28 volumio go-librespot[18150]: time="2026-02-12T13:44:28+07:00" level=debug msg="obtained new client token: AAAw2daDvYFLmBPr5WKNj2M2FconXCSIIOftOGhGJ5D2UwFMOxjFOyIBFSCJEbyEpNTwAXN9E9+SacHrTKOF0dFTsKVPmqcWdSdYzFcZs1lbYu7YxsieNvBMWNTZs1AAl/2w7eJSJY67NNo8IdCf4AC8sdN/PCWALEx0SvNbwqBghbBurDMwdvk1YhYM7WQaQWmft2T0GL+hEtvnocMfkPtwrIfOc2s0MbtyVywVfpqROBwgNRP+uvPGlA==" Feb 12 13:44:28 volumio go-librespot[18150]: time="2026-02-12T13:44:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 13:44:28 volumio go-librespot[18150]: time="2026-02-12T13:44:28+07: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: read tcp 192.168.1.23:34454->104.199.241.202:4070: read: connection reset by peer" Feb 12 13:44:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:44:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:44:30 volumio volumio[18134]: info: ------------------------------------------- Feb 12 13:44:30 volumio volumio[18134]: info: ----- Volumio3 ---- Feb 12 13:44:30 volumio volumio[18134]: info: ------------------------------------------- Feb 12 13:44:30 volumio volumio[18134]: info: ----- System startup ---- Feb 12 13:44:30 volumio volumio[18134]: info: ------------------------------------------- Feb 12 13:44:31 volumio volumio-remote-updater[643]: [2026-02-12 13:44:31] [connect] Successful connection Feb 12 13:44:31 volumio volumio[18134]: info: MYVOLUMIO Environment detected Feb 12 13:44:31 volumio volumio[18134]: info: Plugin folders cleanup Feb 12 13:44:31 volumio volumio[18134]: info: Scanning into folder /volumio/app/plugins/ Feb 12 13:44:31 volumio volumio[18134]: info: Scanning category audio_interface Feb 12 13:44:31 volumio volumio[18134]: info: Scanning category miscellanea Feb 12 13:44:31 volumio volumio[18134]: info: Scanning category music_service Feb 12 13:44:31 volumio volumio[18134]: info: Scanning category plugins.json Feb 12 13:44:31 volumio volumio[18134]: info: Scanning category system_controller Feb 12 13:44:31 volumio volumio[18134]: info: Scanning category user_interface Feb 12 13:44:31 volumio volumio[18134]: info: Scanning into folder /data/plugins/ Feb 12 13:44:31 volumio volumio[18134]: info: Scanning category music_service Feb 12 13:44:31 volumio volumio[18134]: info: Plugin folders cleanup completed Feb 12 13:44:31 volumio volumio[18134]: info: ------------------------------------------- Feb 12 13:44:31 volumio volumio[18134]: info: ----- Core plugins startup ---- Feb 12 13:44:31 volumio volumio[18134]: info: ------------------------------------------- Feb 12 13:44:31 volumio volumio[18134]: info: Loading plugins from folder /volumio/app/plugins/ Feb 12 13:44:31 volumio volumio[18134]: info: Adding plugin upnp to MyMusic Plugins Feb 12 13:44:31 volumio volumio[18134]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 12 13:44:31 volumio volumio[18134]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 12 13:44:31 volumio volumio[18134]: info: Loading plugins from folder /data/plugins/ Feb 12 13:44:31 volumio volumio[18134]: info: Loading plugin "system"... Feb 12 13:44:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 12 13:44:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:31 volumio volumio[18134]: info: Loading plugin "appearance"... Feb 12 13:44:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:31 volumio go-librespot[18167]: go-librespot daemon starting... Feb 12 13:44:31 volumio go-librespot[18170]: time="2026-02-12T13:44:31+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:44:31 volumio go-librespot[18170]: time="2026-02-12T13:44:31+07:00" level=debug msg="app state loaded" Feb 12 13:44:31 volumio go-librespot[18170]: time="2026-02-12T13:44:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:44:32 volumio go-librespot[18170]: time="2026-02-12T13:44:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 13:44:32 volumio go-librespot[18170]: time="2026-02-12T13:44:32+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 13:44:32 volumio go-librespot[18170]: time="2026-02-12T13:44:32+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 13:44:32 volumio go-librespot[18170]: time="2026-02-12T13:44:32+07:00" level=info msg="zeroconf server listening on port 40719" Feb 12 13:44:32 volumio go-librespot[18170]: time="2026-02-12T13:44:32+07:00" level=debug msg="obtained new client token: AAAmVBZbKBppfAjlPXpf4Duq/+qTuYPM5XU8Ajn3znZY6Fu9Qm5NK3ByK2XFQy01iTZkpj9EoDGPKIlF6WO9ONBWn9I1YH07iWf2Y1ZFYwoVnQcr0bhrDJJCOO7ORWaYuoCi0yO8IA47vs70YX0PEMnGfkmB7TZWyVNKBaHkXTO/HILSvZScJh7FnWqeFTVBjseL+rpdWVUs/+FNePbM0cXMkY+trWGYBFI4toATkZ/k73zsMTFCKq1M8Q==" Feb 12 13:44:32 volumio go-librespot[18170]: time="2026-02-12T13:44:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 13:44:32 volumio go-librespot[18170]: time="2026-02-12T13:44:32+07:00" level=debug msg="completed keyexchange" Feb 12 13:44:32 volumio go-librespot[18170]: time="2026-02-12T13:44:32+07:00" level=debug msg="completed challenge" Feb 12 13:44:32 volumio go-librespot[18170]: time="2026-02-12T13:44:32+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 13:44:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:44:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:44:33 volumio volumio[18134]: info: Loading plugin "network"... Feb 12 13:44:33 volumio volumio[18134]: info: Refreshing Cached IP Addresses Feb 12 13:44:33 volumio sudo[18183]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 12 13:44:33 volumio sudo[18183]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:33 volumio volumio[18134]: info: Loading plugin "services"... Feb 12 13:44:33 volumio sudo[18183]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:33 volumio sudo[18185]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 12 13:44:33 volumio sudo[18185]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:33 volumio volumio[18134]: info: Loading plugin "alsa_controller"... Feb 12 13:44:33 volumio sudo[18185]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:33 volumio sudo[18195]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 12 13:44:33 volumio sudo[18195]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:34 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 13:44:34 volumio volumio[18134]: info: Loading plugin "wizard"... Feb 12 13:44:34 volumio volumio[18134]: info: Loading plugin "networkfs"... Feb 12 13:44:34 volumio volumio[18134]: info: Starting Udev Watcher for removable devices Feb 12 13:44:34 volumio volumio[18134]: info: Ignoring mount for partition: boot Feb 12 13:44:34 volumio volumio[18134]: info: Ignoring mount for partition: volumio Feb 12 13:44:34 volumio volumio[18134]: info: Ignoring mount for partition: volumio_data Feb 12 13:44:34 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 13:44:34 volumio volumio[18134]: info: Loading plugin "volumio_command_line_client"... Feb 12 13:44:34 volumio volumio[18134]: info: Loading plugin "upnp"... Feb 12 13:44:34 volumio volumio[18134]: info: [1770878674173] Starting Upmpd Daemon Feb 12 13:44:34 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 13:44:34 volumio volumio[18134]: info: Loading plugin "my_music"... Feb 12 13:44:34 volumio volumio[18134]: info: Loading plugin "mpd"... Feb 12 13:44:34 volumio volumio[18134]: info: Loading plugin "upnp_browser"... Feb 12 13:44:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 12 13:44:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:36 volumio go-librespot[18216]: go-librespot daemon starting... Feb 12 13:44:36 volumio go-librespot[18217]: time="2026-02-12T13:44:36+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:44:36 volumio go-librespot[18217]: time="2026-02-12T13:44:36+07:00" level=debug msg="app state loaded" Feb 12 13:44:36 volumio go-librespot[18217]: time="2026-02-12T13:44:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:44:36 volumio sudo[18195]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:36 volumio go-librespot[18217]: time="2026-02-12T13:44:36+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 13:44:36 volumio go-librespot[18217]: time="2026-02-12T13:44:36+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 13:44:36 volumio go-librespot[18217]: time="2026-02-12T13:44:36+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 13:44:36 volumio go-librespot[18217]: time="2026-02-12T13:44:36+07:00" level=info msg="zeroconf server listening on port 41889" Feb 12 13:44:36 volumio go-librespot[18217]: time="2026-02-12T13:44:36+07:00" level=debug msg="obtained new client token: AADGISD+XL6ts6sWrgbMtlki/ITvd1CGPOGWZbu0Oibiqqky85roAM03ISZTU+UnbUXcQGAN3xKAZHlih5ZDJ1hmNVgCFSOBI2bD+a93FxxNKNPRcA4oWfG16u+l0yYUdCbS9f1ZjRFmWOqroWlTQ88ujf5bUbNwuEJDYNfi0vZm74VySR7vvKAKr5/UfpEfHOvlsvAhXeZlBQ4tK/BV9MkGiWq9ajR99S4frBVxitViMy8Q4aL+939hdg==" Feb 12 13:44:37 volumio go-librespot[18217]: time="2026-02-12T13:44:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 13:44:37 volumio go-librespot[18217]: time="2026-02-12T13:44:37+07: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 12 13:44:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:44:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:44:37 volumio volumio[18134]: info: Starting UPNP Browser Feb 12 13:44:37 volumio volumio[18134]: info: Loading plugin "alarm-clock"... Feb 12 13:44:38 volumio volumio[18134]: info: Loading plugin "airplay_emulation"... Feb 12 13:44:38 volumio volumio[18134]: info: Starting Shairport Sync Feb 12 13:44:38 volumio volumio[18134]: info: Loading plugin "last_100"... Feb 12 13:44:38 volumio volumio[18134]: info: Loading plugin "webradio"... Feb 12 13:44:38 volumio volumio[18134]: info: Loading plugin "i2s_dacs"... Feb 12 13:44:38 volumio volumio[18134]: info: Loading plugin "volumiodiscovery"... Feb 12 13:44:38 volumio volumio[18134]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 12 13:44:38 volumio volumio[18134]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 13:44:38 volumio node[18134]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 12 13:44:38 volumio volumio[18134]: *** WARNING *** For more information see Feb 12 13:44:38 volumio volumio[18134]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 12 13:44:38 volumio volumio[18134]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 13:44:38 volumio volumio[18134]: *** WARNING *** For more information see Feb 12 13:44:38 volumio node[18134]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 13:44:38 volumio node[18134]: *** WARNING *** For more information see Feb 12 13:44:38 volumio node[18134]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 12 13:44:38 volumio node[18134]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 13:44:38 volumio node[18134]: *** WARNING *** For more information see Feb 12 13:44:38 volumio volumio[18134]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 12 13:44:38 volumio volumio[18134]: info: Discovery: Started advertising with name: Volumio Feb 12 13:44:38 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 13:44:38 volumio volumio[18134]: info: Loading plugin "spop"... Feb 12 13:44:40 volumio volumio[18134]: info: Loading plugin "ytcr"... Feb 12 13:44:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 12 13:44:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:40 volumio go-librespot[18226]: go-librespot daemon starting... Feb 12 13:44:40 volumio go-librespot[18227]: time="2026-02-12T13:44:40+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:44:40 volumio go-librespot[18227]: time="2026-02-12T13:44:40+07:00" level=debug msg="app state loaded" Feb 12 13:44:40 volumio go-librespot[18227]: time="2026-02-12T13:44:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:44:40 volumio go-librespot[18227]: time="2026-02-12T13:44:40+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 13:44:40 volumio go-librespot[18227]: time="2026-02-12T13:44:40+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 13:44:40 volumio go-librespot[18227]: time="2026-02-12T13:44:40+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 13:44:40 volumio go-librespot[18227]: time="2026-02-12T13:44:40+07:00" level=info msg="zeroconf server listening on port 44541" Feb 12 13:44:41 volumio go-librespot[18227]: time="2026-02-12T13:44:41+07:00" level=debug msg="obtained new client token: AAAVj7+9NzaLEQOYtPPOoZICXjtV5uBQi4aepCVK0J4s8VgghixsPKWjEhwmlBLHaduyxgUk5WVm7m3PQFkQXsdxvekzyabDOGAk9Kg+NKvQLvGIohmIMkAyg5PTGuWsVAWhUZXQLygg3GRdk0rfzhrhCWst4Rw0sAJ8RGNn21D+gu+SAq84lEKk6jbeUYYGqAdxDn6XCmLMs4X60DO1Au93Swnnv29/OKP9+8CVLzY6qPMNzEePhkk=" Feb 12 13:44:41 volumio go-librespot[18227]: time="2026-02-12T13:44:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 13:44:41 volumio go-librespot[18227]: time="2026-02-12T13:44:41+07:00" level=debug msg="completed keyexchange" Feb 12 13:44:41 volumio go-librespot[18227]: time="2026-02-12T13:44:41+07:00" level=debug msg="completed challenge" Feb 12 13:44:41 volumio go-librespot[18227]: time="2026-02-12T13:44:41+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 13:44:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:44:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:44:42 volumio volumio[18134]: info: Loading plugin "ytmusic"... Feb 12 13:44:43 volumio volumio-remote-updater[643]: [2026-02-12 13:44:43] [connect] Successful connection Feb 12 13:44:44 volumio volumio[18134]: info: Loading plugin "outputs"... Feb 12 13:44:44 volumio volumio[18134]: info: Loading plugin "albumart"... Feb 12 13:44:44 volumio volumio[18134]: info: Plugin example_plugin is not enabled Feb 12 13:44:44 volumio volumio[18134]: info: Loading plugin "inputs"... Feb 12 13:44:44 volumio volumio[18134]: info: Loading plugin "updater_comm"... Feb 12 13:44:44 volumio volumio[18134]: info: Plugin mpdemulation is not enabled Feb 12 13:44:44 volumio volumio[18134]: info: Loading plugin "rest_api"... Feb 12 13:44:44 volumio volumio[18134]: info: Loading plugin "websocket"... Feb 12 13:44:44 volumio volumio[18134]: info: Starting Socket.io Server version 1.7.4 Feb 12 13:44:44 volumio volumio[18134]: info: Loading plugin "RoonBridge"... Feb 12 13:44:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 12 13:44:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:44 volumio go-librespot[18258]: go-librespot daemon starting... Feb 12 13:44:44 volumio go-librespot[18259]: time="2026-02-12T13:44:44+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:44:44 volumio go-librespot[18259]: time="2026-02-12T13:44:44+07:00" level=debug msg="app state loaded" Feb 12 13:44:44 volumio go-librespot[18259]: time="2026-02-12T13:44:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:44:44 volumio volumio[18134]: info: Applying required configuration parameters for plugin RoonBridge Feb 12 13:44:44 volumio volumio[18134]: info: Loading i18n strings for locale en Feb 12 13:44:44 volumio volumio[18134]: Updating browse sources language Feb 12 13:44:44 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:44:45 volumio volumio[18248]: Forking 3 albumart workers Feb 12 13:44:45 volumio go-librespot[18259]: time="2026-02-12T13:44:45+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 13:44:45 volumio go-librespot[18259]: time="2026-02-12T13:44:45+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 13:44:45 volumio go-librespot[18259]: time="2026-02-12T13:44:45+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 13:44:45 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 13:44:45 volumio volumio[18134]: info: CoreCommandRouter::initPlayerControls Feb 12 13:44:45 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:45 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:45 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:45 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:45 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:45 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:45 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:45 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:45 volumio go-librespot[18259]: time="2026-02-12T13:44:45+07:00" level=info msg="zeroconf server listening on port 37815" Feb 12 13:44:45 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 13:44:45 volumio volumio[18134]: Express server listening on port 3000 Feb 12 13:44:45 volumio volumio[18134]: [Metrics] WebUI: 16s 53.70ms Feb 12 13:44:45 volumio volumio[18134]: info: CoreStateMachine::resetVolumioState Feb 12 13:44:45 volumio volumio[18134]: info: CoreStateMachine::getcurrentVolume Feb 12 13:44:45 volumio volumio[18134]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 13:44:45 volumio go-librespot[18259]: time="2026-02-12T13:44:45+07:00" level=debug msg="obtained new client token: AAAuhwM7Y5TxIeYX/G+1zXdE+WGF6QtPV7PcSLqPnxby8r0N0z4jojUPkMRfRHwtKxFwsgydPNZBX4Jt9qtsgYvQCVa9VLHsau3CyV+9jlt8sJEH1Uc/hQo34I7B9PaplnOFMbUtnrjVyTsuYjNCf42wcT6fIa1ehDQZQIUxQXzezZ5r/U2aDqwzqrOBhHmnQzLTyWAeK/FngIgrYyuX5jah4Q3wOo6pQDPp+FcKDgfJQFDqtFegjpuOLQ==" Feb 12 13:44:45 volumio sudo[18298]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 12 13:44:45 volumio sudo[18298]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:45 volumio volumio[18134]: info: Volumio Network Manager: Network status updated: 1 Feb 12 13:44:45 volumio sudo[18301]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 12 13:44:45 volumio sudo[18301]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:45 volumio sudo[18298]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:45 volumio sudo[18301]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:45 volumio go-librespot[18259]: time="2026-02-12T13:44:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 13:44:45 volumio go-librespot[18259]: time="2026-02-12T13:44:45+07: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 12 13:44:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:44:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:44:45 volumio volumio[18134]: info: VolumeController:: Volume=100 Mute =false Feb 12 13:44:45 volumio volumio[18134]: info: CoreStateMachine::pushState Feb 12 13:44:45 volumio volumio[18134]: info: CorePlayQueue::getTrack 0 Feb 12 13:44:45 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 13:44:45 volumio volumio[18134]: info: CoreCommandRouter::volumioPushState Feb 12 13:44:45 volumio volumio[18134]: info: CoreStateMachine::updateTrackBlock Feb 12 13:44:45 volumio volumio[18134]: info: CorePlayQueue::getTrackBlock Feb 12 13:44:45 volumio volumio[18134]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 13:44:46 volumio volumio-remote-updater[643]: [2026-02-12 13:44:45] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770878683 101 Feb 12 13:44:46 volumio volumio[18134]: 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 12 13:44:46 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:44:46 volumio volumio[18134]: info: Reloading queue from file Feb 12 13:44:46 volumio volumio[18134]: info: CoreStateMachine::setRepeat null single undefined Feb 12 13:44:46 volumio volumio[18134]: info: CoreStateMachine::pushState Feb 12 13:44:46 volumio volumio[18134]: info: CorePlayQueue::getTrack 0 Feb 12 13:44:46 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 13:44:46 volumio volumio[18134]: info: CoreCommandRouter::volumioPushState Feb 12 13:44:46 volumio volumio[18134]: info: CoreStateMachine::setRandom null Feb 12 13:44:46 volumio volumio[18134]: info: CoreStateMachine::pushState Feb 12 13:44:46 volumio volumio[18134]: info: CorePlayQueue::getTrack 0 Feb 12 13:44:46 volumio volumio[18134]: info: CoreCommandRouter::volumioPushState Feb 12 13:44:46 volumio volumio[18134]: info: Setting Device type: Raspberry PI Feb 12 13:44:46 volumio volumio[18134]: info: Completed loading Core Plugins Feb 12 13:44:46 volumio volumio[18134]: info: Preparing to generate the ALSA configuration file Feb 12 13:44:46 volumio volumio[18134]: info: VolumeController:: Volume=100 Mute =false Feb 12 13:44:46 volumio volumio[18134]: info: CoreStateMachine::pushState Feb 12 13:44:46 volumio volumio[18134]: info: CorePlayQueue::getTrack 0 Feb 12 13:44:46 volumio volumio[18134]: info: CoreCommandRouter::volumioPushState Feb 12 13:44:46 volumio volumio[18134]: info: Asound.conf file unchanged, so no further update is needed Feb 12 13:44:46 volumio volumio[18134]: info: Output device has changed, restarting MPD Feb 12 13:44:46 volumio sudo[18316]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 12 13:44:46 volumio volumio[18134]: info: Output device has changed, restarting Shairport Sync Feb 12 13:44:46 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:46 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:44:46 volumio sudo[18316]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:46 volumio sudo[18320]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 13:44:46 volumio sudo[18318]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 13:44:46 volumio sudo[18320]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:46 volumio sudo[18318]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:46 volumio sudo[18318]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:46 volumio volumio[18134]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 13:44:46 volumio volumio[18134]: info: ___________ START PLUGINS ___________ Feb 12 13:44:46 volumio volumio[18134]: info: ControllerMpd::onStart: Initializing MPD Feb 12 13:44:46 volumio volumio[18134]: info: Creating MPD Configuration file Feb 12 13:44:46 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 12 13:44:46 volumio sudo[18316]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:46 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 12 13:44:46 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 13:44:46 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 12 13:44:46 volumio volumio[18134]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 13:44:46 volumio systemd[1]: mpd.service: Consumed 7.173s CPU time. Feb 12 13:44:46 volumio volumio[18134]: info: [1770878686851] CoreMusicLibrary::Adding element Media Servers Feb 12 13:44:46 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:44:46 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 12 13:44:46 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 12 13:44:46 volumio sudo[18329]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 13:44:46 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 12 13:44:46 volumio sudo[18329]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:46 volumio sudo[18329]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:46 volumio volumio[18134]: info: UPNP Browser: Client initialized successfully Feb 12 13:44:46 volumio sudo[18331]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 13:44:46 volumio sudo[18331]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:46 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 12 13:44:46 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 12 13:44:46 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:47 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:44:47 volumio volumio[18134]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 13:44:47 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:47 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:44:47 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 12 13:44:47 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 12 13:44:47 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 12 13:44:47 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 12 13:44:47 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 12 13:44:47 volumio volumio[18134]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 13:44:47 volumio volumio[18134]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 13:44:47 volumio volumio[18134]: info: [1770878687151] CoreMusicLibrary::Adding element Last_100 Feb 12 13:44:47 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:44:47 volumio volumio[18134]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 13:44:47 volumio volumio[18134]: info: [1770878687160] CoreMusicLibrary::Adding element Webradio Feb 12 13:44:47 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:44:47 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 13:44:47 volumio volumio[18134]: info: Initializing BBC Radios Feb 12 13:44:47 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 12 13:44:47 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 12 13:44:47 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 13:44:47 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:44:47 volumio volumio[18134]: info: Creating Spotify config file Feb 12 13:44:47 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:47 volumio sudo[18347]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 12 13:44:47 volumio sudo[18347]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 12 13:44:47 volumio sudo[18347]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:48 volumio volumio[18266]: Starting albumart workers Feb 12 13:44:48 volumio volumio[18268]: Starting albumart workers Feb 12 13:44:48 volumio volumio[18134]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 13:44:48 volumio volumio[18134]: info: [1770878688552] CoreMusicLibrary::Adding element YouTube Music Feb 12 13:44:48 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:44:48 volumio volumio[18134]: Cannot find translation for source YouTube Music Feb 12 13:44:48 volumio volumio[18134]: info: Volumio Calling Home Feb 12 13:44:48 volumio sudo[18362]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 12 13:44:48 volumio sudo[18362]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 12 13:44:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:48 volumio volumio[18267]: Starting albumart workers Feb 12 13:44:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:49 volumio go-librespot[18367]: go-librespot daemon starting... Feb 12 13:44:49 volumio sudo[18362]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:49 volumio go-librespot[18368]: time="2026-02-12T13:44:49+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:44:49 volumio volumio[18134]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 12 13:44:49 volumio volumio[18134]: info: Discovery: Found device Volumio Feb 12 13:44:49 volumio volumio[18134]: info: CoreCommandRouter::volumioGetState Feb 12 13:44:49 volumio volumio[18134]: info: CorePlayQueue::getTrack 0 Feb 12 13:44:49 volumio volumio[18134]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 12 13:44:49 volumio volumio[18134]: info: Discovery: Found device Volumio Feb 12 13:44:49 volumio volumio[18134]: info: CoreCommandRouter::volumioGetState Feb 12 13:44:49 volumio volumio[18134]: info: CorePlayQueue::getTrack 0 Feb 12 13:44:49 volumio volumio[18134]: info: MPD Permissions set Feb 12 13:44:49 volumio volumio[18134]: info: MPD Permissions set Feb 12 13:44:49 volumio volumio[18134]: info: Upmpdcli Daemon Started Feb 12 13:44:49 volumio volumio[18134]: info: Spotify config file written Feb 12 13:44:49 volumio go-librespot[18368]: time="2026-02-12T13:44:49+07:00" level=info msg="zeroconf server listening on port 37577" Feb 12 13:44:50 volumio volumio[18134]: 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 12 13:44:50 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:50 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:50 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:50 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:50 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:50 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:50 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:50 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:50 volumio sudo[18376]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 12 13:44:50 volumio sudo[18376]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:50 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:44:50 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:50 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:50 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:50 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:50 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:50 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:50 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:50 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:50 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:50 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 12 13:44:50 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 12 13:44:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:50 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:44:50 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:44:50 volumio volumio[18134]: info: No need to fix Spotify hosts Feb 12 13:44:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:50 volumio go-librespot[18395]: go-librespot daemon starting... Feb 12 13:44:50 volumio sudo[18376]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:50 volumio go-librespot[18396]: time="2026-02-12T13:44:50+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:44:50 volumio go-librespot[18396]: time="2026-02-12T13:44:50+07:00" level=debug msg="app state loaded" Feb 12 13:44:50 volumio go-librespot[18396]: time="2026-02-12T13:44:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:44:50 volumio volumio[18134]: info: Volumio called home Feb 12 13:44:51 volumio go-librespot[18396]: time="2026-02-12T13:44:51+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 13:44:51 volumio go-librespot[18396]: time="2026-02-12T13:44:51+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 13:44:51 volumio go-librespot[18396]: time="2026-02-12T13:44:51+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 13:44:51 volumio go-librespot[18396]: time="2026-02-12T13:44:51+07:00" level=info msg="zeroconf server listening on port 41261" Feb 12 13:44:51 volumio go-librespot[18396]: time="2026-02-12T13:44:51+07:00" level=debug msg="obtained new client token: AABJULrd+NK6x/TCX2GnlrLyOhCjWfAgK89ljf32nR0ed3H9dfELAh6dfinao7hiX1AYvlVDcz38Q7zw1HCKQ9GaQXNKVrMiFRE7qHJiRmwZBxExiWoyeZhEmt3LsU40K4uLqpF2NUnN/uaUY/PI4x1/PYz/iXnBl8sPOx6RE+8IzfyRPBZmgvFMLMrD909fmjUraU+I6fzEp2muHOv5mmU/QkpMj7t+Se6TA14gKYYg08Fhz18Iarg=" Feb 12 13:44:51 volumio go-librespot[18396]: time="2026-02-12T13:44:51+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 13:44:51 volumio volumio[18134]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 13:44:51 volumio volumio[18134]: SPOTIFY: BQCZgUaLM83w7M4kAoXzr9e0YMiZSIpZ84JOnEwG31cL-v22WGQmBtt0Ro-6rYuKlzFlPVskazhzx4yez7SakALnWNKLamzVoEm9zoKGEAtLzoRVnoLS_rT2q0liFZ2R3aug-xKytlalsZ7K15S09Gdjcjr9Btsos5iuVyiP92Uat1507fSeHkFFwr5Z7T8GwhO0pwX4lmGCMmfwry4alP-kPy1pT1n1wZV__5QIHB9XsCPXGTkIngWNgSJLkGqh-zDkP6KRoaAZfMGwOW5EIWvZBLNaCoM05hUC3PZ4XD5UYcE_6OAHxk06 Feb 12 13:44:51 volumio volumio[18134]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 13:44:51 volumio volumio[18134]: info: New Spotify access token = BQCZgUaLM83w7M4kAoXzr9e0YMiZSIpZ84JOnEwG31cL-v22WGQmBtt0Ro-6rYuKlzFlPVskazhzx4yez7SakALnWNKLamzVoEm9zoKGEAtLzoRVnoLS_rT2q0liFZ2R3aug-xKytlalsZ7K15S09Gdjcjr9Btsos5iuVyiP92Uat1507fSeHkFFwr5Z7T8GwhO0pwX4lmGCMmfwry4alP-kPy1pT1n1wZV__5QIHB9XsCPXGTkIngWNgSJLkGqh-zDkP6KRoaAZfMGwOW5EIWvZBLNaCoM05hUC3PZ4XD5UYcE_6OAHxk06 Feb 12 13:44:51 volumio volumio[18134]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 12 13:44:51 volumio go-librespot[18396]: time="2026-02-12T13:44:51+07: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 12 13:44:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:44:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:44:51 volumio volumio[18134]: info: Starting Shairport Sync Feb 12 13:44:51 volumio volumio[18134]: info: Starting Shairport Sync Feb 12 13:44:51 volumio volumio[18134]: info: Starting Shairport Sync Feb 12 13:44:51 volumio sudo[18417]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 13:44:51 volumio sudo[18417]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:51 volumio sudo[18419]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 13:44:51 volumio sudo[18419]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:51 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 12 13:44:51 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 12 13:44:51 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 13:44:51 volumio systemd[1]: shairport-sync.service: Consumed 2.288s CPU time. Feb 12 13:44:51 volumio sudo[18421]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 13:44:51 volumio sudo[18421]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:44:51 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 13:44:51 volumio sudo[18417]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:51 volumio volumio[18134]: info: Shairport-Sync Started Feb 12 13:44:51 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 12 13:44:51 volumio volumio[18134]: Error adding Membership: Error: addMembership EINVAL Feb 12 13:44:51 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 12 13:44:51 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 13:44:51 volumio volumio[18134]: info: CoreCommandRouter::volumioGetState Feb 12 13:44:51 volumio volumio[18134]: info: CorePlayQueue::getTrack 0 Feb 12 13:44:52 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 13:44:52 volumio sudo[18419]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:52 volumio sudo[18421]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:52 volumio volumio[18134]: info: Shairport-Sync Started Feb 12 13:44:52 volumio volumio[18134]: info: Shairport-Sync Started Feb 12 13:44:52 volumio volumio[18134]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 12 13:44:52 volumio volumio[18134]: info: Spotify Successfully logged in Feb 12 13:44:52 volumio volumio[18134]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 13:44:52 volumio volumio[18134]: info: [1770878692176] CoreMusicLibrary::Adding element Spotify Feb 12 13:44:52 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:44:52 volumio volumio[18134]: Cannot find translation for source YouTube Music Feb 12 13:44:52 volumio volumio[18134]: Cannot find translation for source Spotify Feb 12 13:44:53 volumio volumio[18134]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 12 13:44:53 volumio volumio[18134]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 13:44:53 volumio volumio[18134]: info: VolumeController:: Volume=100 Mute =false Feb 12 13:44:53 volumio volumio[18134]: info: CoreCommandRouter::volumioGetState Feb 12 13:44:53 volumio volumio[18134]: info: CorePlayQueue::getTrack 0 Feb 12 13:44:53 volumio volumio[18134]: info: CoreStateMachine::pushState Feb 12 13:44:53 volumio volumio[18134]: info: CorePlayQueue::getTrack 0 Feb 12 13:44:53 volumio volumio[18134]: info: CoreCommandRouter::volumioPushState Feb 12 13:44:54 volumio volumio[18134]: info: go-librespot daemon successfully initialized Feb 12 13:44:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 12 13:44:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:54 volumio go-librespot[18458]: go-librespot daemon starting... Feb 12 13:44:54 volumio mpd[18360]: 2026-02-12T13:44:54 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 12 13:44:54 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 12 13:44:54 volumio sudo[18331]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:54 volumio sudo[18320]: pam_unix(sudo:session): session closed for user root Feb 12 13:44:54 volumio go-librespot[18459]: time="2026-02-12T13:44:54+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:44:54 volumio go-librespot[18459]: time="2026-02-12T13:44:54+07:00" level=debug msg="app state loaded" Feb 12 13:44:54 volumio go-librespot[18459]: time="2026-02-12T13:44:54+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:44:54 volumio volumio[18134]: error: MPD error: The expression evaluated to a falsy value: Feb 12 13:44:54 volumio volumio[18134]: assert.ok(self.idling) Feb 12 13:44:54 volumio volumio[18134]: error: The expression evaluated to a falsy value: Feb 12 13:44:54 volumio volumio[18134]: assert.ok(self.idling) Feb 12 13:44:54 volumio volumio[18134]: info: MPD running with PID18360 Feb 12 13:44:54 volumio volumio[18134]: ,establishing connection Feb 12 13:44:54 volumio volumio[18134]: error: updateQueue error: null Feb 12 13:44:55 volumio volumio[18134]: info: Completed starting Core Plugins Feb 12 13:44:55 volumio volumio[18134]: info: ------------------------------------------- Feb 12 13:44:55 volumio volumio[18134]: info: ----- MyVolumio plugins startup ---- Feb 12 13:44:55 volumio volumio[18134]: info: ------------------------------------------- Feb 12 13:44:55 volumio volumio[18134]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 12 13:44:55 volumio volumio[18134]: error: updateQueue error: null Feb 12 13:44:55 volumio go-librespot[18459]: time="2026-02-12T13:44:55+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 13:44:55 volumio go-librespot[18459]: time="2026-02-12T13:44:55+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 13:44:55 volumio go-librespot[18459]: time="2026-02-12T13:44:55+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 13:44:55 volumio go-librespot[18459]: time="2026-02-12T13:44:55+07:00" level=info msg="zeroconf server listening on port 36439" Feb 12 13:44:55 volumio nmbd[966]: [2026/02/12 13:44:55.382821, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) Feb 12 13:44:55 volumio nmbd[966]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.1.23 for name WORKGROUP<1d>. Feb 12 13:44:55 volumio nmbd[966]: This response was from IP 192.168.1.237, reporting an IP address of 192.168.1.237. Feb 12 13:44:55 volumio go-librespot[18459]: time="2026-02-12T13:44:55+07:00" level=debug msg="obtained new client token: AADH7m+ePI9BIOcZPhEK8NDPuqsfCEwyp2/kwZ8XJsYJgtYm64Wge212KcyvKckkyd/dUDckFbrZMEth50VT5+q2UrUOfIlEIYra3NUxRU00LKXPyo6NSje0SsPh6nxWRMZ+SJa3Jt+Xi/nNEylbeJZNmYjCZx43cHjIFHSkvc0cObkvNKnx68Oh2XXPCJ1wDO9ovh06JcTPNpGDbdcrawIv/DMmHWINXg7P5ktrcpm//UCCy+iPWUan8A==" Feb 12 13:44:55 volumio go-librespot[18459]: time="2026-02-12T13:44:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 13:44:55 volumio go-librespot[18459]: time="2026-02-12T13:44:55+07:00" level=debug msg="completed keyexchange" Feb 12 13:44:55 volumio go-librespot[18459]: time="2026-02-12T13:44:55+07:00" level=debug msg="completed challenge" Feb 12 13:44:55 volumio go-librespot[18459]: time="2026-02-12T13:44:55+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 13:44:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:44:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:44:57 volumio volumio[18134]: info: Initializing connection to go-librespot Websocket Feb 12 13:44:57 volumio volumio[18134]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 13:44:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 12 13:44:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:44:58 volumio go-librespot[18472]: go-librespot daemon starting... Feb 12 13:44:58 volumio go-librespot[18473]: time="2026-02-12T13:44:58+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:44:58 volumio go-librespot[18473]: time="2026-02-12T13:44:58+07:00" level=debug msg="app state loaded" Feb 12 13:44:58 volumio go-librespot[18473]: time="2026-02-12T13:44:58+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:44:59 volumio go-librespot[18473]: time="2026-02-12T13:44:59+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 13:44:59 volumio go-librespot[18473]: time="2026-02-12T13:44:59+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 13:44:59 volumio go-librespot[18473]: time="2026-02-12T13:44:59+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 13:44:59 volumio go-librespot[18473]: time="2026-02-12T13:44:59+07:00" level=info msg="zeroconf server listening on port 38981" Feb 12 13:44:59 volumio go-librespot[18473]: time="2026-02-12T13:44:59+07:00" level=debug msg="obtained new client token: AAD7c67c259p4MoblvPPYIVihnQClEMxFkhoz42/5Lh053MdkEsC7MOmSnUKiwW+tFHjVWyv5L23Xtnt1cvmM91SSEIqX/rR5262SnpLLMEGTLU5Bm6BjKOI3aO2c1Soo/5u89/15qEly0lSe8xAJpo0Im/7ojFZ5YhiJgsZnt7tdHpFZ1dm3iBcX1lGVkv9S3qyHxt/OLhgbV9a6GbfKLldKqtASf8XmaTVUy/5iAieaf6524SfsAQFCQ==" Feb 12 13:44:59 volumio volumio[18134]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 12 13:44:59 volumio go-librespot[18473]: time="2026-02-12T13:44:59+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 13:44:59 volumio go-librespot[18473]: time="2026-02-12T13:44:59+07: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 12 13:44:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:44:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:45:00 volumio volumio[18134]: info: Initializing connection to go-librespot Websocket Feb 12 13:45:00 volumio volumio[18134]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 13:45:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 12 13:45:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:45:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:45:03 volumio go-librespot[18481]: go-librespot daemon starting... Feb 12 13:45:03 volumio go-librespot[18482]: time="2026-02-12T13:45:03+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:45:03 volumio go-librespot[18482]: time="2026-02-12T13:45:03+07:00" level=debug msg="app state loaded" Feb 12 13:45:03 volumio go-librespot[18482]: time="2026-02-12T13:45:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:45:03 volumio volumio[18134]: info: Initializing connection to go-librespot Websocket Feb 12 13:45:03 volumio go-librespot[18482]: time="2026-02-12T13:45:03+07:00" level=debug msg="new websocket client" Feb 12 13:45:03 volumio volumio[18134]: info: Connection to go-librespot Websocket established Feb 12 13:45:03 volumio go-librespot[18482]: time="2026-02-12T13:45:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 13:45:03 volumio go-librespot[18482]: time="2026-02-12T13:45:03+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 13:45:03 volumio go-librespot[18482]: time="2026-02-12T13:45:03+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 13:45:03 volumio go-librespot[18482]: time="2026-02-12T13:45:03+07:00" level=info msg="zeroconf server listening on port 41285" Feb 12 13:45:03 volumio volumio[18134]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 12 13:45:03 volumio volumio[18134]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 12 13:45:03 volumio volumio[18134]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 12 13:45:03 volumio volumio[18134]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 12 13:45:03 volumio volumio[18134]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 12 13:45:03 volumio volumio[18134]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 12 13:45:03 volumio volumio[18134]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 12 13:45:03 volumio volumio[18134]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 12 13:45:03 volumio volumio[18134]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 12 13:45:03 volumio volumio[18134]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 12 13:45:03 volumio volumio[18134]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 12 13:45:03 volumio volumio[18134]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 12 13:45:03 volumio volumio[18134]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 12 13:45:03 volumio volumio[18134]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 12 13:45:03 volumio volumio[18134]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 12 13:45:03 volumio volumio[18134]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 12 13:45:03 volumio volumio[18134]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 12 13:45:03 volumio volumio[18134]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 12 13:45:03 volumio volumio[18134]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 12 13:45:03 volumio volumio[18134]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 12 13:45:03 volumio volumio[18134]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 12 13:45:03 volumio volumio[18134]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 12 13:45:03 volumio volumio[18134]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 12 13:45:03 volumio volumio[18134]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 12 13:45:03 volumio volumio[18134]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 12 13:45:03 volumio volumio[18134]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 12 13:45:03 volumio volumio[18134]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 12 13:45:03 volumio volumio[18134]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 12 13:45:03 volumio volumio[18134]: info: Adding plugin bluetooth to MyMusic Plugins Feb 12 13:45:03 volumio volumio[18134]: info: Adding plugin multiroom to MyMusic Plugins Feb 12 13:45:03 volumio volumio[18134]: info: Adding plugin metavolumio to MyMusic Plugins Feb 12 13:45:03 volumio volumio[18134]: info: Adding plugin cd_controller to MyMusic Plugins Feb 12 13:45:03 volumio volumio[18134]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 12 13:45:03 volumio volumio[18134]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 12 13:45:03 volumio volumio[18134]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 12 13:45:03 volumio volumio[18134]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 12 13:45:03 volumio go-librespot[18482]: time="2026-02-12T13:45:03+07:00" level=debug msg="obtained new client token: AAD5Wj8lYE5z3HjcKYF7ayE4OHFqiIIZxJy04anpCusVmictxbLplB8LQ6vBVZcJtzXWT91ixKpSHamG/BpdQiGur1JRSHmQg4CDRa0CZhXgwtSEvpk9Y54vzr2b7pfTLx1wEp1/GNFResaJK4TlWScJEGk344IsqWm+P2w0+VkfcdGrxNFh2Cuu9wgaFQ8sRavCpB1ga+Y86/IHVqsHKWCrBGtn6+z3AtygVhCeSTIkn3RWDTol9nKV7g==" Feb 12 13:45:04 volumio go-librespot[18482]: time="2026-02-12T13:45:04+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 12 13:45:04 volumio go-librespot[18482]: time="2026-02-12T13:45:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 12 13:45:04 volumio go-librespot[18482]: time="2026-02-12T13:45:04+07: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 12 13:45:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:45:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:45:05 volumio volumio[18134]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 12 13:45:05 volumio volumio[18134]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 12 13:45:05 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:45:05 volumio volumio[18134]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:45:05 volumio volumio[18134]: info: Starting MyVolumio Remote Streaming Endpoints Feb 12 13:45:05 volumio volumio[18134]: info: MyVolumio login type: Token Feb 12 13:45:05 volumio volumio[18134]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 12 13:45:05 volumio volumio[18134]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 12 13:45:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 12 13:45:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:45:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:45:07 volumio go-librespot[18503]: go-librespot daemon starting... Feb 12 13:45:07 volumio go-librespot[18504]: time="2026-02-12T13:45:07+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:45:07 volumio go-librespot[18504]: time="2026-02-12T13:45:07+07:00" level=debug msg="app state loaded" Feb 12 13:45:07 volumio go-librespot[18504]: time="2026-02-12T13:45:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:45:07 volumio volumio[18134]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 12 13:45:07 volumio volumio[18134]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 12 13:45:07 volumio volumio[18134]: info: Streaming services startup Feb 12 13:45:07 volumio volumio[18134]: info: Starting Streaming Daemon Feb 12 13:45:07 volumio sudo[18511]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 12 13:45:07 volumio volumio[18134]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 12 13:45:07 volumio sudo[18511]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:45:07 volumio sudo[18511]: pam_unix(sudo:session): session closed for user root Feb 12 13:45:07 volumio volumio[18134]: info: Getting Spotify volume Feb 12 13:45:07 volumio volumio[18134]: info: Connection to go-librespot Websocket closed Feb 12 13:45:07 volumio volumio[18134]: error: Cannot start Volumio Streaming Daemon Feb 12 13:45:07 volumio volumio[18134]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 12 13:45:07 volumio volumio[18134]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 12 13:45:07 volumio volumio[18134]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 12 13:45:08 volumio go-librespot[18504]: time="2026-02-12T13:45:08+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 13:45:08 volumio go-librespot[18504]: time="2026-02-12T13:45:08+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 13:45:08 volumio go-librespot[18504]: time="2026-02-12T13:45:08+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 13:45:08 volumio go-librespot[18504]: time="2026-02-12T13:45:08+07:00" level=info msg="zeroconf server listening on port 39089" Feb 12 13:45:08 volumio volumio[18134]: info: CoreCommandRouter::volumioGetState Feb 12 13:45:08 volumio volumio[18134]: info: CorePlayQueue::getTrack 0 Feb 12 13:45:08 volumio volumio[18134]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 12 13:45:08 volumio volumio[18134]: SPOTIFY: SPOTIFY VOLUME undefined Feb 12 13:45:08 volumio volumio[18134]: SPOTIFY: VOLUMIO VOLUME 100 Feb 12 13:45:08 volumio volumio[18134]: info: Aligning Spotify Volume to Volumio Volume Feb 12 13:45:08 volumio volumio[18134]: info: CoreCommandRouter::volumioGetState Feb 12 13:45:08 volumio volumio[18134]: info: CorePlayQueue::getTrack 0 Feb 12 13:45:08 volumio volumio[18134]: info: Setting Spotify Volume from Volumio: 100 Feb 12 13:45:08 volumio go-librespot[18504]: time="2026-02-12T13:45:08+07:00" level=debug msg="obtained new client token: AADikfkpCNhCyguj8aEonkFdHiN+s1gx7wH5U0FRunQnpJCke2qDfQ7enelQBunwyIbrw75xzkBr6sA9rNnT/Lnw6oAFAmf8zFDdgxkAawwe/hGvvzNHb8KzszwMoh43bmbRfl107ItipzcKtIS66xyETbJTJxfXWcD8myGVgVa1p3XQqS8HhzExTW7ad088rMVuHRWP5xRmfZUdIzJmEah2ihg8UCxMbT2ocUHMfFgt4Z0qyMZd4D4=" Feb 12 13:45:08 volumio go-librespot[18504]: time="2026-02-12T13:45:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 13:45:08 volumio go-librespot[18504]: time="2026-02-12T13:45:08+07: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 12 13:45:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:45:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:45:08 volumio volumio[18134]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 13:45:08 volumio volumio[18134]: Error: socket hang up Feb 12 13:45:08 volumio volumio[18134]: at connResetException (node:internal/errors:720:14) Feb 12 13:45:08 volumio volumio[18134]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 12 13:45:08 volumio volumio[18134]: at Socket.emit (node:events:526:35) Feb 12 13:45:08 volumio volumio[18134]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 12 13:45:08 volumio volumio[18134]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 12 13:45:08 volumio volumio[18134]: code: 'ECONNRESET', Feb 12 13:45:08 volumio volumio[18134]: response: undefined Feb 12 13:45:08 volumio volumio[18134]: } Feb 12 13:45:08 volumio volumio[18134]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 13:45:09 volumio sudo[18533]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-12 13:44' Feb 12 13:45:09 volumio sudo[18533]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:45:10 volumio sudo[18533]: pam_unix(sudo:session): session closed for user root Feb 12 13:45:10 volumio volumio-remote-updater[643]: [2026-02-12 13:45:10] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 12 13:45:10 volumio volumio-remote-updater[643]: [2026-02-12 13:45:10] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 12 13:45:10 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:45:10 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 12 13:45:10 volumio systemd[1]: volumio.service: Consumed 55.586s CPU time. Feb 12 13:45:10 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 12 13:45:10 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 12 13:45:10 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 13254. Feb 12 13:45:10 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 12 13:45:10 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 12 13:45:10 volumio systemd[1]: volumio.service: Consumed 55.586s CPU time. Feb 12 13:45:10 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 12 13:45:10 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 12 13:45:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 12 13:45:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:45:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:45:11 volumio go-librespot[18563]: go-librespot daemon starting... Feb 12 13:45:11 volumio go-librespot[18564]: time="2026-02-12T13:45:11+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:45:11 volumio go-librespot[18564]: time="2026-02-12T13:45:11+07:00" level=debug msg="app state loaded" Feb 12 13:45:11 volumio go-librespot[18564]: time="2026-02-12T13:45:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:45:12 volumio go-librespot[18564]: time="2026-02-12T13:45:12+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 13:45:12 volumio go-librespot[18564]: time="2026-02-12T13:45:12+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 13:45:12 volumio go-librespot[18564]: time="2026-02-12T13:45:12+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 13:45:12 volumio go-librespot[18564]: time="2026-02-12T13:45:12+07:00" level=info msg="zeroconf server listening on port 38641" Feb 12 13:45:12 volumio go-librespot[18564]: time="2026-02-12T13:45:12+07:00" level=debug msg="obtained new client token: AACzLjQc/8x+uuSqM6of/BAGslvW4ILIdhKH2Jd/FI0hJcYA1/OsODAi6bpK6LMgbWUomtxmNEgpi7RSasI0v+c+vjlsXb7h4KuZ9sJUPGzY/kX5u83XIufIXDRxA/+lhux2Qajy50paVEuVNhUaqZ7HzPC85q875Ao7IgSm8xyvkq32kEF7HIab57OohgjfHWQ2ETrqJ8SjYcf4WPhqujvdP27BxnkjbUr9bWZdpIhzBG8f201vRBfkuQ==" Feb 12 13:45:12 volumio go-librespot[18564]: time="2026-02-12T13:45:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 13:45:12 volumio go-librespot[18564]: time="2026-02-12T13:45:12+07: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 12 13:45:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:45:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:45:14 volumio volumio[18548]: info: ------------------------------------------- Feb 12 13:45:14 volumio volumio[18548]: info: ----- Volumio3 ---- Feb 12 13:45:14 volumio volumio[18548]: info: ------------------------------------------- Feb 12 13:45:14 volumio volumio[18548]: info: ----- System startup ---- Feb 12 13:45:14 volumio volumio[18548]: info: ------------------------------------------- Feb 12 13:45:15 volumio volumio-remote-updater[643]: [2026-02-12 13:45:15] [connect] Successful connection Feb 12 13:45:15 volumio volumio[18548]: info: MYVOLUMIO Environment detected Feb 12 13:45:15 volumio volumio[18548]: info: Plugin folders cleanup Feb 12 13:45:15 volumio volumio[18548]: info: Scanning into folder /volumio/app/plugins/ Feb 12 13:45:15 volumio volumio[18548]: info: Scanning category audio_interface Feb 12 13:45:15 volumio volumio[18548]: info: Scanning category miscellanea Feb 12 13:45:15 volumio volumio[18548]: info: Scanning category music_service Feb 12 13:45:15 volumio volumio[18548]: info: Scanning category plugins.json Feb 12 13:45:15 volumio volumio[18548]: info: Scanning category system_controller Feb 12 13:45:15 volumio volumio[18548]: info: Scanning category user_interface Feb 12 13:45:15 volumio volumio[18548]: info: Scanning into folder /data/plugins/ Feb 12 13:45:15 volumio volumio[18548]: info: Scanning category music_service Feb 12 13:45:15 volumio volumio[18548]: info: Plugin folders cleanup completed Feb 12 13:45:15 volumio volumio[18548]: info: ------------------------------------------- Feb 12 13:45:15 volumio volumio[18548]: info: ----- Core plugins startup ---- Feb 12 13:45:15 volumio volumio[18548]: info: ------------------------------------------- Feb 12 13:45:15 volumio volumio[18548]: info: Loading plugins from folder /volumio/app/plugins/ Feb 12 13:45:15 volumio volumio[18548]: info: Adding plugin upnp to MyMusic Plugins Feb 12 13:45:15 volumio volumio[18548]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 12 13:45:15 volumio volumio[18548]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 12 13:45:15 volumio volumio[18548]: info: Loading plugins from folder /data/plugins/ Feb 12 13:45:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 12 13:45:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:45:15 volumio volumio[18548]: info: Loading plugin "system"... Feb 12 13:45:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:45:15 volumio go-librespot[18580]: go-librespot daemon starting... Feb 12 13:45:15 volumio volumio[18548]: info: Loading plugin "appearance"... Feb 12 13:45:15 volumio go-librespot[18583]: time="2026-02-12T13:45:15+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:45:15 volumio go-librespot[18583]: time="2026-02-12T13:45:15+07:00" level=debug msg="app state loaded" Feb 12 13:45:15 volumio go-librespot[18583]: time="2026-02-12T13:45:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:45:16 volumio go-librespot[18583]: time="2026-02-12T13:45:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 13:45:16 volumio go-librespot[18583]: time="2026-02-12T13:45:16+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 13:45:16 volumio go-librespot[18583]: time="2026-02-12T13:45:16+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 13:45:16 volumio go-librespot[18583]: time="2026-02-12T13:45:16+07:00" level=info msg="zeroconf server listening on port 35637" Feb 12 13:45:16 volumio go-librespot[18583]: time="2026-02-12T13:45:16+07:00" level=debug msg="obtained new client token: AABw4LLFr0fU0wtI5KKMOGMZRJExknc3xNsqthNUTRmpcWncyTFDQLMY/Y2O/xmB+UMBbC8oEFqXrM917zzYCB66bZcwBgR7AvGRpS6o/WX3kIyydCtGPZfbBwqKrK0Z2ggY1tM7/7NjcoghZPM3ZJStU5nWeYOuUTA62iFAQoAKKEkbj8IFDJMhXv96mVf8gwyFFEoAn77i+dD6Diusol5ObklgjIHkxR6sIc+bKFq5RnyLZ0s7UoX2mQ==" Feb 12 13:45:16 volumio go-librespot[18583]: time="2026-02-12T13:45:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 13:45:16 volumio go-librespot[18583]: time="2026-02-12T13:45:16+07: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 12 13:45:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:45:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:45:17 volumio volumio[18548]: info: Loading plugin "network"... Feb 12 13:45:17 volumio volumio[18548]: info: Refreshing Cached IP Addresses Feb 12 13:45:17 volumio sudo[18593]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 12 13:45:17 volumio sudo[18593]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:45:17 volumio sudo[18595]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 12 13:45:17 volumio sudo[18595]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:45:17 volumio sudo[18595]: pam_unix(sudo:session): session closed for user root Feb 12 13:45:17 volumio sudo[18593]: pam_unix(sudo:session): session closed for user root Feb 12 13:45:17 volumio volumio[18548]: info: Loading plugin "services"... Feb 12 13:45:17 volumio volumio[18548]: info: Loading plugin "alsa_controller"... Feb 12 13:45:17 volumio sudo[18604]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 12 13:45:17 volumio sudo[18604]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:45:18 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 13:45:18 volumio volumio[18548]: info: Loading plugin "wizard"... Feb 12 13:45:18 volumio volumio[18548]: info: Loading plugin "networkfs"... Feb 12 13:45:18 volumio volumio[18548]: info: Starting Udev Watcher for removable devices Feb 12 13:45:18 volumio volumio[18548]: info: Ignoring mount for partition: boot Feb 12 13:45:18 volumio volumio[18548]: info: Ignoring mount for partition: volumio Feb 12 13:45:18 volumio volumio[18548]: info: Ignoring mount for partition: volumio_data Feb 12 13:45:18 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 13:45:18 volumio volumio[18548]: info: Loading plugin "volumio_command_line_client"... Feb 12 13:45:18 volumio volumio[18548]: info: Loading plugin "upnp"... Feb 12 13:45:18 volumio volumio[18548]: info: [1770878718229] Starting Upmpd Daemon Feb 12 13:45:18 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 13:45:18 volumio volumio[18548]: info: Loading plugin "my_music"... Feb 12 13:45:18 volumio volumio[18548]: info: Loading plugin "mpd"... Feb 12 13:45:18 volumio volumio[18548]: info: Loading plugin "upnp_browser"... Feb 12 13:45:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 12 13:45:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:45:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:45:20 volumio go-librespot[18626]: go-librespot daemon starting... Feb 12 13:45:20 volumio go-librespot[18627]: time="2026-02-12T13:45:20+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:45:20 volumio go-librespot[18627]: time="2026-02-12T13:45:20+07:00" level=debug msg="app state loaded" Feb 12 13:45:20 volumio go-librespot[18627]: time="2026-02-12T13:45:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:45:20 volumio sudo[18604]: pam_unix(sudo:session): session closed for user root Feb 12 13:45:20 volumio go-librespot[18627]: time="2026-02-12T13:45:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 13:45:20 volumio go-librespot[18627]: time="2026-02-12T13:45:20+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 13:45:20 volumio go-librespot[18627]: time="2026-02-12T13:45:20+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 13:45:20 volumio go-librespot[18627]: time="2026-02-12T13:45:20+07:00" level=info msg="zeroconf server listening on port 40363" Feb 12 13:45:21 volumio go-librespot[18627]: time="2026-02-12T13:45:21+07:00" level=debug msg="obtained new client token: AADukk4t/6/lLlZ82PHDGw7Rx9WDwPHEWn8xJ3QoxebPeDmUARQcWKFRhiLYUF/3DeMlts2piR+ysjngxRXw9VlNRUV5uIrE/81EXnWG7k7zumimqCynwlk2zNQZngoA/obH95QDyG/sA8XwyJVL0erLkp5AJmbHgX3RIPsMJHBUbb8Zw0bKaiLeuapjXbvIXZAvNSoGiKteJ0vGtrUdkZJ+KmPCRO+T4MWyRKHFjNnxfFcGz9Y5irWHrQ==" Feb 12 13:45:21 volumio go-librespot[18627]: time="2026-02-12T13:45:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 13:45:21 volumio go-librespot[18627]: time="2026-02-12T13:45:21+07: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 12 13:45:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:45:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:45:21 volumio volumio[18548]: info: Starting UPNP Browser Feb 12 13:45:21 volumio volumio[18548]: info: Loading plugin "alarm-clock"... Feb 12 13:45:22 volumio volumio[18548]: info: Loading plugin "airplay_emulation"... Feb 12 13:45:22 volumio volumio[18548]: info: Starting Shairport Sync Feb 12 13:45:22 volumio volumio[18548]: info: Loading plugin "last_100"... Feb 12 13:45:22 volumio volumio[18548]: info: Loading plugin "webradio"... Feb 12 13:45:22 volumio volumio[18548]: info: Loading plugin "i2s_dacs"... Feb 12 13:45:22 volumio volumio[18548]: info: Loading plugin "volumiodiscovery"... Feb 12 13:45:22 volumio volumio[18548]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 12 13:45:22 volumio volumio[18548]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 13:45:22 volumio node[18548]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 12 13:45:22 volumio volumio[18548]: *** WARNING *** For more information see Feb 12 13:45:22 volumio volumio[18548]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 12 13:45:22 volumio volumio[18548]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 13:45:22 volumio volumio[18548]: *** WARNING *** For more information see Feb 12 13:45:22 volumio node[18548]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 13:45:22 volumio node[18548]: *** WARNING *** For more information see Feb 12 13:45:22 volumio node[18548]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 12 13:45:22 volumio node[18548]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 13:45:22 volumio node[18548]: *** WARNING *** For more information see Feb 12 13:45:22 volumio volumio[18548]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 12 13:45:22 volumio volumio[18548]: info: Discovery: Started advertising with name: Volumio Feb 12 13:45:22 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 13:45:22 volumio volumio[18548]: info: Loading plugin "spop"... Feb 12 13:45:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 12 13:45:24 volumio volumio[18548]: info: Loading plugin "ytcr"... Feb 12 13:45:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:45:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:45:24 volumio go-librespot[18637]: go-librespot daemon starting... Feb 12 13:45:24 volumio go-librespot[18638]: time="2026-02-12T13:45:24+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:45:24 volumio go-librespot[18638]: time="2026-02-12T13:45:24+07:00" level=debug msg="app state loaded" Feb 12 13:45:24 volumio go-librespot[18638]: time="2026-02-12T13:45:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:45:24 volumio go-librespot[18638]: time="2026-02-12T13:45:24+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 13:45:24 volumio go-librespot[18638]: time="2026-02-12T13:45:24+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 13:45:24 volumio go-librespot[18638]: time="2026-02-12T13:45:24+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 13:45:24 volumio go-librespot[18638]: time="2026-02-12T13:45:24+07:00" level=info msg="zeroconf server listening on port 44211" Feb 12 13:45:25 volumio go-librespot[18638]: time="2026-02-12T13:45:25+07:00" level=debug msg="obtained new client token: AAA3KzbGuo7SUsnO8MjnLiE+wz1ghyZXfqVX7vt/i6R2gE5yZtETURblwPF1Ggl/JkJkJBINl9cf336d7CEO/AUcbrrfOeY8DbKoW/uau6mjYBEv1MF+GiR0lCZh8nHYrkZdqY1+F8vuCX9EuumlQ/mhyLzHLf+OH8e7fh2hffiZSJDVDzMRn+/QTk5wnFR2GGXS6l2plgQ/JwRZoUpmqFxJ8pPQYz0kuQSiDp1/ejeuX45EKqbwkes=" Feb 12 13:45:25 volumio go-librespot[18638]: time="2026-02-12T13:45:25+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 12 13:45:25 volumio go-librespot[18638]: time="2026-02-12T13:45:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 12 13:45:25 volumio go-librespot[18638]: time="2026-02-12T13:45:25+07:00" level=debug msg="completed keyexchange" Feb 12 13:45:25 volumio go-librespot[18638]: time="2026-02-12T13:45:25+07:00" level=debug msg="completed challenge" Feb 12 13:45:25 volumio go-librespot[18638]: time="2026-02-12T13:45:25+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 13:45:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:45:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:45:27 volumio volumio[18548]: info: Loading plugin "ytmusic"... Feb 12 13:45:27 volumio volumio-remote-updater[643]: [2026-02-12 13:45:27] [connect] Successful connection Feb 12 13:45:28 volumio volumio[18548]: info: Loading plugin "outputs"... Feb 12 13:45:28 volumio volumio[18548]: info: Loading plugin "albumart"... Feb 12 13:45:28 volumio volumio[18548]: info: Plugin example_plugin is not enabled Feb 12 13:45:28 volumio volumio[18548]: info: Loading plugin "inputs"... Feb 12 13:45:28 volumio volumio[18548]: info: Loading plugin "updater_comm"... Feb 12 13:45:28 volumio volumio[18548]: info: Plugin mpdemulation is not enabled Feb 12 13:45:28 volumio volumio[18548]: info: Loading plugin "rest_api"... Feb 12 13:45:28 volumio volumio[18548]: info: Loading plugin "websocket"... Feb 12 13:45:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 12 13:45:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:45:28 volumio volumio[18548]: info: Starting Socket.io Server version 1.7.4 Feb 12 13:45:28 volumio volumio[18548]: info: Loading plugin "RoonBridge"... Feb 12 13:45:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:45:28 volumio go-librespot[18670]: go-librespot daemon starting... Feb 12 13:45:28 volumio go-librespot[18671]: time="2026-02-12T13:45:28+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:45:28 volumio go-librespot[18671]: time="2026-02-12T13:45:28+07:00" level=debug msg="app state loaded" Feb 12 13:45:28 volumio go-librespot[18671]: time="2026-02-12T13:45:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:45:29 volumio volumio[18548]: info: Applying required configuration parameters for plugin RoonBridge Feb 12 13:45:29 volumio volumio[18548]: info: Loading i18n strings for locale en Feb 12 13:45:29 volumio volumio[18548]: Updating browse sources language Feb 12 13:45:29 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:45:29 volumio go-librespot[18671]: time="2026-02-12T13:45:29+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 12 13:45:29 volumio go-librespot[18671]: time="2026-02-12T13:45:29+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 12 13:45:29 volumio go-librespot[18671]: time="2026-02-12T13:45:29+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 12 13:45:29 volumio volumio[18660]: Forking 3 albumart workers Feb 12 13:45:29 volumio go-librespot[18671]: time="2026-02-12T13:45:29+07:00" level=info msg="zeroconf server listening on port 38215" Feb 12 13:45:29 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 13:45:29 volumio volumio[18548]: info: CoreCommandRouter::initPlayerControls Feb 12 13:45:29 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:45:29 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:45:29 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:45:29 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:45:29 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:45:29 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:45:29 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:45:29 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:45:29 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 13:45:29 volumio volumio[18548]: Express server listening on port 3000 Feb 12 13:45:29 volumio volumio[18548]: [Metrics] WebUI: 16s 132.46ms Feb 12 13:45:29 volumio volumio[18548]: info: CoreStateMachine::resetVolumioState Feb 12 13:45:29 volumio volumio[18548]: info: CoreStateMachine::getcurrentVolume Feb 12 13:45:29 volumio volumio[18548]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 13:45:29 volumio go-librespot[18671]: time="2026-02-12T13:45:29+07:00" level=debug msg="obtained new client token: AAChsKwhxpGWWMtJdxcbem+giuHqN+PQjE3rR6FdNKbHD48R5rfnL5MqyNCJqwjxN+7RQm1V9m6pT4QFtMlIjiR1fGgTys0ss5JwppJuy+8wEtQf3Xllzk1nMdh9bUHmofd0dPmnP+i2hC6NcZUoWGRXM++QD5sqkFisD8+3fk+xEmJqkJLe58kliUSXXmVE+QCHvGvK+ZUH2VVWKl715hOTnUuimS7K8c2CRFyAd8ZinoeanEze3wBeVQ==" Feb 12 13:45:29 volumio go-librespot[18671]: time="2026-02-12T13:45:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 13:45:29 volumio go-librespot[18671]: time="2026-02-12T13:45:29+07: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 12 13:45:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:45:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:45:29 volumio sudo[18712]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 12 13:45:29 volumio sudo[18712]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:45:29 volumio sudo[18715]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 12 13:45:29 volumio sudo[18715]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:45:29 volumio sudo[18715]: pam_unix(sudo:session): session closed for user root Feb 12 13:45:29 volumio sudo[18712]: pam_unix(sudo:session): session closed for user root Feb 12 13:45:29 volumio volumio[18548]: info: Volumio Network Manager: Network status updated: 1 Feb 12 13:45:30 volumio volumio[18548]: info: VolumeController:: Volume=100 Mute =false Feb 12 13:45:30 volumio volumio[18548]: info: CoreStateMachine::pushState Feb 12 13:45:30 volumio volumio[18548]: info: CorePlayQueue::getTrack 0 Feb 12 13:45:30 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 13:45:30 volumio volumio[18548]: info: CoreCommandRouter::volumioPushState Feb 12 13:45:30 volumio volumio[18548]: info: CoreStateMachine::updateTrackBlock Feb 12 13:45:30 volumio volumio[18548]: info: CorePlayQueue::getTrackBlock Feb 12 13:45:30 volumio volumio[18548]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 13:45:30 volumio volumio-remote-updater[643]: [2026-02-12 13:45:30] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770878727 101 Feb 12 13:45:30 volumio volumio[18548]: 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 12 13:45:30 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:45:30 volumio volumio[18548]: info: Reloading queue from file Feb 12 13:45:30 volumio volumio[18548]: info: CoreStateMachine::setRepeat null single undefined Feb 12 13:45:30 volumio volumio[18548]: info: CoreStateMachine::pushState Feb 12 13:45:30 volumio volumio[18548]: info: CorePlayQueue::getTrack 0 Feb 12 13:45:30 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 13:45:30 volumio volumio[18548]: info: CoreCommandRouter::volumioPushState Feb 12 13:45:30 volumio volumio[18548]: info: CoreStateMachine::setRandom null Feb 12 13:45:30 volumio volumio[18548]: info: CoreStateMachine::pushState Feb 12 13:45:30 volumio volumio[18548]: info: CorePlayQueue::getTrack 0 Feb 12 13:45:30 volumio volumio[18548]: info: CoreCommandRouter::volumioPushState Feb 12 13:45:30 volumio volumio[18548]: info: Setting Device type: Raspberry PI Feb 12 13:45:30 volumio volumio[18548]: info: Completed loading Core Plugins Feb 12 13:45:30 volumio volumio[18548]: info: Preparing to generate the ALSA configuration file Feb 12 13:45:30 volumio volumio[18548]: info: VolumeController:: Volume=100 Mute =false Feb 12 13:45:30 volumio volumio[18548]: info: CoreStateMachine::pushState Feb 12 13:45:30 volumio volumio[18548]: info: CorePlayQueue::getTrack 0 Feb 12 13:45:30 volumio volumio[18548]: info: CoreCommandRouter::volumioPushState Feb 12 13:45:30 volumio volumio[18548]: info: Asound.conf file unchanged, so no further update is needed Feb 12 13:45:30 volumio volumio[18548]: info: Output device has changed, restarting MPD Feb 12 13:45:30 volumio sudo[18729]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 12 13:45:30 volumio sudo[18729]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:45:30 volumio volumio[18548]: info: Output device has changed, restarting Shairport Sync Feb 12 13:45:30 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:45:30 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:45:30 volumio sudo[18731]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 13:45:30 volumio sudo[18731]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:45:30 volumio sudo[18729]: pam_unix(sudo:session): session closed for user root Feb 12 13:45:30 volumio sudo[18734]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 13:45:30 volumio sudo[18731]: pam_unix(sudo:session): session closed for user root Feb 12 13:45:30 volumio sudo[18734]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:45:30 volumio volumio[18548]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 13:45:30 volumio volumio[18548]: info: ___________ START PLUGINS ___________ Feb 12 13:45:30 volumio volumio[18548]: info: ControllerMpd::onStart: Initializing MPD Feb 12 13:45:30 volumio volumio[18548]: info: Creating MPD Configuration file Feb 12 13:45:31 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 12 13:45:31 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 13:45:31 volumio volumio[18548]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 13:45:31 volumio volumio[18548]: info: [1770878731066] CoreMusicLibrary::Adding element Media Servers Feb 12 13:45:31 volumio sudo[18742]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 13:45:31 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:45:31 volumio sudo[18742]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:45:31 volumio sudo[18742]: pam_unix(sudo:session): session closed for user root Feb 12 13:45:31 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 12 13:45:31 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 12 13:45:31 volumio systemd[1]: mpd.service: Consumed 7.100s CPU time. Feb 12 13:45:31 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 12 13:45:31 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 12 13:45:31 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 12 13:45:31 volumio volumio[18548]: info: UPNP Browser: Client initialized successfully Feb 12 13:45:31 volumio sudo[18744]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 13:45:31 volumio sudo[18744]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:45:31 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:45:31 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 12 13:45:31 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:45:31 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 12 13:45:31 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 12 13:45:31 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 12 13:45:31 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 12 13:45:31 volumio volumio[18548]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 13:45:31 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 12 13:45:31 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:45:31 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:45:31 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 12 13:45:31 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 12 13:45:31 volumio volumio[18548]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 13:45:31 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 12 13:45:31 volumio volumio[18548]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 13:45:31 volumio volumio[18548]: info: [1770878731457] CoreMusicLibrary::Adding element Last_100 Feb 12 13:45:31 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:45:31 volumio volumio[18548]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 13:45:31 volumio volumio[18548]: info: [1770878731481] CoreMusicLibrary::Adding element Webradio Feb 12 13:45:31 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:45:31 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 13:45:31 volumio volumio[18548]: info: Initializing BBC Radios Feb 12 13:45:31 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 13:45:31 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:45:31 volumio volumio[18548]: info: Creating Spotify config file Feb 12 13:45:31 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:45:31 volumio sudo[18758]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 12 13:45:31 volumio sudo[18758]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 12 13:45:31 volumio sudo[18758]: pam_unix(sudo:session): session closed for user root Feb 12 13:45:32 volumio volumio[18680]: Starting albumart workers Feb 12 13:45:32 volumio volumio[18679]: Starting albumart workers Feb 12 13:45:32 volumio volumio[18678]: Starting albumart workers Feb 12 13:45:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 12 13:45:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:45:32 volumio volumio[18548]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 13:45:32 volumio volumio[18548]: info: [1770878732882] CoreMusicLibrary::Adding element YouTube Music Feb 12 13:45:32 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:45:32 volumio volumio[18548]: Cannot find translation for source YouTube Music Feb 12 13:45:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:45:32 volumio go-librespot[18775]: go-librespot daemon starting... Feb 12 13:45:32 volumio volumio[18548]: info: Volumio Calling Home Feb 12 13:45:32 volumio go-librespot[18776]: time="2026-02-12T13:45:32+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:45:33 volumio sudo[18784]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 12 13:45:33 volumio sudo[18784]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:45:33 volumio sudo[18784]: pam_unix(sudo:session): session closed for user root Feb 12 13:45:33 volumio go-librespot[18776]: time="2026-02-12T13:45:33+07:00" level=info msg="zeroconf server listening on port 43621" Feb 12 13:45:33 volumio volumio[18548]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 12 13:45:33 volumio volumio[18548]: info: Discovery: Found device Volumio Feb 12 13:45:33 volumio volumio[18548]: info: CoreCommandRouter::volumioGetState Feb 12 13:45:33 volumio volumio[18548]: info: CorePlayQueue::getTrack 0 Feb 12 13:45:33 volumio volumio[18548]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 12 13:45:33 volumio volumio[18548]: info: Discovery: Found device Volumio Feb 12 13:45:33 volumio volumio[18548]: info: CoreCommandRouter::volumioGetState Feb 12 13:45:33 volumio volumio[18548]: info: CorePlayQueue::getTrack 0 Feb 12 13:45:33 volumio volumio[18548]: info: MPD Permissions set Feb 12 13:45:33 volumio volumio[18548]: info: MPD Permissions set Feb 12 13:45:33 volumio volumio[18548]: info: Upmpdcli Daemon Started Feb 12 13:45:33 volumio volumio[18548]: info: Spotify config file written Feb 12 13:45:34 volumio volumio[18548]: 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 12 13:45:34 volumio volumio[18548]: info: Volumio called home Feb 12 13:45:34 volumio sudo[18791]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 12 13:45:34 volumio sudo[18791]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:45:34 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:45:34 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:45:34 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:45:34 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:45:34 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:45:34 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:45:34 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:45:34 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:45:34 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:45:34 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:45:34 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:45:34 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:45:34 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:45:34 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:45:34 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:45:34 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:45:34 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:45:34 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:45:34 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 12 13:45:34 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 12 13:45:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:45:34 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 13:45:34 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 13:45:34 volumio volumio[18548]: info: No need to fix Spotify hosts Feb 12 13:45:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:45:34 volumio go-librespot[18802]: go-librespot daemon starting... Feb 12 13:45:34 volumio sudo[18791]: pam_unix(sudo:session): session closed for user root Feb 12 13:45:34 volumio go-librespot[18804]: time="2026-02-12T13:45:34+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:45:34 volumio go-librespot[18804]: time="2026-02-12T13:45:34+07:00" level=debug msg="app state loaded" Feb 12 13:45:34 volumio go-librespot[18804]: time="2026-02-12T13:45:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:45:35 volumio go-librespot[18804]: time="2026-02-12T13:45:35+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 12 13:45:35 volumio go-librespot[18804]: time="2026-02-12T13:45:35+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 12 13:45:35 volumio go-librespot[18804]: time="2026-02-12T13:45:35+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 12 13:45:35 volumio go-librespot[18804]: time="2026-02-12T13:45:35+07:00" level=info msg="zeroconf server listening on port 41623" Feb 12 13:45:35 volumio volumio[18548]: info: Starting Shairport Sync Feb 12 13:45:35 volumio volumio[18548]: info: Starting Shairport Sync Feb 12 13:45:35 volumio volumio[18548]: info: Starting Shairport Sync Feb 12 13:45:35 volumio sudo[18831]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 13:45:35 volumio sudo[18831]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:45:35 volumio go-librespot[18804]: time="2026-02-12T13:45:35+07:00" level=debug msg="obtained new client token: AAAu9JP8DuHgIXAm5uBz/UEcsD2nxg83t1WJc5SZOGHwhXDvRJLWYd1a5/tT8bD27XvXKypauvzuJtyhSKp5LvvTBCtHcPUN7YwAPoZ93ukb7ZQaBJl8ew6wO+eml47mkTP8ccvzyLapplHUEHyy/l3QZQFlKI4AhX83PnsWDB7XB1wJjMM+h+pNpazvJBC2/LwxiZrhULjXutTJRJYKNJmoiEwneIu2HogODAif0FUyIl1/mEonrpAeYg==" Feb 12 13:45:35 volumio sudo[18833]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 13:45:35 volumio sudo[18833]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:45:35 volumio sudo[18836]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 13:45:35 volumio volumio[18548]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 13:45:35 volumio volumio[18548]: SPOTIFY: BQAVLkSATAQE5FZhCaOW1OOVYEvV2ax3FSB6jk-h7oJISP5CB_2E6wlu2ORD8Us3a9z_2wxPPrbYyNux0o0IOXeQUVjxJpOVoBfy3oA2i9A08sLGJA_erJcJkTkeET3gr6ELz2w_Cg_TkeV82vCzWzbuRWXHCWe7c1Elk0JAtZQwg5WMix4hBp43VSfQY9AJ1rPbbXKNhN58AbO0AHGXDC6a1KOPzGziViQn7Zi81Pm4OoI7Csdqnw242b_IYeTlri4idxNG2dPV_kfAd5l05-pmNvupqDblL9fISNV7NBQKPhecB3Xqda6T Feb 12 13:45:35 volumio volumio[18548]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 13:45:35 volumio volumio[18548]: info: New Spotify access token = BQAVLkSATAQE5FZhCaOW1OOVYEvV2ax3FSB6jk-h7oJISP5CB_2E6wlu2ORD8Us3a9z_2wxPPrbYyNux0o0IOXeQUVjxJpOVoBfy3oA2i9A08sLGJA_erJcJkTkeET3gr6ELz2w_Cg_TkeV82vCzWzbuRWXHCWe7c1Elk0JAtZQwg5WMix4hBp43VSfQY9AJ1rPbbXKNhN58AbO0AHGXDC6a1KOPzGziViQn7Zi81Pm4OoI7Csdqnw242b_IYeTlri4idxNG2dPV_kfAd5l05-pmNvupqDblL9fISNV7NBQKPhecB3Xqda6T Feb 12 13:45:35 volumio volumio[18548]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 12 13:45:35 volumio sudo[18836]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:45:35 volumio go-librespot[18804]: time="2026-02-12T13:45:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 13:45:35 volumio go-librespot[18804]: time="2026-02-12T13:45:35+07:00" level=debug msg="completed keyexchange" Feb 12 13:45:35 volumio go-librespot[18804]: time="2026-02-12T13:45:35+07:00" level=debug msg="completed challenge" Feb 12 13:45:35 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 12 13:45:35 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 12 13:45:35 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 13:45:35 volumio systemd[1]: shairport-sync.service: Consumed 2.323s CPU time. Feb 12 13:45:35 volumio go-librespot[18804]: time="2026-02-12T13:45:35+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 13:45:35 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 13:45:35 volumio sudo[18831]: pam_unix(sudo:session): session closed for user root Feb 12 13:45:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:45:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:45:35 volumio sudo[18833]: pam_unix(sudo:session): session closed for user root Feb 12 13:45:35 volumio sudo[18836]: pam_unix(sudo:session): session closed for user root Feb 12 13:45:36 volumio volumio[18548]: info: CoreCommandRouter::volumioGetState Feb 12 13:45:36 volumio volumio[18548]: info: CorePlayQueue::getTrack 0 Feb 12 13:45:36 volumio volumio[18548]: info: Shairport-Sync Started Feb 12 13:45:36 volumio volumio[18548]: Error adding Membership: Error: addMembership EINVAL Feb 12 13:45:36 volumio volumio[18548]: info: Shairport-Sync Started Feb 12 13:45:36 volumio volumio[18548]: info: Shairport-Sync Started Feb 12 13:45:36 volumio volumio[18548]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 12 13:45:36 volumio volumio[18548]: info: Spotify Successfully logged in Feb 12 13:45:36 volumio volumio[18548]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 13:45:36 volumio volumio[18548]: info: [1770878736388] CoreMusicLibrary::Adding element Spotify Feb 12 13:45:36 volumio volumio[18548]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:45:36 volumio volumio[18548]: Cannot find translation for source YouTube Music Feb 12 13:45:36 volumio volumio[18548]: Cannot find translation for source Spotify Feb 12 13:45:37 volumio volumio[18548]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 12 13:45:37 volumio volumio[18548]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 13:45:37 volumio volumio[18548]: info: VolumeController:: Volume=100 Mute =false Feb 12 13:45:37 volumio volumio[18548]: info: CoreCommandRouter::volumioGetState Feb 12 13:45:37 volumio volumio[18548]: info: CorePlayQueue::getTrack 0 Feb 12 13:45:37 volumio volumio[18548]: info: CoreStateMachine::pushState Feb 12 13:45:37 volumio volumio[18548]: info: CorePlayQueue::getTrack 0 Feb 12 13:45:37 volumio volumio[18548]: info: CoreCommandRouter::volumioPushState Feb 12 13:45:38 volumio volumio[18548]: info: go-librespot daemon successfully initialized Feb 12 13:45:39 volumio mpd[18773]: 2026-02-12T13:45:39 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 12 13:45:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 12 13:45:39 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 12 13:45:39 volumio sudo[18734]: pam_unix(sudo:session): session closed for user root Feb 12 13:45:39 volumio sudo[18744]: pam_unix(sudo:session): session closed for user root Feb 12 13:45:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:45:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:45:39 volumio go-librespot[18874]: go-librespot daemon starting... Feb 12 13:45:39 volumio go-librespot[18877]: time="2026-02-12T13:45:39+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:45:39 volumio go-librespot[18877]: time="2026-02-12T13:45:39+07:00" level=debug msg="app state loaded" Feb 12 13:45:39 volumio go-librespot[18877]: time="2026-02-12T13:45:39+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:45:39 volumio volumio[18548]: error: MPD error: The expression evaluated to a falsy value: Feb 12 13:45:39 volumio volumio[18548]: assert.ok(self.idling) Feb 12 13:45:39 volumio volumio[18548]: error: The expression evaluated to a falsy value: Feb 12 13:45:39 volumio volumio[18548]: assert.ok(self.idling) Feb 12 13:45:39 volumio volumio[18548]: error: updateQueue error: null Feb 12 13:45:39 volumio volumio[18548]: info: MPD running with PID18773 Feb 12 13:45:39 volumio volumio[18548]: ,establishing connection Feb 12 13:45:39 volumio volumio[18548]: info: Completed starting Core Plugins Feb 12 13:45:39 volumio volumio[18548]: info: ------------------------------------------- Feb 12 13:45:39 volumio volumio[18548]: info: ----- MyVolumio plugins startup ---- Feb 12 13:45:39 volumio volumio[18548]: info: ------------------------------------------- Feb 12 13:45:39 volumio volumio[18548]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 12 13:45:39 volumio volumio[18548]: error: updateQueue error: null Feb 12 13:45:39 volumio go-librespot[18877]: time="2026-02-12T13:45:39+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 13:45:39 volumio go-librespot[18877]: time="2026-02-12T13:45:39+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 13:45:39 volumio go-librespot[18877]: time="2026-02-12T13:45:39+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 13:45:39 volumio go-librespot[18877]: time="2026-02-12T13:45:39+07:00" level=info msg="zeroconf server listening on port 43725" Feb 12 13:45:39 volumio go-librespot[18877]: time="2026-02-12T13:45:39+07:00" level=debug msg="obtained new client token: AADiv2y99yfHw+2TdlwXsGnyv+0Iloe7Q3gSRmMVkLiHYKKoDBfqLnE+92V7DY4V3/WSzgWPRyx7uBL2zhZXKRca2EfX2QnPM16R/snkU1AhSVjgD6Pee7HQwxiyFrB9OchLnJAYRAlp+i76sJZDxq4xlTa4xi1DMkMWQ9IBJwKnZ2GO0V4idjRl7dv9E1uNB/1htloWRrXeFAClJecsdNvcpSAaDHSqJ4Rft5FgrY2SDYLn6398HS/u6w==" Feb 12 13:45:40 volumio go-librespot[18877]: time="2026-02-12T13:45:40+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 12 13:45:40 volumio go-librespot[18877]: time="2026-02-12T13:45:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 12 13:45:40 volumio go-librespot[18877]: time="2026-02-12T13:45:40+07:00" level=debug msg="completed keyexchange" Feb 12 13:45:40 volumio go-librespot[18877]: time="2026-02-12T13:45:40+07:00" level=debug msg="completed challenge" Feb 12 13:45:40 volumio go-librespot[18877]: time="2026-02-12T13:45:40+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 13:45:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:45:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:45:41 volumio volumio[18548]: info: Initializing connection to go-librespot Websocket Feb 12 13:45:41 volumio volumio[18548]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 13:45:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 12 13:45:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:45:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:45:43 volumio go-librespot[18885]: go-librespot daemon starting... Feb 12 13:45:43 volumio go-librespot[18886]: time="2026-02-12T13:45:43+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:45:43 volumio go-librespot[18886]: time="2026-02-12T13:45:43+07:00" level=debug msg="app state loaded" Feb 12 13:45:43 volumio go-librespot[18886]: time="2026-02-12T13:45:43+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:45:44 volumio volumio[18548]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 12 13:45:44 volumio go-librespot[18886]: time="2026-02-12T13:45:44+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 13:45:44 volumio go-librespot[18886]: time="2026-02-12T13:45:44+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 13:45:44 volumio go-librespot[18886]: time="2026-02-12T13:45:44+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 13:45:44 volumio go-librespot[18886]: time="2026-02-12T13:45:44+07:00" level=info msg="zeroconf server listening on port 36303" Feb 12 13:45:44 volumio volumio[18548]: info: Initializing connection to go-librespot Websocket Feb 12 13:45:44 volumio go-librespot[18886]: time="2026-02-12T13:45:44+07:00" level=debug msg="new websocket client" Feb 12 13:45:44 volumio volumio[18548]: info: Connection to go-librespot Websocket established Feb 12 13:45:44 volumio go-librespot[18886]: time="2026-02-12T13:45:44+07:00" level=debug msg="obtained new client token: AADhUIdV/iuApqWf4bHtTWb761VeUOfqMwrWIalOHOTEfTEjrhKRpVLGd2WFBCilBEdrhTH1AB9T1lkxpU3/o6oQ00V1ZsV1anJwa/DsY1aFZb6OJUT6h8FRUZBWFuupLM2zP2NASQbEgbWHmGGwPlGaM8D0iAERUOK4FiFzoMPxiETYijDhCT9iTVwA+MPJquJwPpJ2AZ9oLdtzlBI1cm7cP0ujUZkRyDg4L1cdRpmY9SGAweuUCo3BAg==" Feb 12 13:45:44 volumio go-librespot[18886]: time="2026-02-12T13:45:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 13:45:44 volumio go-librespot[18886]: time="2026-02-12T13:45:44+07:00" level=debug msg="completed keyexchange" Feb 12 13:45:44 volumio go-librespot[18886]: time="2026-02-12T13:45:44+07:00" level=debug msg="completed challenge" Feb 12 13:45:44 volumio go-librespot[18886]: time="2026-02-12T13:45:44+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 13:45:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:45:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 13:45:44 volumio volumio[18548]: info: Connection to go-librespot Websocket closed Feb 12 13:45:47 volumio volumio[18548]: info: Getting Spotify volume Feb 12 13:45:47 volumio volumio[18548]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 13:45:47 volumio volumio[18548]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 13:45:47 volumio volumio[18548]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 12 13:45:47 volumio volumio[18548]: errno: -111, Feb 12 13:45:47 volumio volumio[18548]: code: 'ECONNREFUSED', Feb 12 13:45:47 volumio volumio[18548]: syscall: 'connect', Feb 12 13:45:47 volumio volumio[18548]: address: '127.0.0.1', Feb 12 13:45:47 volumio volumio[18548]: port: 9879, Feb 12 13:45:47 volumio volumio[18548]: response: undefined Feb 12 13:45:47 volumio volumio[18548]: } Feb 12 13:45:47 volumio volumio[18548]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 13:45:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 12 13:45:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:45:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 13:45:47 volumio go-librespot[18905]: go-librespot daemon starting... Feb 12 13:45:47 volumio go-librespot[18906]: time="2026-02-12T13:45:47+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 13:45:47 volumio go-librespot[18906]: time="2026-02-12T13:45:47+07:00" level=debug msg="app state loaded" Feb 12 13:45:47 volumio go-librespot[18906]: time="2026-02-12T13:45:47+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 13:45:48 volumio go-librespot[18906]: time="2026-02-12T13:45:48+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 13:45:48 volumio go-librespot[18906]: time="2026-02-12T13:45:48+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 13:45:48 volumio go-librespot[18906]: time="2026-02-12T13:45:48+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 13:45:48 volumio go-librespot[18906]: time="2026-02-12T13:45:48+07:00" level=info msg="zeroconf server listening on port 45783" Feb 12 13:45:48 volumio sudo[18929]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-12 13:44' Feb 12 13:45:48 volumio sudo[18929]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:45:48 volumio go-librespot[18906]: time="2026-02-12T13:45:48+07:00" level=debug msg="obtained new client token: AABYjLQYaOWMO7HLdZFFKT1P6aAOedklG11SADgacKRxICYR0RZtJw9xRcWMeRZkbB4S3nWME/0CmETMgrKP/XoFDCbSGMZBaiYWjSetFy3Pp1dF2nardwCJgTQJebhs1QN2TmGqOfcBZvvDM8FBBfk/xvv0jXWIoZWYykCAMN4u1MV1e1625T+B1EyRcD8UeCU1f+d9XkMmpBmZo4I9//S5+YkhQCHbmTwwFB/wkgsmZvbXk9KPTEKraQ==" Feb 12 13:45:48 volumio go-librespot[18906]: time="2026-02-12T13:45:48+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 13:45:49 volumio go-librespot[18906]: time="2026-02-12T13:45:49+07:00" level=debug msg="completed keyexchange" Feb 12 13:45:49 volumio go-librespot[18906]: time="2026-02-12T13:45:49+07:00" level=debug msg="completed challenge" Feb 12 13:45:49 volumio go-librespot[18906]: time="2026-02-12T13:45:49+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 13:45:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 13:45:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. 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="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"