Feb 17 13:43:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50. Feb 17 13:43:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:43:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:43:00 volumio go-librespot[31383]: go-librespot daemon starting... Feb 17 13:43:00 volumio go-librespot[31384]: time="2026-02-17T13:43:00+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 13:43:00 volumio go-librespot[31384]: time="2026-02-17T13:43:00+07:00" level=debug msg="app state loaded" Feb 17 13:43:00 volumio go-librespot[31384]: time="2026-02-17T13:43:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 13:43:01 volumio go-librespot[31384]: time="2026-02-17T13:43: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 13:43:01 volumio go-librespot[31384]: time="2026-02-17T13:43:01+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 17 13:43:01 volumio go-librespot[31384]: time="2026-02-17T13:43:01+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 17 13:43:01 volumio go-librespot[31384]: time="2026-02-17T13:43:01+07:00" level=info msg="zeroconf server listening on port 42977" Feb 17 13:43:01 volumio go-librespot[31384]: time="2026-02-17T13:43:01+07:00" level=debug msg="obtained new client token: AACzx/Y33RborQlWZWdl5iykoqFAnfrwZOV98MH+o+N1JZ4nuzv9oXuDV9W2IYMJUsnCNZw5zpi6JYckviGSKITiANDUeZ3s9ikTzIIY/t5KSF7fox/I97SZ2n8mMck95J+POu6vPEMZfMaPD8i2V9m3yQq+qFLAML7zQmGcJnbq4S9D8MlarG9NsHLlRgTqZ8VqEC/256n0Z2r76rLfApimFD2Suaslk7pBWsnXeVI3dUHPripE+yG4rQ==" Feb 17 13:43:01 volumio go-librespot[31384]: time="2026-02-17T13:43:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 13:43:01 volumio go-librespot[31384]: time="2026-02-17T13:43: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 17 13:43:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 13:43:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 13:43:01 volumio volumio[31303]: info: Loading plugin "ytcr"... Feb 17 13:43:04 volumio volumio[31303]: info: Loading plugin "ytmusic"... Feb 17 13:43:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 51. Feb 17 13:43:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:43:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:43:04 volumio go-librespot[31391]: go-librespot daemon starting... Feb 17 13:43:04 volumio go-librespot[31392]: time="2026-02-17T13:43:04+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 13:43:04 volumio go-librespot[31392]: time="2026-02-17T13:43:04+07:00" level=debug msg="app state loaded" Feb 17 13:43:04 volumio go-librespot[31392]: time="2026-02-17T13:43:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 13:43:05 volumio volumio-remote-updater[25144]: [2026-02-17 13:43:05] [connect] Successful connection Feb 17 13:43:05 volumio go-librespot[31392]: time="2026-02-17T13:43:05+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 17 13:43:05 volumio go-librespot[31392]: time="2026-02-17T13:43:05+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 17 13:43:05 volumio go-librespot[31392]: time="2026-02-17T13:43:05+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 17 13:43:05 volumio go-librespot[31392]: time="2026-02-17T13:43:05+07:00" level=info msg="zeroconf server listening on port 38615" Feb 17 13:43:05 volumio volumio[31303]: info: Loading plugin "outputs"... Feb 17 13:43:05 volumio volumio[31303]: info: Loading plugin "albumart"... Feb 17 13:43:05 volumio volumio[31303]: info: Plugin example_plugin is not enabled Feb 17 13:43:05 volumio volumio[31303]: info: Loading plugin "inputs"... Feb 17 13:43:05 volumio volumio[31303]: info: Loading plugin "updater_comm"... Feb 17 13:43:05 volumio go-librespot[31392]: time="2026-02-17T13:43:05+07:00" level=debug msg="obtained new client token: AACEQSxLxvMYEEalckvvaNNKEC/oPn4CihG86ZliFRpIBMU6+IAHg7WXczonBqE6enkbrLqxNILNAivZCARRFO/PsXZGd1ME+2WSUeXJl2vLKzw7HUfuFdo29K+oPdA4hd2uVRjJ2Q8eOEJeitC1wjCKhL0u3aBZh3+jAVaaqfb1+dl5G/lhKhD19EOpQyHErMGUm1Hsa1oe2o4x8zg8bAh0nkQ5woFuy4RXpX+vSMfjiZKzpzvEKJ8ibQ==" Feb 17 13:43:05 volumio go-librespot[31392]: time="2026-02-17T13:43:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 13:43:05 volumio volumio[31303]: info: Plugin mpdemulation is not enabled Feb 17 13:43:05 volumio volumio[31303]: info: Loading plugin "rest_api"... Feb 17 13:43:05 volumio go-librespot[31392]: time="2026-02-17T13:43:05+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 17 13:43:05 volumio volumio[31303]: info: Loading plugin "websocket"... Feb 17 13:43:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 13:43:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 13:43:05 volumio volumio[31303]: info: Starting Socket.io Server version 1.7.4 Feb 17 13:43:05 volumio volumio[31303]: info: Loading plugin "RoonBridge"... Feb 17 13:43:06 volumio volumio[31303]: info: Applying required configuration parameters for plugin RoonBridge Feb 17 13:43:06 volumio volumio[31303]: info: Loading i18n strings for locale en Feb 17 13:43:06 volumio volumio[31303]: Updating browse sources language Feb 17 13:43:06 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 13:43:06 volumio volumio[31413]: Forking 3 albumart workers Feb 17 13:43:06 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 13:43:06 volumio volumio[31303]: info: CoreCommandRouter::initPlayerControls Feb 17 13:43:06 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:06 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:06 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:06 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:06 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:06 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:06 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:06 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:06 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 13:43:06 volumio volumio[31303]: Express server listening on port 3000 Feb 17 13:43:06 volumio volumio[31303]: [Metrics] WebUI: 15s 976.58ms Feb 17 13:43:06 volumio volumio[31303]: info: CoreStateMachine::resetVolumioState Feb 17 13:43:06 volumio volumio[31303]: info: CoreStateMachine::getcurrentVolume Feb 17 13:43:06 volumio volumio[31303]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 13:43:07 volumio sudo[31457]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 13:43:07 volumio sudo[31457]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:43:07 volumio sudo[31460]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 13:43:07 volumio sudo[31460]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:43:07 volumio sudo[31457]: pam_unix(sudo:session): session closed for user root Feb 17 13:43:07 volumio volumio[31303]: info: Volumio Network Manager: Network status updated: 1 Feb 17 13:43:07 volumio sudo[31460]: pam_unix(sudo:session): session closed for user root Feb 17 13:43:07 volumio volumio[31303]: info: VolumeController:: Volume=100 Mute =false Feb 17 13:43:07 volumio volumio[31303]: info: CoreStateMachine::pushState Feb 17 13:43:07 volumio volumio[31303]: info: CorePlayQueue::getTrack 0 Feb 17 13:43:07 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 13:43:07 volumio volumio[31303]: info: CoreCommandRouter::volumioPushState Feb 17 13:43:07 volumio volumio[31303]: info: CoreStateMachine::updateTrackBlock Feb 17 13:43:07 volumio volumio[31303]: info: CorePlayQueue::getTrackBlock Feb 17 13:43:07 volumio volumio[31303]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 13:43:07 volumio volumio-remote-updater[25144]: [2026-02-17 13:43:07] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771310585 101 Feb 17 13:43:07 volumio volumio[31303]: 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 17 13:43:07 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 13:43:07 volumio volumio[31303]: info: Reloading queue from file Feb 17 13:43:07 volumio volumio[31303]: info: CoreStateMachine::setRepeat null single undefined Feb 17 13:43:07 volumio volumio[31303]: info: CoreStateMachine::pushState Feb 17 13:43:07 volumio volumio[31303]: info: CorePlayQueue::getTrack 0 Feb 17 13:43:07 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 13:43:07 volumio volumio[31303]: info: CoreCommandRouter::volumioPushState Feb 17 13:43:07 volumio volumio[31303]: info: CoreStateMachine::setRandom null Feb 17 13:43:07 volumio volumio[31303]: info: CoreStateMachine::pushState Feb 17 13:43:07 volumio volumio[31303]: info: CorePlayQueue::getTrack 0 Feb 17 13:43:07 volumio volumio[31303]: info: CoreCommandRouter::volumioPushState Feb 17 13:43:07 volumio volumio[31303]: info: Setting Device type: Raspberry PI Feb 17 13:43:07 volumio volumio[31303]: info: Completed loading Core Plugins Feb 17 13:43:07 volumio volumio[31303]: info: Preparing to generate the ALSA configuration file Feb 17 13:43:07 volumio volumio[31303]: info: VolumeController:: Volume=100 Mute =false Feb 17 13:43:07 volumio volumio[31303]: info: CoreStateMachine::pushState Feb 17 13:43:07 volumio volumio[31303]: info: CorePlayQueue::getTrack 0 Feb 17 13:43:07 volumio volumio[31303]: info: CoreCommandRouter::volumioPushState Feb 17 13:43:07 volumio volumio[31303]: info: Asound.conf file unchanged, so no further update is needed Feb 17 13:43:07 volumio volumio[31303]: info: Output device has changed, restarting MPD Feb 17 13:43:07 volumio volumio[31303]: info: Output device has changed, restarting Shairport Sync Feb 17 13:43:07 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:07 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 13:43:07 volumio sudo[31474]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 17 13:43:07 volumio sudo[31474]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:43:07 volumio sudo[31476]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 13:43:07 volumio volumio[31303]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 13:43:07 volumio volumio[31303]: info: ___________ START PLUGINS ___________ Feb 17 13:43:07 volumio sudo[31476]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:43:07 volumio sudo[31476]: pam_unix(sudo:session): session closed for user root Feb 17 13:43:07 volumio sudo[31478]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 13:43:07 volumio sudo[31478]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:43:08 volumio volumio[31303]: info: ControllerMpd::onStart: Initializing MPD Feb 17 13:43:08 volumio volumio[31303]: info: Creating MPD Configuration file Feb 17 13:43:08 volumio sudo[31474]: pam_unix(sudo:session): session closed for user root Feb 17 13:43:08 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 13:43:08 volumio volumio[31303]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 13:43:08 volumio volumio[31303]: info: [1771310588086] CoreMusicLibrary::Adding element Media Servers Feb 17 13:43:08 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 13:43:08 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 17 13:43:08 volumio sudo[31489]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 13:43:08 volumio sudo[31489]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:43:08 volumio volumio[31303]: info: UPNP Browser: Client initialized successfully Feb 17 13:43:08 volumio sudo[31487]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 13:43:08 volumio sudo[31487]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:43:08 volumio sudo[31487]: pam_unix(sudo:session): session closed for user root Feb 17 13:43:08 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 17 13:43:08 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 13:43:08 volumio systemd[1]: mpd.service: Consumed 7.110s CPU time. Feb 17 13:43:08 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 17 13:43:08 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 13:43:08 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 13:43:08 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:08 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 13:43:08 volumio volumio[31303]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 13:43:08 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:08 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 13:43:08 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 13:43:08 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 13:43:08 volumio volumio[31303]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 13:43:08 volumio volumio[31303]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 13:43:08 volumio volumio[31303]: info: [1771310588433] CoreMusicLibrary::Adding element Last_100 Feb 17 13:43:08 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 13:43:08 volumio volumio[31303]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 13:43:08 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 17 13:43:08 volumio volumio[31303]: info: [1771310588494] CoreMusicLibrary::Adding element Webradio Feb 17 13:43:08 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 13:43:08 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 13:43:08 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 17 13:43:08 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 13:43:08 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 13:43:08 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 13:43:08 volumio volumio[31303]: info: Initializing BBC Radios Feb 17 13:43:08 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 13:43:08 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 13:43:08 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 13:43:08 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 13:43:08 volumio volumio[31303]: info: Creating Spotify config file Feb 17 13:43:08 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 52. Feb 17 13:43:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:43:09 volumio sudo[31508]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 17 13:43:09 volumio sudo[31508]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 17 13:43:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:43:09 volumio go-librespot[31520]: go-librespot daemon starting... Feb 17 13:43:09 volumio sudo[31508]: pam_unix(sudo:session): session closed for user root Feb 17 13:43:09 volumio go-librespot[31522]: time="2026-02-17T13:43:09+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 13:43:09 volumio volumio[31425]: Starting albumart workers Feb 17 13:43:10 volumio volumio[31423]: Starting albumart workers Feb 17 13:43:10 volumio go-librespot[31522]: time="2026-02-17T13:43:10+07:00" level=info msg="zeroconf server listening on port 41095" Feb 17 13:43:10 volumio volumio[31424]: Starting albumart workers Feb 17 13:43:10 volumio volumio[31303]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 13:43:10 volumio volumio[31303]: info: [1771310590674] CoreMusicLibrary::Adding element YouTube Music Feb 17 13:43:10 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 13:43:10 volumio volumio[31303]: Cannot find translation for source YouTube Music Feb 17 13:43:10 volumio volumio[31303]: info: Volumio Calling Home Feb 17 13:43:10 volumio sudo[31531]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 17 13:43:10 volumio sudo[31531]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:43:11 volumio sudo[31531]: pam_unix(sudo:session): session closed for user root Feb 17 13:43:11 volumio volumio[31303]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 13:43:11 volumio volumio[31303]: info: Discovery: Found device Volumio Feb 17 13:43:11 volumio volumio[31303]: info: CoreCommandRouter::volumioGetState Feb 17 13:43:11 volumio volumio[31303]: info: CorePlayQueue::getTrack 0 Feb 17 13:43:11 volumio volumio[31303]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 13:43:11 volumio volumio[31303]: info: Discovery: Found device Volumio Feb 17 13:43:11 volumio volumio[31303]: info: CoreCommandRouter::volumioGetState Feb 17 13:43:11 volumio volumio[31303]: info: CorePlayQueue::getTrack 0 Feb 17 13:43:11 volumio volumio[31303]: info: MPD Permissions set Feb 17 13:43:11 volumio volumio[31303]: info: MPD Permissions set Feb 17 13:43:11 volumio volumio[31303]: info: Upmpdcli Daemon Started Feb 17 13:43:11 volumio volumio[31303]: info: Volumio called home Feb 17 13:43:11 volumio volumio[31303]: info: Spotify config file written Feb 17 13:43:11 volumio volumio[31303]: 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 17 13:43:11 volumio sudo[31540]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 17 13:43:11 volumio sudo[31540]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:43:11 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:11 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:11 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:11 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:11 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:11 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:11 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:11 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:11 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 13:43:11 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 17 13:43:11 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:11 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 17 13:43:11 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:11 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:11 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:11 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:11 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:11 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:43:11 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:11 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:43:12 volumio go-librespot[31564]: go-librespot daemon starting... Feb 17 13:43:12 volumio sudo[31540]: pam_unix(sudo:session): session closed for user root Feb 17 13:43:12 volumio go-librespot[31565]: time="2026-02-17T13:43:12+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 13:43:12 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 13:43:12 volumio go-librespot[31565]: time="2026-02-17T13:43:12+07:00" level=debug msg="app state loaded" Feb 17 13:43:12 volumio go-librespot[31565]: time="2026-02-17T13:43:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 13:43:12 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:12 volumio volumio[31303]: info: No need to fix Spotify hosts Feb 17 13:43:12 volumio go-librespot[31565]: time="2026-02-17T13:43: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 13:43:12 volumio go-librespot[31565]: time="2026-02-17T13:43:12+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 17 13:43:12 volumio go-librespot[31565]: time="2026-02-17T13:43:12+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 17 13:43:12 volumio go-librespot[31565]: time="2026-02-17T13:43:12+07:00" level=info msg="zeroconf server listening on port 37765" Feb 17 13:43:12 volumio volumio[31303]: info: Starting Shairport Sync Feb 17 13:43:12 volumio go-librespot[31565]: time="2026-02-17T13:43:12+07:00" level=debug msg="obtained new client token: AACmVbiIqCgDFZShrFDVI+bO0cgIvSAykB3FuU0E7NwNiFA9HzkinVNgIahMDb2W4N8bz2XstXuL1fiKZwn6u31zwu6vCzbJhp2ZrRxxl1M3fhWExEWhszqf+d9v6Pp5wEI9iCXkXK3zLJZtqeChDXqT/QDb7rV8EEkIcMGVm2Mh8EtdPuk86NfBjUI0mQTXf/aKGDkqcFI74psTyErI5xJtlpntxW33qih4A88aBe8oHkFiPQHRunNwRA==" Feb 17 13:43:12 volumio volumio[31303]: info: Starting Shairport Sync Feb 17 13:43:13 volumio volumio[31303]: info: Starting Shairport Sync Feb 17 13:43:13 volumio go-librespot[31565]: time="2026-02-17T13:43:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 13:43:13 volumio sudo[31578]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 13:43:13 volumio sudo[31578]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:43:13 volumio sudo[31580]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 13:43:13 volumio sudo[31580]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:43:13 volumio sudo[31576]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 13:43:13 volumio sudo[31576]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:43:13 volumio go-librespot[31565]: time="2026-02-17T13:43:13+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 17 13:43:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 13:43:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 13:43:13 volumio volumio[31303]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 13:43:13 volumio volumio[31303]: SPOTIFY: BQBCOZBo6niPca3EVVVLsngbbdxHwfSSK42TXqp-w83oEI2rG0b5IqVwepy2QkuJNQZBYsYGlZek4AF6_4COEFiQgdY5By-BIYNwtWOJM8RvFr-BnhVkp3K-pm-X1cV4U2gYHR9P9co8mCLuc1Nss8DF9OzjEwOpMlP3c9BPoZxrKO4sg312BczZqm_TUKFCHUYrl-_j_hSzBDHIMY8mwvDVq42Kro1Sw2-UWp3hClF6JEIPGh4yIEeRWT_velwM8LQynkI9F70XkYabhsGYli3kpc7_RZqm0JKW78kw_5CdpA7WWrcm3XjN Feb 17 13:43:13 volumio volumio[31303]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 13:43:13 volumio volumio[31303]: info: New Spotify access token = BQBCOZBo6niPca3EVVVLsngbbdxHwfSSK42TXqp-w83oEI2rG0b5IqVwepy2QkuJNQZBYsYGlZek4AF6_4COEFiQgdY5By-BIYNwtWOJM8RvFr-BnhVkp3K-pm-X1cV4U2gYHR9P9co8mCLuc1Nss8DF9OzjEwOpMlP3c9BPoZxrKO4sg312BczZqm_TUKFCHUYrl-_j_hSzBDHIMY8mwvDVq42Kro1Sw2-UWp3hClF6JEIPGh4yIEeRWT_velwM8LQynkI9F70XkYabhsGYli3kpc7_RZqm0JKW78kw_5CdpA7WWrcm3XjN Feb 17 13:43:13 volumio volumio[31303]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 17 13:43:13 volumio volumio[31303]: info: CoreCommandRouter::volumioGetState Feb 17 13:43:13 volumio volumio[31303]: info: CorePlayQueue::getTrack 0 Feb 17 13:43:13 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 17 13:43:13 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 17 13:43:13 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 13:43:13 volumio systemd[1]: shairport-sync.service: Consumed 2.316s CPU time. Feb 17 13:43:13 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 13:43:13 volumio sudo[31576]: pam_unix(sudo:session): session closed for user root Feb 17 13:43:13 volumio sudo[31580]: pam_unix(sudo:session): session closed for user root Feb 17 13:43:13 volumio sudo[31578]: pam_unix(sudo:session): session closed for user root Feb 17 13:43:13 volumio volumio[31303]: info: Shairport-Sync Started Feb 17 13:43:13 volumio volumio[31303]: Error adding Membership: Error: addMembership EINVAL Feb 17 13:43:13 volumio volumio[31303]: info: Shairport-Sync Started Feb 17 13:43:13 volumio volumio[31303]: info: Shairport-Sync Started Feb 17 13:43:13 volumio volumio[31303]: 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 17 13:43:13 volumio volumio[31303]: info: Spotify Successfully logged in Feb 17 13:43:13 volumio volumio[31303]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 13:43:13 volumio volumio[31303]: info: [1771310593836] CoreMusicLibrary::Adding element Spotify Feb 17 13:43:13 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 13:43:13 volumio volumio[31303]: Cannot find translation for source YouTube Music Feb 17 13:43:13 volumio volumio[31303]: Cannot find translation for source Spotify Feb 17 13:43:14 volumio volumio[31303]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 17 13:43:14 volumio volumio[31303]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 13:43:14 volumio volumio[31303]: info: VolumeController:: Volume=100 Mute =false Feb 17 13:43:14 volumio volumio[31303]: info: CoreCommandRouter::volumioGetState Feb 17 13:43:14 volumio volumio[31303]: info: CorePlayQueue::getTrack 0 Feb 17 13:43:14 volumio volumio[31303]: info: CoreStateMachine::pushState Feb 17 13:43:14 volumio volumio[31303]: info: CorePlayQueue::getTrack 0 Feb 17 13:43:14 volumio volumio[31303]: info: CoreCommandRouter::volumioPushState Feb 17 13:43:15 volumio volumio[31303]: info: go-librespot daemon successfully initialized Feb 17 13:43:15 volumio mpd[31528]: 2026-02-17T13:43:15 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 17 13:43:15 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 17 13:43:15 volumio sudo[31478]: pam_unix(sudo:session): session closed for user root Feb 17 13:43:15 volumio sudo[31489]: pam_unix(sudo:session): session closed for user root Feb 17 13:43:16 volumio volumio[31303]: error: MPD error: The expression evaluated to a falsy value: Feb 17 13:43:16 volumio volumio[31303]: assert.ok(self.idling) Feb 17 13:43:16 volumio volumio[31303]: error: The expression evaluated to a falsy value: Feb 17 13:43:16 volumio volumio[31303]: assert.ok(self.idling) Feb 17 13:43:16 volumio volumio[31303]: error: updateQueue error: null Feb 17 13:43:16 volumio volumio[31303]: info: MPD running with PID31528 Feb 17 13:43:16 volumio volumio[31303]: ,establishing connection Feb 17 13:43:16 volumio volumio[31303]: info: Completed starting Core Plugins Feb 17 13:43:16 volumio volumio[31303]: info: ------------------------------------------- Feb 17 13:43:16 volumio volumio[31303]: info: ----- MyVolumio plugins startup ---- Feb 17 13:43:16 volumio volumio[31303]: info: ------------------------------------------- Feb 17 13:43:16 volumio volumio[31303]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 17 13:43:16 volumio volumio[31303]: error: updateQueue error: null Feb 17 13:43:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 17 13:43:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:43:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:43:16 volumio go-librespot[31621]: go-librespot daemon starting... Feb 17 13:43:16 volumio go-librespot[31622]: time="2026-02-17T13:43:16+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 13:43:16 volumio go-librespot[31622]: time="2026-02-17T13:43:16+07:00" level=debug msg="app state loaded" Feb 17 13:43:16 volumio go-librespot[31622]: time="2026-02-17T13:43:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 13:43:16 volumio go-librespot[31622]: time="2026-02-17T13:43: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 13:43:16 volumio go-librespot[31622]: time="2026-02-17T13:43:16+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 17 13:43:16 volumio go-librespot[31622]: time="2026-02-17T13:43:16+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 17 13:43:16 volumio go-librespot[31622]: time="2026-02-17T13:43:16+07:00" level=info msg="zeroconf server listening on port 45859" Feb 17 13:43:17 volumio go-librespot[31622]: time="2026-02-17T13:43:17+07:00" level=debug msg="obtained new client token: AABGYwG23dCiZyRcpFUKIVi2NbRPkr5VEqT9khkrBMLlhrfRlpx9mdzWjnyySAef3gvOltXIELOY4ExNkupvWCvAkkdi+F+lIsjXrd4HwnIdsLfZz0/E1K7dqmi+K3T8eLCe1NZGDNVwS982JFXi0b0h7OyCtvJ4+6q7fvrYXJVIEmlWvS1U9jIuAp5ViDP42GXYoAvWbGowGPtJZcAedIYNs9TNrJjFl2rTVdrkaGuqnweGmd2lDn8=" Feb 17 13:43:17 volumio go-librespot[31622]: time="2026-02-17T13:43:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 13:43:17 volumio go-librespot[31622]: time="2026-02-17T13:43:17+07:00" level=debug msg="completed keyexchange" Feb 17 13:43:17 volumio go-librespot[31622]: time="2026-02-17T13:43:17+07:00" level=debug msg="completed challenge" Feb 17 13:43:17 volumio go-librespot[31622]: time="2026-02-17T13:43:17+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 17 13:43:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 13:43:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 13:43:18 volumio volumio[31303]: info: Initializing connection to go-librespot Websocket Feb 17 13:43:18 volumio volumio[31303]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 13:43:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 17 13:43:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:43:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:43:20 volumio go-librespot[31630]: go-librespot daemon starting... Feb 17 13:43:20 volumio go-librespot[31631]: time="2026-02-17T13:43:20+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 13:43:20 volumio go-librespot[31631]: time="2026-02-17T13:43:20+07:00" level=debug msg="app state loaded" Feb 17 13:43:20 volumio go-librespot[31631]: time="2026-02-17T13:43:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 13:43:21 volumio volumio[31303]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 17 13:43:21 volumio go-librespot[31631]: time="2026-02-17T13:43:21+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 17 13:43:21 volumio go-librespot[31631]: time="2026-02-17T13:43:21+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 17 13:43:21 volumio go-librespot[31631]: time="2026-02-17T13:43:21+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 17 13:43:21 volumio go-librespot[31631]: time="2026-02-17T13:43:21+07:00" level=info msg="zeroconf server listening on port 44839" Feb 17 13:43:21 volumio go-librespot[31631]: time="2026-02-17T13:43:21+07:00" level=debug msg="obtained new client token: AABvtwffUys7JH+c99V8l5E9h6i93dDfUciV0jjESoK8h8qxo/m+CCx2svmsEDDevCLBBNZGhXEi8VYGV3v3Uu0Y6DfbK+ggqxJTHBp3MkvUkUilNKOwriPa6pf2Xdpi+HNlExgLqFM1OaMiM+gcGQuCsA6N96NQ98hfBeszOfaF3c2KLtfcQmEgUxIDqil4dQzl6teYcJ3vmWza2UkcDyWniMzTS/C5v/lU7M8OrBwVQahvXpm1mC/4Eg==" Feb 17 13:43:21 volumio go-librespot[31631]: time="2026-02-17T13:43:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 13:43:21 volumio go-librespot[31631]: time="2026-02-17T13:43: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 17 13:43:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 13:43:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 13:43:21 volumio volumio[31303]: info: Initializing connection to go-librespot Websocket Feb 17 13:43:21 volumio volumio[31303]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 13:43:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 17 13:43:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:43:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:43:24 volumio go-librespot[31638]: go-librespot daemon starting... Feb 17 13:43:24 volumio go-librespot[31639]: time="2026-02-17T13:43:24+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 13:43:24 volumio go-librespot[31639]: time="2026-02-17T13:43:24+07:00" level=debug msg="app state loaded" Feb 17 13:43:24 volumio go-librespot[31639]: time="2026-02-17T13:43:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 13:43:24 volumio volumio[31303]: info: Initializing connection to go-librespot Websocket Feb 17 13:43:24 volumio go-librespot[31639]: time="2026-02-17T13:43:24+07:00" level=debug msg="new websocket client" Feb 17 13:43:24 volumio volumio[31303]: info: Connection to go-librespot Websocket established Feb 17 13:43:25 volumio volumio[31303]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 17 13:43:25 volumio volumio[31303]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 17 13:43:25 volumio volumio[31303]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 17 13:43:25 volumio volumio[31303]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 17 13:43:25 volumio volumio[31303]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 17 13:43:25 volumio volumio[31303]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 17 13:43:25 volumio volumio[31303]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 17 13:43:25 volumio volumio[31303]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 17 13:43:25 volumio volumio[31303]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 17 13:43:25 volumio volumio[31303]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 17 13:43:25 volumio volumio[31303]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 17 13:43:25 volumio volumio[31303]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 17 13:43:25 volumio volumio[31303]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 17 13:43:25 volumio volumio[31303]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 17 13:43:25 volumio volumio[31303]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 17 13:43:25 volumio volumio[31303]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 17 13:43:25 volumio volumio[31303]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 17 13:43:25 volumio volumio[31303]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 17 13:43:25 volumio volumio[31303]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 17 13:43:25 volumio volumio[31303]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 17 13:43:25 volumio volumio[31303]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 17 13:43:25 volumio volumio[31303]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 17 13:43:25 volumio volumio[31303]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 17 13:43:25 volumio volumio[31303]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 17 13:43:25 volumio volumio[31303]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 17 13:43:25 volumio volumio[31303]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 17 13:43:25 volumio volumio[31303]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 17 13:43:25 volumio volumio[31303]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 17 13:43:25 volumio volumio[31303]: info: Adding plugin bluetooth to MyMusic Plugins Feb 17 13:43:25 volumio volumio[31303]: info: Adding plugin multiroom to MyMusic Plugins Feb 17 13:43:25 volumio volumio[31303]: info: Adding plugin metavolumio to MyMusic Plugins Feb 17 13:43:25 volumio volumio[31303]: info: Adding plugin cd_controller to MyMusic Plugins Feb 17 13:43:25 volumio volumio[31303]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 17 13:43:25 volumio volumio[31303]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 17 13:43:25 volumio volumio[31303]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 17 13:43:25 volumio volumio[31303]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 17 13:43:25 volumio go-librespot[31639]: time="2026-02-17T13:43:25+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 17 13:43:25 volumio go-librespot[31639]: time="2026-02-17T13:43:25+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 17 13:43:25 volumio go-librespot[31639]: time="2026-02-17T13:43:25+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 17 13:43:25 volumio go-librespot[31639]: time="2026-02-17T13:43:25+07:00" level=info msg="zeroconf server listening on port 36387" Feb 17 13:43:25 volumio go-librespot[31639]: time="2026-02-17T13:43:25+07:00" level=debug msg="obtained new client token: AABrOKq/lViFTTm9hu+W0PAnjYpjwYiDhmkG1f5GfhDaOejKxqMDPWQ9EvSZhnA34NmFmAu5jYp+Xq0KpDzlrp2Gei0FZa9ZdiUzvcW2/jL0QlBqyzvz026AbD6m11eCv6dTcTFuqpWmXnAFwIB4msRvnF6qLa7PjCQn0fImlP/RZhOSPvm2QvTWJqtliNthhOcbvbpuCjNJMEBdmW8Ho2tnLEuLwPiwdomQOnXrxNnPRXwyxXTTy8vyyw==" Feb 17 13:43:25 volumio go-librespot[31639]: time="2026-02-17T13:43: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 17 13:43:25 volumio go-librespot[31639]: time="2026-02-17T13:43:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 17 13:43:25 volumio go-librespot[31639]: time="2026-02-17T13:43:25+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 17 13:43:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 13:43:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 13:43:26 volumio volumio[31303]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 17 13:43:26 volumio volumio[31303]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 17 13:43:26 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 13:43:26 volumio volumio[31303]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 13:43:26 volumio volumio[31303]: info: Starting MyVolumio Remote Streaming Endpoints Feb 17 13:43:27 volumio volumio[31303]: info: MyVolumio login type: Token Feb 17 13:43:27 volumio volumio[31303]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 17 13:43:27 volumio volumio[31303]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 17 13:43:28 volumio volumio[31303]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 17 13:43:28 volumio volumio[31303]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 17 13:43:28 volumio volumio[31303]: info: Streaming services startup Feb 17 13:43:28 volumio volumio[31303]: info: Starting Streaming Daemon Feb 17 13:43:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 17 13:43:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:43:28 volumio volumio[31303]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 17 13:43:28 volumio sudo[31661]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 17 13:43:28 volumio sudo[31661]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:43:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:43:28 volumio go-librespot[31663]: go-librespot daemon starting... Feb 17 13:43:28 volumio go-librespot[31668]: time="2026-02-17T13:43:28+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 13:43:28 volumio go-librespot[31668]: time="2026-02-17T13:43:28+07:00" level=debug msg="app state loaded" Feb 17 13:43:28 volumio go-librespot[31668]: time="2026-02-17T13:43:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 13:43:28 volumio sudo[31661]: pam_unix(sudo:session): session closed for user root Feb 17 13:43:29 volumio volumio[31303]: info: Getting Spotify volume Feb 17 13:43:29 volumio volumio[31303]: info: Connection to go-librespot Websocket closed Feb 17 13:43:29 volumio volumio[31303]: error: Cannot start Volumio Streaming Daemon Feb 17 13:43:29 volumio volumio[31303]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 17 13:43:29 volumio volumio[31303]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 17 13:43:29 volumio volumio[31303]: 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 17 13:43:29 volumio volumio[31303]: info: CoreCommandRouter::volumioGetState Feb 17 13:43:29 volumio volumio[31303]: info: CorePlayQueue::getTrack 0 Feb 17 13:43:29 volumio volumio[31303]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 17 13:43:29 volumio volumio[31303]: SPOTIFY: SPOTIFY VOLUME undefined Feb 17 13:43:29 volumio volumio[31303]: SPOTIFY: VOLUMIO VOLUME 100 Feb 17 13:43:29 volumio volumio[31303]: info: Aligning Spotify Volume to Volumio Volume Feb 17 13:43:29 volumio volumio[31303]: info: CoreCommandRouter::volumioGetState Feb 17 13:43:29 volumio volumio[31303]: info: CorePlayQueue::getTrack 0 Feb 17 13:43:29 volumio volumio[31303]: info: Setting Spotify Volume from Volumio: 100 Feb 17 13:43:29 volumio go-librespot[31668]: time="2026-02-17T13:43: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-gew4.spotify.com:80]" Feb 17 13:43:29 volumio go-librespot[31668]: time="2026-02-17T13:43:29+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 17 13:43:29 volumio go-librespot[31668]: time="2026-02-17T13:43:29+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 17 13:43:29 volumio go-librespot[31668]: time="2026-02-17T13:43:29+07:00" level=info msg="zeroconf server listening on port 42195" Feb 17 13:43:29 volumio go-librespot[31668]: time="2026-02-17T13:43:29+07:00" level=debug msg="obtained new client token: AACw01CUsn2xDfUYa9aThL6rFjunhoLXiG8b9J2xsbEB4asg9+LsNC3Xa0JJZw+g9XCNzbaJOPiPWGO+1aZHjJzf91dKnQZFgVo56QtezPodr9BkBj0fCVJbg3W2g4s4hgEKUAenvkZLq/pqSdxezEcLYAHsXZrWMKJmWmYIArgg60aKGiRFW3CaNG3WCLo5nbNhpEZ8jvlyjEncPXdAMXaYk6wnqrlh9HSRpFBHDHFGrahfS24awr4hFQ==" Feb 17 13:43:29 volumio go-librespot[31668]: time="2026-02-17T13:43:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 13:43:29 volumio go-librespot[31668]: time="2026-02-17T13:43: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 17 13:43:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 13:43:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 13:43:29 volumio volumio[31303]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 13:43:29 volumio volumio[31303]: Error: socket hang up Feb 17 13:43:29 volumio volumio[31303]: at connResetException (node:internal/errors:720:14) Feb 17 13:43:29 volumio volumio[31303]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 17 13:43:29 volumio volumio[31303]: at Socket.emit (node:events:526:35) Feb 17 13:43:29 volumio volumio[31303]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 17 13:43:29 volumio volumio[31303]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 17 13:43:29 volumio volumio[31303]: code: 'ECONNRESET', Feb 17 13:43:29 volumio volumio[31303]: response: undefined Feb 17 13:43:29 volumio volumio[31303]: } Feb 17 13:43:29 volumio volumio[31303]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 13:43:31 volumio sudo[31689]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-17 13:42' Feb 17 13:43:31 volumio sudo[31689]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:43:31 volumio sudo[31689]: pam_unix(sudo:session): session closed for user root Feb 17 13:43:31 volumio volumio-remote-updater[25144]: [2026-02-17 13:43:31] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 17 13:43:31 volumio volumio-remote-updater[25144]: [2026-02-17 13:43:31] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 17 13:43:31 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 17 13:43:31 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 17 13:43:31 volumio systemd[1]: volumio.service: Consumed 55.590s CPU time. Feb 17 13:43:31 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 17 13:43:31 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 20438. Feb 17 13:43:31 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 17 13:43:31 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 17 13:43:31 volumio systemd[1]: volumio.service: Consumed 55.590s CPU time. Feb 17 13:43:31 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 17 13:43:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 17 13:43:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:43:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:43:33 volumio go-librespot[31710]: go-librespot daemon starting... Feb 17 13:43:33 volumio go-librespot[31711]: time="2026-02-17T13:43:33+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 13:43:33 volumio go-librespot[31711]: time="2026-02-17T13:43:33+07:00" level=debug msg="app state loaded" Feb 17 13:43:33 volumio go-librespot[31711]: time="2026-02-17T13:43:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 13:43:33 volumio go-librespot[31711]: time="2026-02-17T13:43:33+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 17 13:43:33 volumio go-librespot[31711]: time="2026-02-17T13:43:33+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 17 13:43:33 volumio go-librespot[31711]: time="2026-02-17T13:43:33+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 17 13:43:33 volumio go-librespot[31711]: time="2026-02-17T13:43:33+07:00" level=info msg="zeroconf server listening on port 42651" Feb 17 13:43:33 volumio go-librespot[31711]: time="2026-02-17T13:43:33+07:00" level=debug msg="obtained new client token: AAARd6nP1VgHupELfhck1dbiXiH/MZK0UKmsvhaAGH6z3elA8dS7I1OrRelSqft5y/IaLf09k3XMX/6lCxx4JeMYmF4TEPnmyDmemiye4NBOxIY8V4LWXdCc7EYM40/2bxty3NDJ3ryKoQXIvATan6FZ8vVUawomCdq270BG5o4TiT3zy5VXeGB4wEoXIan81XA2pISNQTkm5z2C+MLKbE+dnQI/ycMfycg3AXDpkZq0FB9bMTNJSrVjkg==" Feb 17 13:43:34 volumio go-librespot[31711]: time="2026-02-17T13:43:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 13:43:34 volumio go-librespot[31711]: time="2026-02-17T13:43:34+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 17 13:43:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 13:43:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 13:43:35 volumio volumio[31700]: info: ------------------------------------------- Feb 17 13:43:35 volumio volumio[31700]: info: ----- Volumio3 ---- Feb 17 13:43:35 volumio volumio[31700]: info: ------------------------------------------- Feb 17 13:43:35 volumio volumio[31700]: info: ----- System startup ---- Feb 17 13:43:35 volumio volumio[31700]: info: ------------------------------------------- Feb 17 13:43:36 volumio volumio-remote-updater[25144]: [2026-02-17 13:43:36] [connect] Successful connection Feb 17 13:43:36 volumio volumio[31700]: info: MYVOLUMIO Environment detected Feb 17 13:43:37 volumio volumio[31700]: info: Plugin folders cleanup Feb 17 13:43:37 volumio volumio[31700]: info: Scanning into folder /volumio/app/plugins/ Feb 17 13:43:37 volumio volumio[31700]: info: Scanning category audio_interface Feb 17 13:43:37 volumio volumio[31700]: info: Scanning category miscellanea Feb 17 13:43:37 volumio volumio[31700]: info: Scanning category music_service Feb 17 13:43:37 volumio volumio[31700]: info: Scanning category plugins.json Feb 17 13:43:37 volumio volumio[31700]: info: Scanning category system_controller Feb 17 13:43:37 volumio volumio[31700]: info: Scanning category user_interface Feb 17 13:43:37 volumio volumio[31700]: info: Scanning into folder /data/plugins/ Feb 17 13:43:37 volumio volumio[31700]: info: Scanning category music_service Feb 17 13:43:37 volumio volumio[31700]: info: Plugin folders cleanup completed Feb 17 13:43:37 volumio volumio[31700]: info: ------------------------------------------- Feb 17 13:43:37 volumio volumio[31700]: info: ----- Core plugins startup ---- Feb 17 13:43:37 volumio volumio[31700]: info: ------------------------------------------- Feb 17 13:43:37 volumio volumio[31700]: info: Loading plugins from folder /volumio/app/plugins/ Feb 17 13:43:37 volumio volumio[31700]: info: Adding plugin upnp to MyMusic Plugins Feb 17 13:43:37 volumio volumio[31700]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 17 13:43:37 volumio volumio[31700]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 17 13:43:37 volumio volumio[31700]: info: Loading plugins from folder /data/plugins/ Feb 17 13:43:37 volumio volumio[31700]: info: Loading plugin "system"... Feb 17 13:43:37 volumio volumio[31700]: info: Loading plugin "appearance"... Feb 17 13:43:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 17 13:43:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:43:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:43:37 volumio go-librespot[31731]: go-librespot daemon starting... Feb 17 13:43:37 volumio go-librespot[31732]: time="2026-02-17T13:43:37+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 13:43:37 volumio go-librespot[31732]: time="2026-02-17T13:43:37+07:00" level=debug msg="app state loaded" Feb 17 13:43:37 volumio go-librespot[31732]: time="2026-02-17T13:43:37+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 13:43:37 volumio go-librespot[31732]: time="2026-02-17T13:43:37+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 17 13:43:37 volumio go-librespot[31732]: time="2026-02-17T13:43:37+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 17 13:43:37 volumio go-librespot[31732]: time="2026-02-17T13:43:37+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 17 13:43:37 volumio go-librespot[31732]: time="2026-02-17T13:43:37+07:00" level=info msg="zeroconf server listening on port 35553" Feb 17 13:43:38 volumio go-librespot[31732]: time="2026-02-17T13:43:38+07:00" level=debug msg="obtained new client token: AAAe6mgQOLEPPIAzs0mUmtEYd8npKWGVVFxC1xSCBemvran2CKHHUx9RPg8v8Flaer4ZqtXMYTlgkweBN22GVdNoYi3mYV8n1GFe74Aiq9DnDpHSfebeJsMoh4XlKy9KzWtLiRgU4hhBuoMkFvJB71NOgSb3o98lGnOIjXpLlSABYWHLjTsB3sBZOs531enCl8sCMTxqTOQqrteViUIL1qazIH6GIqmUsrzlQyr02fKXGAsUjHTNBxk=" Feb 17 13:43:38 volumio go-librespot[31732]: time="2026-02-17T13:43:38+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 13:43:38 volumio go-librespot[31732]: time="2026-02-17T13:43:38+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 17 13:43:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 13:43:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 13:43:39 volumio volumio[31700]: info: Loading plugin "network"... Feb 17 13:43:39 volumio volumio[31700]: info: Refreshing Cached IP Addresses Feb 17 13:43:39 volumio sudo[31741]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 13:43:39 volumio sudo[31741]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:43:39 volumio volumio[31700]: info: Loading plugin "services"... Feb 17 13:43:39 volumio sudo[31743]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 13:43:39 volumio sudo[31741]: pam_unix(sudo:session): session closed for user root Feb 17 13:43:39 volumio sudo[31743]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:43:39 volumio volumio[31700]: info: Loading plugin "alsa_controller"... Feb 17 13:43:39 volumio sudo[31743]: pam_unix(sudo:session): session closed for user root Feb 17 13:43:39 volumio sudo[31751]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 17 13:43:39 volumio sudo[31751]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:43:39 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 13:43:39 volumio volumio[31700]: info: Loading plugin "wizard"... Feb 17 13:43:39 volumio volumio[31700]: info: Loading plugin "networkfs"... Feb 17 13:43:39 volumio volumio[31700]: info: Starting Udev Watcher for removable devices Feb 17 13:43:39 volumio volumio[31700]: info: Ignoring mount for partition: boot Feb 17 13:43:39 volumio volumio[31700]: info: Ignoring mount for partition: volumio Feb 17 13:43:39 volumio volumio[31700]: info: Ignoring mount for partition: volumio_data Feb 17 13:43:39 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 13:43:39 volumio volumio[31700]: info: Loading plugin "volumio_command_line_client"... Feb 17 13:43:39 volumio volumio[31700]: info: Loading plugin "upnp"... Feb 17 13:43:39 volumio volumio[31700]: info: [1771310619609] Starting Upmpd Daemon Feb 17 13:43:39 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 13:43:39 volumio volumio[31700]: info: Loading plugin "my_music"... Feb 17 13:43:39 volumio volumio[31700]: info: Loading plugin "mpd"... Feb 17 13:43:40 volumio volumio[31700]: info: Loading plugin "upnp_browser"... Feb 17 13:43:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 17 13:43:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:43:41 volumio go-librespot[31774]: go-librespot daemon starting... Feb 17 13:43:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:43:41 volumio go-librespot[31775]: time="2026-02-17T13:43:41+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 13:43:41 volumio go-librespot[31775]: time="2026-02-17T13:43:41+07:00" level=debug msg="app state loaded" Feb 17 13:43:41 volumio go-librespot[31775]: time="2026-02-17T13:43:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 13:43:42 volumio sudo[31751]: pam_unix(sudo:session): session closed for user root Feb 17 13:43:42 volumio go-librespot[31775]: time="2026-02-17T13:43:42+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 17 13:43:42 volumio go-librespot[31775]: time="2026-02-17T13:43:42+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 17 13:43:42 volumio go-librespot[31775]: time="2026-02-17T13:43:42+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 17 13:43:42 volumio go-librespot[31775]: time="2026-02-17T13:43:42+07:00" level=info msg="zeroconf server listening on port 45215" Feb 17 13:43:42 volumio go-librespot[31775]: time="2026-02-17T13:43:42+07:00" level=debug msg="obtained new client token: AABPIyE3XD3k4cYgmH6xvTCordt12Kl8M/jIV7oJVT2+Kq1cGgjgIyTxjz10y8HKUjIY+F2kiB6WH3rq2MuyjcbwGEP5ZqHjqafBwuhgjGz3utUWpLxix0O4MjK3ExMjLjILqbEWTmqkROZ7fv9/yRjHBIY8GOkbV/2BeGIO2+NXR200lqORcMZZmq/BiHgyeiovdoDouY7pWHOTPsnRmguFM63BlfqyMsv/O64c4DARWpNS0uePousKoQ==" Feb 17 13:43:42 volumio go-librespot[31775]: time="2026-02-17T13:43:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 13:43:42 volumio go-librespot[31775]: time="2026-02-17T13:43:42+07:00" level=debug msg="completed keyexchange" Feb 17 13:43:42 volumio go-librespot[31775]: time="2026-02-17T13:43:42+07:00" level=debug msg="completed challenge" Feb 17 13:43:42 volumio go-librespot[31775]: time="2026-02-17T13:43:42+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 17 13:43:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 13:43:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 13:43:43 volumio volumio[31700]: info: Starting UPNP Browser Feb 17 13:43:43 volumio volumio[31700]: info: Loading plugin "alarm-clock"... Feb 17 13:43:43 volumio volumio[31700]: info: Loading plugin "airplay_emulation"... Feb 17 13:43:43 volumio volumio[31700]: info: Starting Shairport Sync Feb 17 13:43:43 volumio volumio[31700]: info: Loading plugin "last_100"... Feb 17 13:43:43 volumio volumio[31700]: info: Loading plugin "webradio"... Feb 17 13:43:43 volumio volumio[31700]: info: Loading plugin "i2s_dacs"... Feb 17 13:43:43 volumio volumio[31700]: info: Loading plugin "volumiodiscovery"... Feb 17 13:43:43 volumio volumio[31700]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 13:43:43 volumio volumio[31700]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 13:43:43 volumio volumio[31700]: *** WARNING *** For more information see Feb 17 13:43:43 volumio volumio[31700]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 13:43:43 volumio volumio[31700]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 13:43:43 volumio volumio[31700]: *** WARNING *** For more information see Feb 17 13:43:43 volumio node[31700]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 13:43:43 volumio node[31700]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 13:43:43 volumio node[31700]: *** WARNING *** For more information see Feb 17 13:43:43 volumio node[31700]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 13:43:43 volumio node[31700]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 13:43:43 volumio node[31700]: *** WARNING *** For more information see Feb 17 13:43:43 volumio volumio[31700]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 17 13:43:43 volumio volumio[31700]: info: Discovery: Started advertising with name: Volumio Feb 17 13:43:43 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 13:43:43 volumio volumio[31700]: info: Loading plugin "spop"... Feb 17 13:43:45 volumio volumio[31700]: info: Loading plugin "ytcr"... Feb 17 13:43:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 17 13:43:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:43:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:43:45 volumio go-librespot[31784]: go-librespot daemon starting... Feb 17 13:43:45 volumio go-librespot[31785]: time="2026-02-17T13:43:45+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 13:43:45 volumio go-librespot[31785]: time="2026-02-17T13:43:45+07:00" level=debug msg="app state loaded" Feb 17 13:43:45 volumio go-librespot[31785]: time="2026-02-17T13:43:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 13:43:46 volumio go-librespot[31785]: time="2026-02-17T13:43:46+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 17 13:43:46 volumio go-librespot[31785]: time="2026-02-17T13:43:46+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 17 13:43:46 volumio go-librespot[31785]: time="2026-02-17T13:43:46+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 17 13:43:46 volumio go-librespot[31785]: time="2026-02-17T13:43:46+07:00" level=info msg="zeroconf server listening on port 42143" Feb 17 13:43:46 volumio go-librespot[31785]: time="2026-02-17T13:43:46+07:00" level=debug msg="obtained new client token: AAC39svlMI0sjG25EQt7IkIgg9Swol3R4Xjre4UI3PfeGFkW9VIYyk/yN5GxU2AL7UqwJJdCNa3chLrQ5+dIKbuWdRbtHTodLOvtzBYEj7nnaQFzAz4ECgVGqKAUXhxE+t3Aq5o2tzDv+aAnPuLhEAsAlzf+3CWjsapKhydZRT2tV3DLYPOSPZIOOCjYwnDx2j/MoModb1unT+yIV/QCXaCnetyiaru0j5gGGvqpPLuiGJ5BDGGWS1jKWA==" Feb 17 13:43:46 volumio go-librespot[31785]: time="2026-02-17T13:43:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 13:43:46 volumio go-librespot[31785]: time="2026-02-17T13:43:46+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 17 13:43:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 13:43:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 13:43:48 volumio volumio[31700]: info: Loading plugin "ytmusic"... Feb 17 13:43:49 volumio volumio-remote-updater[25144]: [2026-02-17 13:43:49] [connect] Successful connection Feb 17 13:43:49 volumio volumio[31700]: info: Loading plugin "outputs"... Feb 17 13:43:49 volumio volumio[31700]: info: Loading plugin "albumart"... Feb 17 13:43:49 volumio volumio[31700]: info: Plugin example_plugin is not enabled Feb 17 13:43:49 volumio volumio[31700]: info: Loading plugin "inputs"... Feb 17 13:43:49 volumio volumio[31700]: info: Loading plugin "updater_comm"... Feb 17 13:43:49 volumio volumio[31700]: info: Plugin mpdemulation is not enabled Feb 17 13:43:49 volumio volumio[31700]: info: Loading plugin "rest_api"... Feb 17 13:43:49 volumio volumio[31700]: info: Loading plugin "websocket"... Feb 17 13:43:49 volumio volumio[31700]: info: Starting Socket.io Server version 1.7.4 Feb 17 13:43:49 volumio volumio[31700]: info: Loading plugin "RoonBridge"... Feb 17 13:43:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 17 13:43:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:43:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:43:50 volumio go-librespot[31819]: go-librespot daemon starting... Feb 17 13:43:50 volumio go-librespot[31820]: time="2026-02-17T13:43:50+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 13:43:50 volumio go-librespot[31820]: time="2026-02-17T13:43:50+07:00" level=debug msg="app state loaded" Feb 17 13:43:50 volumio go-librespot[31820]: time="2026-02-17T13:43:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 13:43:50 volumio volumio[31700]: info: Applying required configuration parameters for plugin RoonBridge Feb 17 13:43:50 volumio volumio[31700]: info: Loading i18n strings for locale en Feb 17 13:43:50 volumio volumio[31700]: Updating browse sources language Feb 17 13:43:50 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 13:43:50 volumio volumio[31809]: Forking 3 albumart workers Feb 17 13:43:50 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 13:43:50 volumio volumio[31700]: info: CoreCommandRouter::initPlayerControls Feb 17 13:43:50 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:50 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:50 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:50 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:50 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:50 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:50 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:50 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:50 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 13:43:50 volumio volumio[31700]: Express server listening on port 3000 Feb 17 13:43:50 volumio volumio[31700]: [Metrics] WebUI: 16s 106.19ms Feb 17 13:43:50 volumio go-librespot[31820]: time="2026-02-17T13:43:50+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 17 13:43:50 volumio go-librespot[31820]: time="2026-02-17T13:43:50+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 17 13:43:50 volumio go-librespot[31820]: time="2026-02-17T13:43:50+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 17 13:43:50 volumio go-librespot[31820]: time="2026-02-17T13:43:50+07:00" level=info msg="zeroconf server listening on port 38021" Feb 17 13:43:50 volumio volumio[31700]: info: CoreStateMachine::resetVolumioState Feb 17 13:43:50 volumio volumio[31700]: info: CoreStateMachine::getcurrentVolume Feb 17 13:43:50 volumio volumio[31700]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 13:43:51 volumio go-librespot[31820]: time="2026-02-17T13:43:51+07:00" level=debug msg="obtained new client token: AADlTNO8Elpau+W7i8L+7lrn3LLQC2K8+3w0Z98/tLOWTnOOrpjywj8SDSWOOAkqlB75dhaET4kz5Uzh5PVVFOzTHcv3u9xrXb0afNk2KBy6diM+werGkHmqdzj3xtW0eN0tAHKbz1fZ0zwNVOMd7Yqd4qsvB//5zbQzeJv7ejtnPGdujta8KGYAE5PxmBjq2830uNhKqKIgdR2JyuUw1XP5SalrYW7Up8UIVuVYkYPi1AVDzkyuOu4=" Feb 17 13:43:51 volumio sudo[31863]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 13:43:51 volumio sudo[31865]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 13:43:51 volumio sudo[31863]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:43:51 volumio sudo[31865]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:43:51 volumio volumio[31700]: info: Volumio Network Manager: Network status updated: 1 Feb 17 13:43:51 volumio sudo[31863]: pam_unix(sudo:session): session closed for user root Feb 17 13:43:51 volumio sudo[31865]: pam_unix(sudo:session): session closed for user root Feb 17 13:43:51 volumio go-librespot[31820]: time="2026-02-17T13:43:51+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 13:43:51 volumio go-librespot[31820]: time="2026-02-17T13:43: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 17 13:43:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 13:43:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 13:43:51 volumio volumio[31700]: info: VolumeController:: Volume=100 Mute =false Feb 17 13:43:51 volumio volumio[31700]: info: CoreStateMachine::pushState Feb 17 13:43:51 volumio volumio[31700]: info: CorePlayQueue::getTrack 0 Feb 17 13:43:51 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 13:43:51 volumio volumio[31700]: info: CoreCommandRouter::volumioPushState Feb 17 13:43:51 volumio volumio[31700]: info: CoreStateMachine::updateTrackBlock Feb 17 13:43:51 volumio volumio[31700]: info: CorePlayQueue::getTrackBlock Feb 17 13:43:51 volumio volumio[31700]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 13:43:51 volumio volumio-remote-updater[25144]: [2026-02-17 13:43:51] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771310629 101 Feb 17 13:43:51 volumio volumio[31700]: 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 17 13:43:51 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 13:43:51 volumio volumio[31700]: info: Reloading queue from file Feb 17 13:43:51 volumio volumio[31700]: info: CoreStateMachine::setRepeat null single undefined Feb 17 13:43:51 volumio volumio[31700]: info: CoreStateMachine::pushState Feb 17 13:43:51 volumio volumio[31700]: info: CorePlayQueue::getTrack 0 Feb 17 13:43:51 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 13:43:51 volumio volumio[31700]: info: CoreCommandRouter::volumioPushState Feb 17 13:43:51 volumio volumio[31700]: info: CoreStateMachine::setRandom null Feb 17 13:43:51 volumio volumio[31700]: info: CoreStateMachine::pushState Feb 17 13:43:51 volumio volumio[31700]: info: CorePlayQueue::getTrack 0 Feb 17 13:43:51 volumio volumio[31700]: info: CoreCommandRouter::volumioPushState Feb 17 13:43:51 volumio volumio[31700]: info: Setting Device type: Raspberry PI Feb 17 13:43:51 volumio volumio[31700]: info: Completed loading Core Plugins Feb 17 13:43:51 volumio volumio[31700]: info: Preparing to generate the ALSA configuration file Feb 17 13:43:52 volumio volumio[31700]: info: VolumeController:: Volume=100 Mute =false Feb 17 13:43:52 volumio volumio[31700]: info: CoreStateMachine::pushState Feb 17 13:43:52 volumio volumio[31700]: info: CorePlayQueue::getTrack 0 Feb 17 13:43:52 volumio volumio[31700]: info: CoreCommandRouter::volumioPushState Feb 17 13:43:52 volumio volumio[31700]: info: Asound.conf file unchanged, so no further update is needed Feb 17 13:43:52 volumio volumio[31700]: info: Output device has changed, restarting MPD Feb 17 13:43:52 volumio sudo[31879]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 17 13:43:52 volumio sudo[31879]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:43:52 volumio sudo[31882]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 13:43:52 volumio sudo[31882]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:43:52 volumio volumio[31700]: info: Output device has changed, restarting Shairport Sync Feb 17 13:43:52 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:52 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 13:43:52 volumio sudo[31882]: pam_unix(sudo:session): session closed for user root Feb 17 13:43:52 volumio sudo[31879]: pam_unix(sudo:session): session closed for user root Feb 17 13:43:52 volumio sudo[31884]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 13:43:52 volumio sudo[31884]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:43:52 volumio volumio[31700]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 13:43:52 volumio volumio[31700]: info: ___________ START PLUGINS ___________ Feb 17 13:43:52 volumio volumio[31700]: info: ControllerMpd::onStart: Initializing MPD Feb 17 13:43:52 volumio volumio[31700]: info: Creating MPD Configuration file Feb 17 13:43:52 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 17 13:43:52 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 13:43:52 volumio volumio[31700]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 13:43:52 volumio volumio[31700]: info: [1771310632386] CoreMusicLibrary::Adding element Media Servers Feb 17 13:43:52 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 13:43:52 volumio volumio[31700]: info: UPNP Browser: Client initialized successfully Feb 17 13:43:52 volumio sudo[31892]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 13:43:52 volumio sudo[31892]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:43:52 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 17 13:43:52 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 13:43:52 volumio systemd[1]: mpd.service: Consumed 7.116s CPU time. Feb 17 13:43:52 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 17 13:43:52 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 13:43:52 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 13:43:52 volumio sudo[31892]: pam_unix(sudo:session): session closed for user root Feb 17 13:43:52 volumio sudo[31894]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 13:43:52 volumio sudo[31894]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:43:52 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 13:43:52 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 13:43:52 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:52 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 13:43:52 volumio volumio[31700]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 13:43:52 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 17 13:43:52 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 13:43:52 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:52 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 13:43:52 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 17 13:43:52 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 13:43:52 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 13:43:52 volumio volumio[31700]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 13:43:52 volumio volumio[31700]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 13:43:52 volumio volumio[31700]: info: [1771310632730] CoreMusicLibrary::Adding element Last_100 Feb 17 13:43:52 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 13:43:52 volumio volumio[31700]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 13:43:52 volumio volumio[31700]: info: [1771310632739] CoreMusicLibrary::Adding element Webradio Feb 17 13:43:52 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 13:43:52 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 13:43:52 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 13:43:52 volumio volumio[31700]: info: Initializing BBC Radios Feb 17 13:43:52 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 13:43:52 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 13:43:52 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 13:43:53 volumio volumio[31700]: info: Creating Spotify config file Feb 17 13:43:53 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:53 volumio sudo[31911]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 17 13:43:53 volumio sudo[31911]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 17 13:43:53 volumio sudo[31911]: pam_unix(sudo:session): session closed for user root Feb 17 13:43:53 volumio volumio[31830]: Starting albumart workers Feb 17 13:43:53 volumio volumio[31826]: Starting albumart workers Feb 17 13:43:53 volumio volumio[31827]: Starting albumart workers Feb 17 13:43:54 volumio volumio[31700]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 13:43:54 volumio volumio[31700]: info: [1771310634177] CoreMusicLibrary::Adding element YouTube Music Feb 17 13:43:54 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 13:43:54 volumio volumio[31700]: Cannot find translation for source YouTube Music Feb 17 13:43:54 volumio volumio[31700]: info: Volumio Calling Home Feb 17 13:43:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 17 13:43:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:43:54 volumio sudo[31925]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 17 13:43:54 volumio sudo[31925]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:43:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:43:54 volumio go-librespot[31928]: go-librespot daemon starting... Feb 17 13:43:54 volumio go-librespot[31930]: time="2026-02-17T13:43:54+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 13:43:54 volumio sudo[31925]: pam_unix(sudo:session): session closed for user root Feb 17 13:43:55 volumio go-librespot[31930]: time="2026-02-17T13:43:55+07:00" level=info msg="zeroconf server listening on port 46257" Feb 17 13:43:55 volumio volumio[31700]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 13:43:55 volumio volumio[31700]: info: Discovery: Found device Volumio Feb 17 13:43:55 volumio volumio[31700]: info: CoreCommandRouter::volumioGetState Feb 17 13:43:55 volumio volumio[31700]: info: CorePlayQueue::getTrack 0 Feb 17 13:43:55 volumio volumio[31700]: info: MPD Permissions set Feb 17 13:43:55 volumio volumio[31700]: info: MPD Permissions set Feb 17 13:43:55 volumio volumio[31700]: info: Upmpdcli Daemon Started Feb 17 13:43:55 volumio volumio[31700]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 13:43:55 volumio volumio[31700]: info: Discovery: Found device Volumio Feb 17 13:43:55 volumio volumio[31700]: info: CoreCommandRouter::volumioGetState Feb 17 13:43:55 volumio volumio[31700]: info: CorePlayQueue::getTrack 0 Feb 17 13:43:55 volumio volumio[31700]: info: Spotify config file written Feb 17 13:43:55 volumio sudo[31952]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 17 13:43:55 volumio sudo[31952]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:43:55 volumio volumio[31700]: 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 17 13:43:55 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:55 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:55 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:55 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:55 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:55 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:55 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:55 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:55 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 17 13:43:55 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 17 13:43:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:43:55 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 13:43:55 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:55 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:55 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:55 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:55 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:55 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:55 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:55 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:55 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:56 volumio go-librespot[31965]: go-librespot daemon starting... Feb 17 13:43:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:43:56 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 13:43:56 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:43:56 volumio volumio[31700]: info: No need to fix Spotify hosts Feb 17 13:43:56 volumio sudo[31952]: pam_unix(sudo:session): session closed for user root Feb 17 13:43:56 volumio go-librespot[31971]: time="2026-02-17T13:43:56+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 13:43:56 volumio go-librespot[31971]: time="2026-02-17T13:43:56+07:00" level=debug msg="app state loaded" Feb 17 13:43:56 volumio go-librespot[31971]: time="2026-02-17T13:43:56+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 13:43:56 volumio go-librespot[31971]: time="2026-02-17T13:43:56+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 17 13:43:56 volumio go-librespot[31971]: time="2026-02-17T13:43:56+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 17 13:43:56 volumio go-librespot[31971]: time="2026-02-17T13:43:56+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 17 13:43:56 volumio go-librespot[31971]: time="2026-02-17T13:43:56+07:00" level=info msg="zeroconf server listening on port 42725" Feb 17 13:43:56 volumio volumio[31700]: info: Volumio called home Feb 17 13:43:56 volumio volumio[31700]: info: Starting Shairport Sync Feb 17 13:43:56 volumio go-librespot[31971]: time="2026-02-17T13:43:56+07:00" level=debug msg="obtained new client token: AADZmEf5hkrPvzn0DorLlVHkCODhRImC6z/oJ7ebXJhLYU4YZK/tWldxUXQZ+DPVVhaTdjM/PRRfWRjATfhqaaC4UIXqC2kLmvQWPDRiziQsOxZ3x4uPmtTZNKAl9fpCUEVPlFWvEf+JVP25YjEHtTiPKuH/Bj+KWXHiIz0x338Z8FdSm7ZGaNsxzp+cvq3PWJBYwU2hcEQdHiDlbqIA0WU6XQ8WdA9PxwiUznbVa3TZOzgKmP6MfgzzmA==" Feb 17 13:43:56 volumio volumio[31700]: info: Starting Shairport Sync Feb 17 13:43:56 volumio volumio[31700]: info: Starting Shairport Sync Feb 17 13:43:56 volumio sudo[31984]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 13:43:56 volumio sudo[31984]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:43:56 volumio sudo[31980]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 13:43:56 volumio sudo[31980]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:43:56 volumio go-librespot[31971]: time="2026-02-17T13:43:56+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 13:43:56 volumio sudo[31982]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 13:43:56 volumio sudo[31982]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:43:57 volumio go-librespot[31971]: time="2026-02-17T13:43:57+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 17 13:43:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 13:43:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 13:43:57 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 17 13:43:57 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 17 13:43:57 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 13:43:57 volumio systemd[1]: shairport-sync.service: Consumed 2.341s CPU time. Feb 17 13:43:57 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 13:43:57 volumio sudo[31980]: pam_unix(sudo:session): session closed for user root Feb 17 13:43:57 volumio sudo[31984]: pam_unix(sudo:session): session closed for user root Feb 17 13:43:57 volumio sudo[31982]: pam_unix(sudo:session): session closed for user root Feb 17 13:43:57 volumio volumio[31700]: info: CoreCommandRouter::volumioGetState Feb 17 13:43:57 volumio volumio[31700]: info: CorePlayQueue::getTrack 0 Feb 17 13:43:57 volumio volumio[31700]: info: Shairport-Sync Started Feb 17 13:43:57 volumio volumio[31700]: Error adding Membership: Error: addMembership EINVAL Feb 17 13:43:57 volumio volumio[31700]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 13:43:57 volumio volumio[31700]: SPOTIFY: BQDvvn6fE9h3n4yj6m4sk3s8l3I1UOXaa-tnjFRPRQgO_t6brjVE18jrl0G0AlvyvZekeJXVe61XvP6HyO-MxJaWQbCHR_YmNeUr6NEEzY6vl1yspzc7Yr-US0wsr1YcX51CxvL-rxAkOiPhuGzYR3-iV5k2DHknZJTk8lAuAeDtXTKvzEiRvfOC9iseMnzXS529Jz9_GF_fvpaorVcsPL6UB4azU70_YDAd0ezMnLtRukg1LG4i4yUhxrMWkzjk2XnlskmaQbhOCvJ9y64pxF7MF5UkqC_dQOmP2lDTgJAk7vg86exKD6wt Feb 17 13:43:57 volumio volumio[31700]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 13:43:57 volumio volumio[31700]: info: New Spotify access token = BQDvvn6fE9h3n4yj6m4sk3s8l3I1UOXaa-tnjFRPRQgO_t6brjVE18jrl0G0AlvyvZekeJXVe61XvP6HyO-MxJaWQbCHR_YmNeUr6NEEzY6vl1yspzc7Yr-US0wsr1YcX51CxvL-rxAkOiPhuGzYR3-iV5k2DHknZJTk8lAuAeDtXTKvzEiRvfOC9iseMnzXS529Jz9_GF_fvpaorVcsPL6UB4azU70_YDAd0ezMnLtRukg1LG4i4yUhxrMWkzjk2XnlskmaQbhOCvJ9y64pxF7MF5UkqC_dQOmP2lDTgJAk7vg86exKD6wt Feb 17 13:43:57 volumio volumio[31700]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 17 13:43:57 volumio volumio[31700]: info: Shairport-Sync Started Feb 17 13:43:57 volumio volumio[31700]: info: Shairport-Sync Started Feb 17 13:43:57 volumio volumio[31700]: 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 17 13:43:57 volumio volumio[31700]: info: Spotify Successfully logged in Feb 17 13:43:57 volumio volumio[31700]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 13:43:57 volumio volumio[31700]: info: [1771310637915] CoreMusicLibrary::Adding element Spotify Feb 17 13:43:57 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 13:43:57 volumio volumio[31700]: Cannot find translation for source YouTube Music Feb 17 13:43:57 volumio volumio[31700]: Cannot find translation for source Spotify Feb 17 13:43:58 volumio volumio[31700]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 17 13:43:58 volumio volumio[31700]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 13:43:58 volumio volumio[31700]: info: VolumeController:: Volume=100 Mute =false Feb 17 13:43:58 volumio volumio[31700]: info: CoreCommandRouter::volumioGetState Feb 17 13:43:58 volumio volumio[31700]: info: CorePlayQueue::getTrack 0 Feb 17 13:43:58 volumio volumio[31700]: info: CoreStateMachine::pushState Feb 17 13:43:58 volumio volumio[31700]: info: CorePlayQueue::getTrack 0 Feb 17 13:43:58 volumio volumio[31700]: info: CoreCommandRouter::volumioPushState Feb 17 13:43:59 volumio volumio[31700]: info: go-librespot daemon successfully initialized Feb 17 13:44:00 volumio mpd[31923]: 2026-02-17T13:44:00 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 17 13:44:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 17 13:44:00 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 17 13:44:00 volumio sudo[31884]: pam_unix(sudo:session): session closed for user root Feb 17 13:44:00 volumio sudo[31894]: pam_unix(sudo:session): session closed for user root Feb 17 13:44:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:44:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:44:00 volumio go-librespot[32023]: go-librespot daemon starting... Feb 17 13:44:00 volumio go-librespot[32025]: time="2026-02-17T13:44:00+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 13:44:00 volumio go-librespot[32025]: time="2026-02-17T13:44:00+07:00" level=debug msg="app state loaded" Feb 17 13:44:00 volumio go-librespot[32025]: time="2026-02-17T13:44:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 13:44:00 volumio volumio[31700]: error: MPD error: The expression evaluated to a falsy value: Feb 17 13:44:00 volumio volumio[31700]: assert.ok(self.idling) Feb 17 13:44:00 volumio volumio[31700]: error: The expression evaluated to a falsy value: Feb 17 13:44:00 volumio volumio[31700]: assert.ok(self.idling) Feb 17 13:44:00 volumio volumio[31700]: error: updateQueue error: null Feb 17 13:44:00 volumio volumio[31700]: info: MPD running with PID31923 Feb 17 13:44:00 volumio volumio[31700]: ,establishing connection Feb 17 13:44:00 volumio volumio[31700]: info: Completed starting Core Plugins Feb 17 13:44:00 volumio volumio[31700]: info: ------------------------------------------- Feb 17 13:44:00 volumio volumio[31700]: info: ----- MyVolumio plugins startup ---- Feb 17 13:44:00 volumio volumio[31700]: info: ------------------------------------------- Feb 17 13:44:00 volumio volumio[31700]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 17 13:44:00 volumio volumio[31700]: error: updateQueue error: null Feb 17 13:44:00 volumio go-librespot[32025]: time="2026-02-17T13:44:00+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 17 13:44:00 volumio go-librespot[32025]: time="2026-02-17T13:44:00+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 17 13:44:00 volumio go-librespot[32025]: time="2026-02-17T13:44:00+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 17 13:44:00 volumio go-librespot[32025]: time="2026-02-17T13:44:00+07:00" level=info msg="zeroconf server listening on port 46527" Feb 17 13:44:01 volumio go-librespot[32025]: time="2026-02-17T13:44:01+07:00" level=debug msg="obtained new client token: AAChvl29kHA9FM3mdBqqbUpkvHfZukK6l65S9FRhr/WQFFCBKDV/BYq7Obujlnrw9s72zsqESmh4FiTcL3cUVMphMQobAihH5VMjcsTn4q3gCyfOtPPZB3AdsqDjbVHB8UWlFLRBMKkyxWt/r7XNMjfFvaex4kBI8hLsyooLb5EU3DqdtCCozRiOfX3bIpbuoTu6m+YlMSbXko4WDLpK78rG7v7KRFc+pu5n2zym4Sc7YHjOtKR5d5DLGA==" Feb 17 13:44:01 volumio go-librespot[32025]: time="2026-02-17T13:44:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 13:44:01 volumio go-librespot[32025]: time="2026-02-17T13: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 17 13:44:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 13:44:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 13:44:02 volumio volumio[31700]: info: Initializing connection to go-librespot Websocket Feb 17 13:44:02 volumio volumio[31700]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 13:44:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 17 13:44:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:44:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:44:04 volumio go-librespot[32032]: go-librespot daemon starting... Feb 17 13:44:04 volumio go-librespot[32033]: time="2026-02-17T13:44:04+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 13:44:04 volumio go-librespot[32033]: time="2026-02-17T13:44:04+07:00" level=debug msg="app state loaded" Feb 17 13:44:04 volumio go-librespot[32033]: time="2026-02-17T13:44:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 13:44:04 volumio go-librespot[32033]: time="2026-02-17T13:44:04+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 17 13:44:04 volumio go-librespot[32033]: time="2026-02-17T13:44:04+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 17 13:44:04 volumio go-librespot[32033]: time="2026-02-17T13:44:04+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 17 13:44:04 volumio go-librespot[32033]: time="2026-02-17T13:44:04+07:00" level=info msg="zeroconf server listening on port 41303" Feb 17 13:44:05 volumio go-librespot[32033]: time="2026-02-17T13:44:05+07:00" level=debug msg="obtained new client token: AAC43vnK9CowuQhgOBGMGVDmY4Cq4J308s40+luYzl3NOvu0ulPlWvlJGKOQYN6mY3B4JtEhkNX2x7OmY6jrPVH/VArmPEH2KQCK7Z3iyfEV9HA2QiKIaw+s15WwbmA3zYv0v5ke91xvUoEFfUNp0tTY9Xda3cRwPxUj3ByE/WPM1mf/BX0Nti2N16iMf6esd3rkokXrXgMUtq/oJgXnzpx6cXOLACOx2zeqLj0+DaXr3S4ZISm4WbI=" Feb 17 13:44:05 volumio go-librespot[32033]: time="2026-02-17T13:44:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 13:44:05 volumio volumio[31700]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 17 13:44:05 volumio go-librespot[32033]: time="2026-02-17T13:44:05+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:36482->104.199.241.202:4070: read: connection reset by peer" Feb 17 13:44:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 13:44:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 13:44:05 volumio volumio[31700]: info: Initializing connection to go-librespot Websocket Feb 17 13:44:05 volumio volumio[31700]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 13:44:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 17 13:44:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:44:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:44:08 volumio go-librespot[32042]: go-librespot daemon starting... Feb 17 13:44:08 volumio go-librespot[32043]: time="2026-02-17T13:44:08+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 13:44:08 volumio go-librespot[32043]: time="2026-02-17T13:44:08+07:00" level=debug msg="app state loaded" Feb 17 13:44:08 volumio go-librespot[32043]: time="2026-02-17T13:44:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 13:44:08 volumio volumio[31700]: info: Initializing connection to go-librespot Websocket Feb 17 13:44:08 volumio go-librespot[32043]: time="2026-02-17T13:44:08+07:00" level=debug msg="new websocket client" Feb 17 13:44:08 volumio volumio[31700]: info: Connection to go-librespot Websocket established Feb 17 13:44:09 volumio go-librespot[32043]: time="2026-02-17T13:44:09+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 17 13:44:09 volumio go-librespot[32043]: time="2026-02-17T13:44:09+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 17 13:44:09 volumio go-librespot[32043]: time="2026-02-17T13:44:09+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 17 13:44:09 volumio go-librespot[32043]: time="2026-02-17T13:44:09+07:00" level=info msg="zeroconf server listening on port 46743" Feb 17 13:44:09 volumio volumio[31700]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 17 13:44:09 volumio volumio[31700]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 17 13:44:09 volumio volumio[31700]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 17 13:44:09 volumio volumio[31700]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 17 13:44:09 volumio volumio[31700]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 17 13:44:09 volumio volumio[31700]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 17 13:44:09 volumio volumio[31700]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 17 13:44:09 volumio volumio[31700]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 17 13:44:09 volumio volumio[31700]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 17 13:44:09 volumio volumio[31700]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 17 13:44:09 volumio volumio[31700]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 17 13:44:09 volumio volumio[31700]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 17 13:44:09 volumio volumio[31700]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 17 13:44:09 volumio volumio[31700]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 17 13:44:09 volumio volumio[31700]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 17 13:44:09 volumio volumio[31700]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 17 13:44:09 volumio volumio[31700]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 17 13:44:09 volumio volumio[31700]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 17 13:44:09 volumio volumio[31700]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 17 13:44:09 volumio volumio[31700]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 17 13:44:09 volumio volumio[31700]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 17 13:44:09 volumio volumio[31700]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 17 13:44:09 volumio volumio[31700]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 17 13:44:09 volumio volumio[31700]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 17 13:44:09 volumio volumio[31700]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 17 13:44:09 volumio volumio[31700]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 17 13:44:09 volumio volumio[31700]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 17 13:44:09 volumio volumio[31700]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 17 13:44:09 volumio volumio[31700]: info: Adding plugin bluetooth to MyMusic Plugins Feb 17 13:44:09 volumio volumio[31700]: info: Adding plugin multiroom to MyMusic Plugins Feb 17 13:44:09 volumio volumio[31700]: info: Adding plugin metavolumio to MyMusic Plugins Feb 17 13:44:09 volumio volumio[31700]: info: Adding plugin cd_controller to MyMusic Plugins Feb 17 13:44:09 volumio volumio[31700]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 17 13:44:09 volumio volumio[31700]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 17 13:44:09 volumio volumio[31700]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 17 13:44:09 volumio volumio[31700]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 17 13:44:09 volumio go-librespot[32043]: time="2026-02-17T13:44:09+07:00" level=debug msg="obtained new client token: AABC9zjSYkN2bGhdI4jRxd6yHS7e5FZ1HWUL7HU590ub3VNsV3okoZkKWFtIhELYclEP8CsebOlFZwDj3szMJIYdq481IO8zE/W8VdEAcgEBcddgBytbQPLypf2+81W7H5hIs74IfJargft+Oh1iX7TcFQ4HRi1ZhYA350IHWGGVvHPuS94DKfXZ9W8e06lBLr5LwRyRqVvE8pkmiZBIthD6J8VPy4aHzv6aoYe5D82gaRvcNNR5kYb8YA==" Feb 17 13:44:09 volumio go-librespot[32043]: time="2026-02-17T13:44:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 13:44:09 volumio go-librespot[32043]: time="2026-02-17T13:44:09+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 17 13:44:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 13:44:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 13:44:11 volumio volumio[31700]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 17 13:44:11 volumio volumio[31700]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 17 13:44:11 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 13:44:11 volumio volumio[31700]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 13:44:11 volumio volumio[31700]: info: Starting MyVolumio Remote Streaming Endpoints Feb 17 13:44:11 volumio volumio[31700]: info: MyVolumio login type: Token Feb 17 13:44:11 volumio volumio[31700]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 17 13:44:11 volumio volumio[31700]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 17 13:44:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 17 13:44:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:44:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:44:12 volumio go-librespot[32064]: go-librespot daemon starting... Feb 17 13:44:12 volumio go-librespot[32065]: time="2026-02-17T13:44:12+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 13:44:12 volumio go-librespot[32065]: time="2026-02-17T13:44:12+07:00" level=debug msg="app state loaded" Feb 17 13:44:12 volumio go-librespot[32065]: time="2026-02-17T13:44:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 13:44:13 volumio volumio[31700]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 17 13:44:13 volumio volumio[31700]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 17 13:44:13 volumio volumio[31700]: info: Streaming services startup Feb 17 13:44:13 volumio volumio[31700]: info: Starting Streaming Daemon Feb 17 13:44:13 volumio sudo[32072]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 17 13:44:13 volumio sudo[32072]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:44:13 volumio volumio[31700]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 17 13:44:13 volumio sudo[32072]: pam_unix(sudo:session): session closed for user root Feb 17 13:44:13 volumio volumio[31700]: info: Getting Spotify volume Feb 17 13:44:13 volumio volumio[31700]: info: Connection to go-librespot Websocket closed Feb 17 13:44:13 volumio volumio[31700]: error: Cannot start Volumio Streaming Daemon Feb 17 13:44:13 volumio volumio[31700]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 17 13:44:13 volumio volumio[31700]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 17 13:44:13 volumio volumio[31700]: 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 17 13:44:13 volumio go-librespot[32065]: time="2026-02-17T13:44:13+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 17 13:44:13 volumio go-librespot[32065]: time="2026-02-17T13:44:13+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 17 13:44:13 volumio go-librespot[32065]: time="2026-02-17T13:44:13+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 17 13:44:13 volumio go-librespot[32065]: time="2026-02-17T13:44:13+07:00" level=info msg="zeroconf server listening on port 46251" Feb 17 13:44:13 volumio volumio[31700]: info: CoreCommandRouter::volumioGetState Feb 17 13:44:13 volumio volumio[31700]: info: CorePlayQueue::getTrack 0 Feb 17 13:44:13 volumio volumio[31700]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 17 13:44:13 volumio volumio[31700]: SPOTIFY: SPOTIFY VOLUME undefined Feb 17 13:44:13 volumio volumio[31700]: SPOTIFY: VOLUMIO VOLUME 100 Feb 17 13:44:13 volumio volumio[31700]: info: Aligning Spotify Volume to Volumio Volume Feb 17 13:44:13 volumio volumio[31700]: info: CoreCommandRouter::volumioGetState Feb 17 13:44:13 volumio volumio[31700]: info: CorePlayQueue::getTrack 0 Feb 17 13:44:13 volumio volumio[31700]: info: Setting Spotify Volume from Volumio: 100 Feb 17 13:44:13 volumio go-librespot[32065]: time="2026-02-17T13:44:13+07:00" level=debug msg="obtained new client token: AACxq2XU2WVe3wEzx0Lzd/z5C4CEgfa/LJLh5lllT+QkiQMk4KuCY6o39sIBkcGheNkV6CwWuj4jSxAgbYqrQDuTYhph4mt53v/tm8TvJRFWoPhR/rD07g1i2sf7v1VL5B19mjbT9Cse7JJeKvp7N+x6legySj0UqYBaxwjjzGg/+XHLquF2Yk+jiefkq32352zo65JLvosr9a8t3s/M46TnrmCsAMQKJjZwkKoMFytdiujYFQrrQVjLkQ==" Feb 17 13:44:13 volumio go-librespot[32065]: time="2026-02-17T13:44:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 13:44:13 volumio go-librespot[32065]: time="2026-02-17T13:44:13+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 17 13:44:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 13:44:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 13:44:13 volumio volumio[31700]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 13:44:13 volumio volumio[31700]: Error: socket hang up Feb 17 13:44:13 volumio volumio[31700]: at connResetException (node:internal/errors:720:14) Feb 17 13:44:13 volumio volumio[31700]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 17 13:44:13 volumio volumio[31700]: at Socket.emit (node:events:526:35) Feb 17 13:44:13 volumio volumio[31700]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 17 13:44:13 volumio volumio[31700]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 17 13:44:13 volumio volumio[31700]: code: 'ECONNRESET', Feb 17 13:44:13 volumio volumio[31700]: response: undefined Feb 17 13:44:13 volumio volumio[31700]: } Feb 17 13:44:13 volumio volumio[31700]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 13:44:15 volumio sudo[32093]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-17 13:43' Feb 17 13:44:15 volumio sudo[32093]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:44:15 volumio sudo[32093]: pam_unix(sudo:session): session closed for user root Feb 17 13:44:15 volumio volumio-remote-updater[25144]: [2026-02-17 13:44:15] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 17 13:44:15 volumio volumio-remote-updater[25144]: [2026-02-17 13:44:15] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 17 13:44:15 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 17 13:44:15 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 17 13:44:15 volumio systemd[1]: volumio.service: Consumed 55.429s CPU time. Feb 17 13:44:15 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 17 13:44:16 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 17 13:44:16 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 20439. Feb 17 13:44:16 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 17 13:44:16 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 17 13:44:16 volumio systemd[1]: volumio.service: Consumed 55.429s CPU time. Feb 17 13:44:16 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 17 13:44:16 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 17 13:44:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 17 13:44:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:44:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:44:17 volumio go-librespot[32124]: go-librespot daemon starting... Feb 17 13:44:17 volumio go-librespot[32125]: time="2026-02-17T13:44:17+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 13:44:17 volumio go-librespot[32125]: time="2026-02-17T13:44:17+07:00" level=debug msg="app state loaded" Feb 17 13:44:17 volumio go-librespot[32125]: time="2026-02-17T13:44:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 13:44:17 volumio go-librespot[32125]: time="2026-02-17T13:44:17+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 17 13:44:17 volumio go-librespot[32125]: time="2026-02-17T13:44:17+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 17 13:44:17 volumio go-librespot[32125]: time="2026-02-17T13:44:17+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 17 13:44:17 volumio go-librespot[32125]: time="2026-02-17T13:44:17+07:00" level=info msg="zeroconf server listening on port 36889" Feb 17 13:44:17 volumio go-librespot[32125]: time="2026-02-17T13:44:17+07:00" level=debug msg="obtained new client token: AAAJdnqKvuK93GAoPyNIm1ygmrtk64dFCOz2sF04MPDchfuBb5+uvnBkTZlI0LYyY+tjlvcbz7iiiazgcfOUsMyCN1jUfxoJcixuJffqFymrhIztjy/CA3strjkTyiWWCSC+5+kQ2aXEgLf/6ko+CrTP287pCmay6JdvpExF91NQYiswTA9hpnLLU0v1chjU0gGOH2ZWyrjMr76UGFG1Qg2Svk5BLhVD0W11jpB8xW/2KfJXvb8RWx8/jQ==" Feb 17 13:44:18 volumio go-librespot[32125]: time="2026-02-17T13:44:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 13:44:19 volumio go-librespot[32125]: time="2026-02-17T13:44:19+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:34170->104.199.241.202:4070: read: connection reset by peer" Feb 17 13:44:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 13:44:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 13:44:19 volumio volumio[32108]: info: ------------------------------------------- Feb 17 13:44:19 volumio volumio[32108]: info: ----- Volumio3 ---- Feb 17 13:44:19 volumio volumio[32108]: info: ------------------------------------------- Feb 17 13:44:19 volumio volumio[32108]: info: ----- System startup ---- Feb 17 13:44:19 volumio volumio[32108]: info: ------------------------------------------- Feb 17 13:44:20 volumio volumio-remote-updater[25144]: [2026-02-17 13:44:20] [connect] Successful connection Feb 17 13:44:21 volumio volumio[32108]: info: MYVOLUMIO Environment detected Feb 17 13:44:21 volumio volumio[32108]: info: Plugin folders cleanup Feb 17 13:44:21 volumio volumio[32108]: info: Scanning into folder /volumio/app/plugins/ Feb 17 13:44:21 volumio volumio[32108]: info: Scanning category audio_interface Feb 17 13:44:21 volumio volumio[32108]: info: Scanning category miscellanea Feb 17 13:44:21 volumio volumio[32108]: info: Scanning category music_service Feb 17 13:44:21 volumio volumio[32108]: info: Scanning category plugins.json Feb 17 13:44:21 volumio volumio[32108]: info: Scanning category system_controller Feb 17 13:44:21 volumio volumio[32108]: info: Scanning category user_interface Feb 17 13:44:21 volumio volumio[32108]: info: Scanning into folder /data/plugins/ Feb 17 13:44:21 volumio volumio[32108]: info: Scanning category music_service Feb 17 13:44:21 volumio volumio[32108]: info: Plugin folders cleanup completed Feb 17 13:44:21 volumio volumio[32108]: info: ------------------------------------------- Feb 17 13:44:21 volumio volumio[32108]: info: ----- Core plugins startup ---- Feb 17 13:44:21 volumio volumio[32108]: info: ------------------------------------------- Feb 17 13:44:21 volumio volumio[32108]: info: Loading plugins from folder /volumio/app/plugins/ Feb 17 13:44:21 volumio volumio[32108]: info: Adding plugin upnp to MyMusic Plugins Feb 17 13:44:21 volumio volumio[32108]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 17 13:44:21 volumio volumio[32108]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 17 13:44:21 volumio volumio[32108]: info: Loading plugins from folder /data/plugins/ Feb 17 13:44:21 volumio volumio[32108]: info: Loading plugin "system"... Feb 17 13:44:21 volumio volumio[32108]: info: Loading plugin "appearance"... Feb 17 13:44:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 17 13:44:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:44:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:44:22 volumio go-librespot[32145]: go-librespot daemon starting... Feb 17 13:44:22 volumio go-librespot[32146]: time="2026-02-17T13:44:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 13:44:22 volumio go-librespot[32146]: time="2026-02-17T13:44:22+07:00" level=debug msg="app state loaded" Feb 17 13:44:22 volumio go-librespot[32146]: time="2026-02-17T13:44:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 13:44:22 volumio go-librespot[32146]: time="2026-02-17T13:44:22+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 17 13:44:22 volumio go-librespot[32146]: time="2026-02-17T13:44:22+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 17 13:44:22 volumio go-librespot[32146]: time="2026-02-17T13:44:22+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 17 13:44:23 volumio go-librespot[32146]: time="2026-02-17T13:44:23+07:00" level=info msg="zeroconf server listening on port 43075" Feb 17 13:44:23 volumio volumio[32108]: info: Loading plugin "network"... Feb 17 13:44:23 volumio volumio[32108]: info: Refreshing Cached IP Addresses Feb 17 13:44:23 volumio go-librespot[32146]: time="2026-02-17T13:44:23+07:00" level=debug msg="obtained new client token: AACOawGutYFhKQ1hso/PcRMf4nMoHL3eI+yRWKPk0W7voJ2rYAczjUgSKH72Qxan9KwfZnt3ry0qhWNGYlmu+5pAQ26ylS1skptp3419RcbES4zgOYQhEaSFtz7XkrYoxCelwGKzPBuIXu3u9/hHZA/CbjhCvVyN6uActnPxkG5clSZwTsNUlr4xBxlsOyMK3fKZQexy2+nVmM5lfResWgwWFqZl+jdTlcJon8sqKgL+5INKAkDiUH8=" Feb 17 13:44:23 volumio sudo[32155]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 13:44:23 volumio sudo[32155]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:44:23 volumio sudo[32155]: pam_unix(sudo:session): session closed for user root Feb 17 13:44:23 volumio sudo[32157]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 13:44:23 volumio sudo[32157]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:44:23 volumio volumio[32108]: info: Loading plugin "services"... Feb 17 13:44:23 volumio sudo[32157]: pam_unix(sudo:session): session closed for user root Feb 17 13:44:23 volumio volumio[32108]: info: Loading plugin "alsa_controller"... Feb 17 13:44:23 volumio go-librespot[32146]: time="2026-02-17T13:44:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 13:44:23 volumio sudo[32165]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 17 13:44:23 volumio sudo[32165]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:44:23 volumio go-librespot[32146]: time="2026-02-17T13:44:23+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 17 13:44:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 13:44:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 13:44:23 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 13:44:23 volumio volumio[32108]: info: Loading plugin "wizard"... Feb 17 13:44:23 volumio volumio[32108]: info: Loading plugin "networkfs"... Feb 17 13:44:23 volumio volumio[32108]: info: Starting Udev Watcher for removable devices Feb 17 13:44:23 volumio volumio[32108]: info: Ignoring mount for partition: boot Feb 17 13:44:23 volumio volumio[32108]: info: Ignoring mount for partition: volumio Feb 17 13:44:23 volumio volumio[32108]: info: Ignoring mount for partition: volumio_data Feb 17 13:44:23 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 13:44:23 volumio volumio[32108]: info: Loading plugin "volumio_command_line_client"... Feb 17 13:44:23 volumio volumio[32108]: info: Loading plugin "upnp"... Feb 17 13:44:23 volumio volumio[32108]: info: [1771310663597] Starting Upmpd Daemon Feb 17 13:44:23 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 13:44:23 volumio volumio[32108]: info: Loading plugin "my_music"... Feb 17 13:44:23 volumio volumio[32108]: info: Loading plugin "mpd"... Feb 17 13:44:24 volumio volumio[32108]: info: Loading plugin "upnp_browser"... Feb 17 13:44:26 volumio sudo[32165]: pam_unix(sudo:session): session closed for user root Feb 17 13:44:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 17 13:44:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:44:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:44:26 volumio go-librespot[32188]: go-librespot daemon starting... Feb 17 13:44:26 volumio go-librespot[32189]: time="2026-02-17T13:44:26+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 13:44:26 volumio go-librespot[32189]: time="2026-02-17T13:44:26+07:00" level=debug msg="app state loaded" Feb 17 13:44:26 volumio go-librespot[32189]: time="2026-02-17T13:44:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 13:44:27 volumio go-librespot[32189]: time="2026-02-17T13:44:27+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 17 13:44:27 volumio go-librespot[32189]: time="2026-02-17T13:44:27+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 17 13:44:27 volumio go-librespot[32189]: time="2026-02-17T13:44:27+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 17 13:44:27 volumio volumio[32108]: info: Starting UPNP Browser Feb 17 13:44:27 volumio volumio[32108]: info: Loading plugin "alarm-clock"... Feb 17 13:44:27 volumio go-librespot[32189]: time="2026-02-17T13:44:27+07:00" level=info msg="zeroconf server listening on port 34979" Feb 17 13:44:27 volumio go-librespot[32189]: time="2026-02-17T13:44:27+07:00" level=debug msg="obtained new client token: AAADCwtaYX40c5vPsoe/o6IZTAfvk0K+3di48RnaawZOk0tEeACUzHmRCHKwP2xmDrD3eV48+ymCQMoL2/GhgLy6xR1r8N6slBNBIP4SwJIVSDrZgnji1Cq3RPh4eGGdhT5TRyqlEPfQsmlRunBzm2nAYm5AyQQiDIgxJhr4tXeOEo+8L3HVOMijURMcMZSDGyQud14/HeCyprZ3UuFw45IFKNLucc6mOunE5XRfS7XocRrWJVibUd2arA==" Feb 17 13:44:27 volumio volumio[32108]: info: Loading plugin "airplay_emulation"... Feb 17 13:44:27 volumio volumio[32108]: info: Starting Shairport Sync Feb 17 13:44:27 volumio go-librespot[32189]: time="2026-02-17T13:44:27+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 17 13:44:27 volumio volumio[32108]: info: Loading plugin "last_100"... Feb 17 13:44:27 volumio volumio[32108]: info: Loading plugin "webradio"... Feb 17 13:44:27 volumio go-librespot[32189]: time="2026-02-17T13:44:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 17 13:44:27 volumio go-librespot[32189]: time="2026-02-17T13:44:27+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 17 13:44:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 13:44:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 13:44:27 volumio volumio[32108]: info: Loading plugin "i2s_dacs"... Feb 17 13:44:27 volumio volumio[32108]: info: Loading plugin "volumiodiscovery"... Feb 17 13:44:27 volumio volumio[32108]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 13:44:27 volumio volumio[32108]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 13:44:27 volumio volumio[32108]: *** WARNING *** For more information see Feb 17 13:44:27 volumio volumio[32108]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 13:44:27 volumio volumio[32108]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 13:44:27 volumio volumio[32108]: *** WARNING *** For more information see Feb 17 13:44:27 volumio node[32108]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 13:44:27 volumio node[32108]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 13:44:27 volumio node[32108]: *** WARNING *** For more information see Feb 17 13:44:27 volumio node[32108]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 13:44:27 volumio node[32108]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 13:44:27 volumio node[32108]: *** WARNING *** For more information see Feb 17 13:44:27 volumio volumio[32108]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 17 13:44:27 volumio volumio[32108]: info: Discovery: Started advertising with name: Volumio Feb 17 13:44:27 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 13:44:27 volumio volumio[32108]: info: Loading plugin "spop"... Feb 17 13:44:29 volumio volumio[32108]: info: Loading plugin "ytcr"... Feb 17 13:44:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 17 13:44:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:44:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:44:30 volumio go-librespot[32198]: go-librespot daemon starting... Feb 17 13:44:30 volumio go-librespot[32199]: time="2026-02-17T13:44:30+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 13:44:30 volumio go-librespot[32199]: time="2026-02-17T13:44:30+07:00" level=debug msg="app state loaded" Feb 17 13:44:30 volumio go-librespot[32199]: time="2026-02-17T13:44:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 13:44:31 volumio go-librespot[32199]: time="2026-02-17T13:44:31+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 17 13:44:31 volumio go-librespot[32199]: time="2026-02-17T13:44:31+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 17 13:44:31 volumio go-librespot[32199]: time="2026-02-17T13:44:31+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 17 13:44:31 volumio go-librespot[32199]: time="2026-02-17T13:44:31+07:00" level=info msg="zeroconf server listening on port 33115" Feb 17 13:44:31 volumio go-librespot[32199]: time="2026-02-17T13:44:31+07:00" level=debug msg="obtained new client token: AADKch5S5NttkFvGlar/JX8QMs5aMMLffRqiLnbejLuFkI6HSF14HrSbQxZw5alqMxTgKTR+rgOH9W3M5Ju0mXNGOiIZU7T9n1IIY1BAWR7YXfeibtuPQYRJDotoNS++B44G71kc7Wa1ibhp96SK6zHkhXPhcsHvSlZs8puMnJRWiyKXKtahhZIHsvEdx1s1XhRlhAG+qcYmRZyXhJnS44pQqeM+i/lb+OMziHKtVR3ucf0mYUq5VqAgCg==" Feb 17 13:44:31 volumio go-librespot[32199]: time="2026-02-17T13:44:31+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 17 13:44:31 volumio go-librespot[32199]: time="2026-02-17T13:44:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 17 13:44:31 volumio go-librespot[32199]: time="2026-02-17T13:44:31+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 17 13:44:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 13:44:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 13:44:32 volumio volumio[32108]: info: Loading plugin "ytmusic"... Feb 17 13:44:33 volumio volumio-remote-updater[25144]: [2026-02-17 13:44:33] [connect] Successful connection Feb 17 13:44:33 volumio volumio[32108]: info: Loading plugin "outputs"... Feb 17 13:44:33 volumio volumio[32108]: info: Loading plugin "albumart"... Feb 17 13:44:33 volumio volumio[32108]: info: Plugin example_plugin is not enabled Feb 17 13:44:33 volumio volumio[32108]: info: Loading plugin "inputs"... Feb 17 13:44:33 volumio volumio[32108]: info: Loading plugin "updater_comm"... Feb 17 13:44:33 volumio volumio[32108]: info: Plugin mpdemulation is not enabled Feb 17 13:44:33 volumio volumio[32108]: info: Loading plugin "rest_api"... Feb 17 13:44:33 volumio volumio[32108]: info: Loading plugin "websocket"... Feb 17 13:44:33 volumio volumio[32108]: info: Starting Socket.io Server version 1.7.4 Feb 17 13:44:33 volumio volumio[32108]: info: Loading plugin "RoonBridge"... Feb 17 13:44:34 volumio volumio[32108]: info: Applying required configuration parameters for plugin RoonBridge Feb 17 13:44:34 volumio volumio[32108]: info: Loading i18n strings for locale en Feb 17 13:44:34 volumio volumio[32108]: Updating browse sources language Feb 17 13:44:34 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 13:44:34 volumio volumio[32221]: Forking 3 albumart workers Feb 17 13:44:34 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 13:44:34 volumio volumio[32108]: info: CoreCommandRouter::initPlayerControls Feb 17 13:44:34 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:44:34 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:44:34 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:44:34 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:44:34 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:44:34 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:44:34 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:44:34 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:44:34 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 13:44:34 volumio volumio[32108]: Express server listening on port 3000 Feb 17 13:44:34 volumio volumio[32108]: [Metrics] WebUI: 15s 935.15ms Feb 17 13:44:34 volumio volumio[32108]: info: CoreStateMachine::resetVolumioState Feb 17 13:44:34 volumio volumio[32108]: info: CoreStateMachine::getcurrentVolume Feb 17 13:44:34 volumio volumio[32108]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 13:44:34 volumio sudo[32265]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 13:44:34 volumio sudo[32265]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:44:34 volumio sudo[32265]: pam_unix(sudo:session): session closed for user root Feb 17 13:44:34 volumio sudo[32267]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 13:44:34 volumio sudo[32267]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:44:34 volumio sudo[32267]: pam_unix(sudo:session): session closed for user root Feb 17 13:44:34 volumio volumio[32108]: info: Volumio Network Manager: Network status updated: 1 Feb 17 13:44:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 17 13:44:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:44:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:44:35 volumio go-librespot[32274]: go-librespot daemon starting... Feb 17 13:44:35 volumio go-librespot[32275]: time="2026-02-17T13:44:35+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 13:44:35 volumio go-librespot[32275]: time="2026-02-17T13:44:35+07:00" level=debug msg="app state loaded" Feb 17 13:44:35 volumio go-librespot[32275]: time="2026-02-17T13:44:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 13:44:35 volumio volumio-remote-updater[25144]: [2026-02-17 13:44:35] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771310673 101 Feb 17 13:44:35 volumio volumio[32108]: 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 17 13:44:35 volumio volumio[32108]: info: VolumeController:: Volume=100 Mute =false Feb 17 13:44:35 volumio volumio[32108]: info: CoreStateMachine::pushState Feb 17 13:44:35 volumio volumio[32108]: info: CorePlayQueue::getTrack 0 Feb 17 13:44:35 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 13:44:35 volumio volumio[32108]: info: CoreCommandRouter::volumioPushState Feb 17 13:44:35 volumio volumio[32108]: info: CoreStateMachine::updateTrackBlock Feb 17 13:44:35 volumio volumio[32108]: info: CorePlayQueue::getTrackBlock Feb 17 13:44:35 volumio volumio[32108]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 13:44:35 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 13:44:35 volumio volumio[32108]: info: Reloading queue from file Feb 17 13:44:35 volumio volumio[32108]: info: CoreStateMachine::setRepeat null single undefined Feb 17 13:44:35 volumio volumio[32108]: info: CoreStateMachine::pushState Feb 17 13:44:35 volumio volumio[32108]: info: CorePlayQueue::getTrack 0 Feb 17 13:44:35 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 13:44:35 volumio volumio[32108]: info: CoreCommandRouter::volumioPushState Feb 17 13:44:35 volumio volumio[32108]: info: CoreStateMachine::setRandom null Feb 17 13:44:35 volumio volumio[32108]: info: CoreStateMachine::pushState Feb 17 13:44:35 volumio volumio[32108]: info: CorePlayQueue::getTrack 0 Feb 17 13:44:35 volumio volumio[32108]: info: CoreCommandRouter::volumioPushState Feb 17 13:44:35 volumio volumio[32108]: info: Setting Device type: Raspberry PI Feb 17 13:44:35 volumio volumio[32108]: info: Completed loading Core Plugins Feb 17 13:44:35 volumio volumio[32108]: info: Preparing to generate the ALSA configuration file Feb 17 13:44:35 volumio go-librespot[32275]: time="2026-02-17T13:44: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 17 13:44:35 volumio go-librespot[32275]: time="2026-02-17T13:44: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 17 13:44:35 volumio go-librespot[32275]: time="2026-02-17T13:44: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 17 13:44:35 volumio volumio[32108]: info: VolumeController:: Volume=100 Mute =false Feb 17 13:44:35 volumio volumio[32108]: info: CoreStateMachine::pushState Feb 17 13:44:35 volumio volumio[32108]: info: CorePlayQueue::getTrack 0 Feb 17 13:44:35 volumio volumio[32108]: info: CoreCommandRouter::volumioPushState Feb 17 13:44:35 volumio go-librespot[32275]: time="2026-02-17T13:44:35+07:00" level=info msg="zeroconf server listening on port 45853" Feb 17 13:44:35 volumio volumio[32108]: info: Asound.conf file unchanged, so no further update is needed Feb 17 13:44:35 volumio volumio[32108]: info: Output device has changed, restarting MPD Feb 17 13:44:36 volumio volumio[32108]: info: Output device has changed, restarting Shairport Sync Feb 17 13:44:36 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:44:36 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 13:44:36 volumio sudo[32292]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 17 13:44:36 volumio sudo[32292]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:44:36 volumio sudo[32295]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 13:44:36 volumio sudo[32295]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:44:36 volumio sudo[32295]: pam_unix(sudo:session): session closed for user root Feb 17 13:44:36 volumio volumio[32108]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 13:44:36 volumio sudo[32292]: pam_unix(sudo:session): session closed for user root Feb 17 13:44:36 volumio go-librespot[32275]: time="2026-02-17T13:44:36+07:00" level=debug msg="obtained new client token: AAA3mwZ3R6l77YzhlBfQYOFdDiIDVlWEctM2fsqgS797OgcjqhZ2q5DR7Re+8rG/POJTbt94f4DqGJU5CwvfLnSxVuHVh/oF5cZI9Z1niIkdRW+ZRfeiXIDcKTptaha+y5Fp53NLgA5PNZSaFOdkqA6uokypK98ABHCeFBP3MSAejFsGYIAW8s4TvCocyIkxg35+gHYsPZSVMly79Dy04D/bnyG2nLHl6b+fYfMNWQpQcPaA6TEb+vk=" Feb 17 13:44:36 volumio sudo[32296]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 13:44:36 volumio volumio[32108]: info: ___________ START PLUGINS ___________ Feb 17 13:44:36 volumio sudo[32296]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:44:36 volumio volumio[32108]: info: ControllerMpd::onStart: Initializing MPD Feb 17 13:44:36 volumio volumio[32108]: info: Creating MPD Configuration file Feb 17 13:44:36 volumio go-librespot[32275]: time="2026-02-17T13:44:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 13:44:36 volumio sudo[32307]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 13:44:36 volumio sudo[32307]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:44:36 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 17 13:44:36 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 13:44:36 volumio sudo[32307]: pam_unix(sudo:session): session closed for user root Feb 17 13:44:36 volumio volumio[32108]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 13:44:36 volumio volumio[32108]: info: [1771310676348] CoreMusicLibrary::Adding element Media Servers Feb 17 13:44:36 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 13:44:36 volumio sudo[32310]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 13:44:36 volumio sudo[32310]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:44:36 volumio go-librespot[32275]: time="2026-02-17T13:44:36+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 17 13:44:36 volumio volumio[32108]: info: UPNP Browser: Client initialized successfully Feb 17 13:44:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 13:44:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 13:44:36 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 17 13:44:36 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 13:44:36 volumio systemd[1]: mpd.service: Consumed 7.017s CPU time. Feb 17 13:44:36 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 17 13:44:36 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 13:44:36 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 13:44:36 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:44:36 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 13:44:36 volumio volumio[32108]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 13:44:36 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:44:36 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 13:44:36 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 13:44:36 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 13:44:36 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 17 13:44:36 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 13:44:36 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 17 13:44:36 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 13:44:36 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 13:44:36 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 13:44:36 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 13:44:36 volumio volumio[32108]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 13:44:36 volumio volumio[32108]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 13:44:36 volumio volumio[32108]: info: [1771310676741] CoreMusicLibrary::Adding element Last_100 Feb 17 13:44:36 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 13:44:36 volumio volumio[32108]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 13:44:36 volumio volumio[32108]: info: [1771310676750] CoreMusicLibrary::Adding element Webradio Feb 17 13:44:36 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 13:44:36 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 13:44:36 volumio volumio[32108]: info: Initializing BBC Radios Feb 17 13:44:36 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 13:44:36 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 13:44:36 volumio volumio[32108]: info: Creating Spotify config file Feb 17 13:44:36 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:44:37 volumio sudo[32323]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 17 13:44:37 volumio sudo[32323]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 17 13:44:37 volumio sudo[32323]: pam_unix(sudo:session): session closed for user root Feb 17 13:44:37 volumio volumio[32108]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 13:44:37 volumio volumio[32108]: info: [1771310677918] CoreMusicLibrary::Adding element YouTube Music Feb 17 13:44:37 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 13:44:37 volumio volumio[32108]: Cannot find translation for source YouTube Music Feb 17 13:44:37 volumio volumio[32233]: Starting albumart workers Feb 17 13:44:37 volumio volumio[32108]: info: Volumio Calling Home Feb 17 13:44:38 volumio sudo[32340]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 17 13:44:38 volumio sudo[32340]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:44:38 volumio sudo[32340]: pam_unix(sudo:session): session closed for user root Feb 17 13:44:38 volumio volumio[32232]: Starting albumart workers Feb 17 13:44:38 volumio volumio[32231]: Starting albumart workers Feb 17 13:44:38 volumio volumio[32108]: info: MPD Permissions set Feb 17 13:44:38 volumio volumio[32108]: info: MPD Permissions set Feb 17 13:44:38 volumio volumio[32108]: info: Upmpdcli Daemon Started Feb 17 13:44:38 volumio volumio[32108]: info: Spotify config file written Feb 17 13:44:38 volumio volumio[32108]: 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 17 13:44:38 volumio sudo[32346]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 17 13:44:38 volumio sudo[32346]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:44:38 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:44:38 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:44:38 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:44:38 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:44:38 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:44:38 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:44:38 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:44:38 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:44:38 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 13:44:38 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:44:38 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:44:38 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:44:38 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:44:38 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:44:38 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:44:38 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:44:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:44:38 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:44:38 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:44:39 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 13:44:39 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 13:44:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:44:39 volumio go-librespot[32353]: go-librespot daemon starting... Feb 17 13:44:39 volumio volumio[32108]: info: No need to fix Spotify hosts Feb 17 13:44:39 volumio sudo[32346]: pam_unix(sudo:session): session closed for user root Feb 17 13:44:39 volumio go-librespot[32359]: time="2026-02-17T13:44:39+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 13:44:39 volumio go-librespot[32359]: time="2026-02-17T13:44:39+07:00" level=debug msg="app state loaded" Feb 17 13:44:39 volumio go-librespot[32359]: time="2026-02-17T13:44:39+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 13:44:39 volumio volumio[32108]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 13:44:39 volumio volumio[32108]: info: Discovery: Found device Volumio Feb 17 13:44:39 volumio volumio[32108]: info: CoreCommandRouter::volumioGetState Feb 17 13:44:39 volumio volumio[32108]: info: CorePlayQueue::getTrack 0 Feb 17 13:44:39 volumio volumio[32108]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 13:44:39 volumio volumio[32108]: info: Discovery: Found device Volumio Feb 17 13:44:39 volumio volumio[32108]: info: CoreCommandRouter::volumioGetState Feb 17 13:44:39 volumio volumio[32108]: info: CorePlayQueue::getTrack 0 Feb 17 13:44:39 volumio volumio[32108]: info: Volumio called home Feb 17 13:44:39 volumio go-librespot[32359]: time="2026-02-17T13:44: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-gew1.spotify.com:80]" Feb 17 13:44:39 volumio go-librespot[32359]: time="2026-02-17T13:44:39+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 17 13:44:39 volumio go-librespot[32359]: time="2026-02-17T13:44:39+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 17 13:44:39 volumio go-librespot[32359]: time="2026-02-17T13:44:39+07:00" level=info msg="zeroconf server listening on port 44977" Feb 17 13:44:40 volumio go-librespot[32359]: time="2026-02-17T13:44:40+07:00" level=debug msg="obtained new client token: AAAfxTWsynF9K9RpVDKXSHJT2+D5cSPG0nrlpH2uT3X56Gt/pch+GupG19RNjxptr30RdsrC2k4t5vwpOJ1BeoW2Qgkj/vh35dieZ29MwwBkYM0Dj0txzuiVCVb/XWs06YxLLop+hSVfvp8RZTCQCX1f9f0ghiz7EG1iKNV3dP15ipiA5Ea1y8SDfI0hQVlhG9BIM5HJGUgBM434zEN8djwymDRMRicH99fRBHRnzfNJ+EuYSlGL9e8=" Feb 17 13:44:40 volumio go-librespot[32359]: time="2026-02-17T13:44:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 13:44:40 volumio go-librespot[32359]: time="2026-02-17T13:44:40+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 17 13:44:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 13:44:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 13:44:40 volumio volumio[32108]: info: Starting Shairport Sync Feb 17 13:44:40 volumio volumio[32108]: info: Starting Shairport Sync Feb 17 13:44:40 volumio volumio[32108]: info: Starting Shairport Sync Feb 17 13:44:40 volumio sudo[32386]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 13:44:40 volumio sudo[32386]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:44:40 volumio sudo[32388]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 13:44:40 volumio sudo[32388]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:44:40 volumio sudo[32390]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 13:44:40 volumio sudo[32390]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:44:40 volumio volumio[32108]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 13:44:40 volumio volumio[32108]: SPOTIFY: BQDMM_m5qPZ7byh_msvYP0yqGsSLiq-JCYweFK5oSI7c4eBHNv-LZibSzBY-ACKMTaglyCachRPe8JJBStPd1AoZviWFo3rF9hhEyB392OOb4Ap1SmJwYWr3__QSYJoz57G5r9njNCJ5DRFkfmlvxKbsq7rzuNJ8TqTKLKQewixnat5S5FDtYjnxaBEZYu3Q3JUTJWZBWcCn7Jqr4jSNTt12qTL4ESE9BRXrPXTqydr8E44paghFcVjdoFxNqA35XZaUhhhyJLOeq-TZeHahnrJdYi8jLsBvnHfWfq695QVDtqRHVO2VXNj1 Feb 17 13:44:40 volumio volumio[32108]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 13:44:40 volumio volumio[32108]: info: New Spotify access token = BQDMM_m5qPZ7byh_msvYP0yqGsSLiq-JCYweFK5oSI7c4eBHNv-LZibSzBY-ACKMTaglyCachRPe8JJBStPd1AoZviWFo3rF9hhEyB392OOb4Ap1SmJwYWr3__QSYJoz57G5r9njNCJ5DRFkfmlvxKbsq7rzuNJ8TqTKLKQewixnat5S5FDtYjnxaBEZYu3Q3JUTJWZBWcCn7Jqr4jSNTt12qTL4ESE9BRXrPXTqydr8E44paghFcVjdoFxNqA35XZaUhhhyJLOeq-TZeHahnrJdYi8jLsBvnHfWfq695QVDtqRHVO2VXNj1 Feb 17 13:44:40 volumio volumio[32108]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 17 13:44:41 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 17 13:44:41 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 17 13:44:41 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 13:44:41 volumio systemd[1]: shairport-sync.service: Consumed 2.311s CPU time. Feb 17 13:44:41 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 13:44:41 volumio sudo[32386]: pam_unix(sudo:session): session closed for user root Feb 17 13:44:41 volumio sudo[32390]: pam_unix(sudo:session): session closed for user root Feb 17 13:44:41 volumio volumio[32108]: info: Shairport-Sync Started Feb 17 13:44:41 volumio volumio[32108]: Error adding Membership: Error: addMembership EINVAL Feb 17 13:44:41 volumio sudo[32388]: pam_unix(sudo:session): session closed for user root Feb 17 13:44:41 volumio volumio[32108]: info: CoreCommandRouter::volumioGetState Feb 17 13:44:41 volumio volumio[32108]: info: CorePlayQueue::getTrack 0 Feb 17 13:44:41 volumio volumio[32108]: info: Shairport-Sync Started Feb 17 13:44:41 volumio volumio[32108]: info: Shairport-Sync Started Feb 17 13:44:41 volumio volumio[32108]: 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 17 13:44:41 volumio volumio[32108]: info: Spotify Successfully logged in Feb 17 13:44:41 volumio volumio[32108]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 13:44:41 volumio volumio[32108]: info: [1771310681599] CoreMusicLibrary::Adding element Spotify Feb 17 13:44:41 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 13:44:41 volumio volumio[32108]: Cannot find translation for source YouTube Music Feb 17 13:44:41 volumio volumio[32108]: Cannot find translation for source Spotify Feb 17 13:44:42 volumio volumio[32108]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 17 13:44:42 volumio volumio[32108]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 13:44:42 volumio volumio[32108]: info: VolumeController:: Volume=100 Mute =false Feb 17 13:44:42 volumio volumio[32108]: info: CoreCommandRouter::volumioGetState Feb 17 13:44:42 volumio volumio[32108]: info: CorePlayQueue::getTrack 0 Feb 17 13:44:42 volumio volumio[32108]: info: CoreStateMachine::pushState Feb 17 13:44:42 volumio volumio[32108]: info: CorePlayQueue::getTrack 0 Feb 17 13:44:42 volumio volumio[32108]: info: CoreCommandRouter::volumioPushState Feb 17 13:44:43 volumio volumio[32108]: info: go-librespot daemon successfully initialized Feb 17 13:44:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 17 13:44:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:44:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:44:43 volumio go-librespot[32426]: go-librespot daemon starting... Feb 17 13:44:43 volumio go-librespot[32427]: time="2026-02-17T13:44:43+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 13:44:43 volumio go-librespot[32427]: time="2026-02-17T13:44:43+07:00" level=debug msg="app state loaded" Feb 17 13:44:43 volumio go-librespot[32427]: time="2026-02-17T13:44:43+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 13:44:44 volumio mpd[32338]: 2026-02-17T13:44:44 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 17 13:44:44 volumio go-librespot[32427]: time="2026-02-17T13:44: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 17 13:44:44 volumio go-librespot[32427]: time="2026-02-17T13:44: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 17 13:44:44 volumio go-librespot[32427]: time="2026-02-17T13:44: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 17 13:44:44 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 17 13:44:44 volumio sudo[32310]: pam_unix(sudo:session): session closed for user root Feb 17 13:44:44 volumio sudo[32296]: pam_unix(sudo:session): session closed for user root Feb 17 13:44:44 volumio go-librespot[32427]: time="2026-02-17T13:44:44+07:00" level=info msg="zeroconf server listening on port 35221" Feb 17 13:44:44 volumio volumio[32108]: error: MPD error: The expression evaluated to a falsy value: Feb 17 13:44:44 volumio volumio[32108]: assert.ok(self.idling) Feb 17 13:44:44 volumio volumio[32108]: error: The expression evaluated to a falsy value: Feb 17 13:44:44 volumio volumio[32108]: assert.ok(self.idling) Feb 17 13:44:44 volumio go-librespot[32427]: time="2026-02-17T13:44:44+07:00" level=debug msg="obtained new client token: AAA62+MFmobWSMr7uKXVSs0PvMmAj5kteomq6OuikdSpdIr0LfBTrSb+Q0g83NPG42xv+mV2EH6x0axIGPZ+y1eWTK5yJKBVxjWw7D7B5FK/SO6YMcybjuv1aL+YWB1oXVc5OFStd7C5YEyKAEH+iNPXhvXHKTT8c95xqhWTBY3Qn5hERZ7gLMS4MkrfPukrk4GynYJKEp3rF8tXUogiFlZtFyxsbi4lOBS8CtAYY7r/PPwWc6b1buL1Xw==" Feb 17 13:44:44 volumio volumio[32108]: info: MPD running with PID32338 Feb 17 13:44:44 volumio volumio[32108]: ,establishing connection Feb 17 13:44:44 volumio volumio[32108]: error: updateQueue error: null Feb 17 13:44:44 volumio volumio[32108]: info: Completed starting Core Plugins Feb 17 13:44:44 volumio volumio[32108]: info: ------------------------------------------- Feb 17 13:44:44 volumio volumio[32108]: info: ----- MyVolumio plugins startup ---- Feb 17 13:44:44 volumio volumio[32108]: info: ------------------------------------------- Feb 17 13:44:44 volumio volumio[32108]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 17 13:44:44 volumio volumio[32108]: error: updateQueue error: null Feb 17 13:44:44 volumio go-librespot[32427]: time="2026-02-17T13:44:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 13:44:44 volumio go-librespot[32427]: time="2026-02-17T13:44:44+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 17 13:44:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 13:44:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 13:44:46 volumio volumio[32108]: info: Initializing connection to go-librespot Websocket Feb 17 13:44:46 volumio volumio[32108]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 13:44:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 17 13:44:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:44:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:44:47 volumio go-librespot[32438]: go-librespot daemon starting... Feb 17 13:44:47 volumio go-librespot[32440]: time="2026-02-17T13:44:47+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 13:44:47 volumio go-librespot[32440]: time="2026-02-17T13:44:47+07:00" level=debug msg="app state loaded" Feb 17 13:44:47 volumio go-librespot[32440]: time="2026-02-17T13:44:47+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 13:44:48 volumio go-librespot[32440]: time="2026-02-17T13:44: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 13:44:48 volumio go-librespot[32440]: time="2026-02-17T13:44:48+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 17 13:44:48 volumio go-librespot[32440]: time="2026-02-17T13:44:48+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 17 13:44:48 volumio go-librespot[32440]: time="2026-02-17T13:44:48+07:00" level=info msg="zeroconf server listening on port 35551" Feb 17 13:44:48 volumio go-librespot[32440]: time="2026-02-17T13:44:48+07:00" level=debug msg="obtained new client token: AACxTw3krrEYOmPMKVSatC+lWR13nyTLxtT2z/rtNqwqndSNq1CsnWXRFKRZ63nUAjlaw7wf7wGyF2bMh35vBnqWpjwLVXIURgD83t0bNbv2x0HRFKGN/v+WbeFoKr2RmtfsWRMpCpzR0b6Omao/9dCvkyiup6vwC4lPDpfoxGqkZAdmBav4kGS5c9liOhvsN4+dDUFJg9OHJqgrVKgiVP0//QZehVogCBFKkSSLAMSIQrYuHYDhWLG36Q==" Feb 17 13:44:48 volumio go-librespot[32440]: time="2026-02-17T13:44:48+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 13:44:48 volumio go-librespot[32440]: time="2026-02-17T13:44:48+07:00" level=debug msg="completed keyexchange" Feb 17 13:44:48 volumio go-librespot[32440]: time="2026-02-17T13:44:48+07:00" level=debug msg="completed challenge" Feb 17 13:44:48 volumio go-librespot[32440]: time="2026-02-17T13:44:48+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 17 13:44:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 13:44:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 13:44:49 volumio volumio[32108]: info: Initializing connection to go-librespot Websocket Feb 17 13:44:49 volumio volumio[32108]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 13:44:49 volumio volumio[32108]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 17 13:44:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 17 13:44:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:44:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:44:52 volumio go-librespot[32448]: go-librespot daemon starting... Feb 17 13:44:52 volumio go-librespot[32449]: time="2026-02-17T13:44:52+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 13:44:52 volumio go-librespot[32449]: time="2026-02-17T13:44:52+07:00" level=debug msg="app state loaded" Feb 17 13:44:52 volumio go-librespot[32449]: time="2026-02-17T13:44:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 13:44:52 volumio volumio[32108]: info: Initializing connection to go-librespot Websocket Feb 17 13:44:52 volumio go-librespot[32449]: time="2026-02-17T13:44:52+07:00" level=debug msg="new websocket client" Feb 17 13:44:52 volumio volumio[32108]: info: Connection to go-librespot Websocket established Feb 17 13:44:52 volumio go-librespot[32449]: time="2026-02-17T13:44:52+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 17 13:44:52 volumio go-librespot[32449]: time="2026-02-17T13:44:52+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 17 13:44:52 volumio go-librespot[32449]: time="2026-02-17T13:44:52+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 17 13:44:52 volumio go-librespot[32449]: time="2026-02-17T13:44:52+07:00" level=info msg="zeroconf server listening on port 33285" Feb 17 13:44:52 volumio go-librespot[32449]: time="2026-02-17T13:44:52+07:00" level=debug msg="obtained new client token: AACW8nPrTdnEMaoa5YPt0Xbu0ydaXNeZw1LH9AlM8gtxaJ8C/mUQPmO5NVgbj0sLpejkuqKH1CTRQe4QWeWOcTz3p43ydQQe/6Og6t3IqyDR9FH0bLlyGDnp2f54ZgOnvo9Ri5PyVUb40uaJkFrVnFTriRrKE3XFfE7vN1hS0chzsH/zNwT9NIwwfSYyi6GPn4ZWTxiDnYj7l511czP7YlaELcM6J4PTqEe7U/rk8m8usMzWZyqaD1h7Wg==" Feb 17 13:44:52 volumio go-librespot[32449]: time="2026-02-17T13:44:52+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 13:44:53 volumio go-librespot[32449]: time="2026-02-17T13:44:53+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 17 13:44:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 13:44:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 13:44:53 volumio volumio[32108]: info: Connection to go-librespot Websocket closed Feb 17 13:44:53 volumio volumio[32108]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 17 13:44:53 volumio volumio[32108]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 17 13:44:53 volumio volumio[32108]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 17 13:44:53 volumio volumio[32108]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 17 13:44:53 volumio volumio[32108]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 17 13:44:53 volumio volumio[32108]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 17 13:44:53 volumio volumio[32108]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 17 13:44:53 volumio volumio[32108]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 17 13:44:53 volumio volumio[32108]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 17 13:44:53 volumio volumio[32108]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 17 13:44:53 volumio volumio[32108]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 17 13:44:53 volumio volumio[32108]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 17 13:44:53 volumio volumio[32108]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 17 13:44:53 volumio volumio[32108]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 17 13:44:53 volumio volumio[32108]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 17 13:44:53 volumio volumio[32108]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 17 13:44:53 volumio volumio[32108]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 17 13:44:53 volumio volumio[32108]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 17 13:44:53 volumio volumio[32108]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 17 13:44:53 volumio volumio[32108]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 17 13:44:53 volumio volumio[32108]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 17 13:44:53 volumio volumio[32108]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 17 13:44:53 volumio volumio[32108]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 17 13:44:53 volumio volumio[32108]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 17 13:44:53 volumio volumio[32108]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 17 13:44:53 volumio volumio[32108]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 17 13:44:53 volumio volumio[32108]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 17 13:44:53 volumio volumio[32108]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 17 13:44:53 volumio volumio[32108]: info: Adding plugin bluetooth to MyMusic Plugins Feb 17 13:44:53 volumio volumio[32108]: info: Adding plugin multiroom to MyMusic Plugins Feb 17 13:44:53 volumio volumio[32108]: info: Adding plugin metavolumio to MyMusic Plugins Feb 17 13:44:53 volumio volumio[32108]: info: Adding plugin cd_controller to MyMusic Plugins Feb 17 13:44:53 volumio volumio[32108]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 17 13:44:53 volumio volumio[32108]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 17 13:44:53 volumio volumio[32108]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 17 13:44:53 volumio volumio[32108]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 17 13:44:55 volumio volumio[32108]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 17 13:44:55 volumio volumio[32108]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 17 13:44:55 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 13:44:55 volumio volumio[32108]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 13:44:55 volumio volumio[32108]: info: Starting MyVolumio Remote Streaming Endpoints Feb 17 13:44:55 volumio volumio[32108]: info: MyVolumio login type: Token Feb 17 13:44:55 volumio volumio[32108]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 17 13:44:55 volumio volumio[32108]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 17 13:44:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Feb 17 13:44:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:44:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 13:44:56 volumio go-librespot[32470]: go-librespot daemon starting... Feb 17 13:44:56 volumio go-librespot[32471]: time="2026-02-17T13:44:56+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 13:44:56 volumio go-librespot[32471]: time="2026-02-17T13:44:56+07:00" level=debug msg="app state loaded" Feb 17 13:44:56 volumio go-librespot[32471]: time="2026-02-17T13:44:56+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 13:44:56 volumio go-librespot[32471]: time="2026-02-17T13:44:56+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 17 13:44:56 volumio go-librespot[32471]: time="2026-02-17T13:44:56+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 17 13:44:56 volumio go-librespot[32471]: time="2026-02-17T13:44:56+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 17 13:44:56 volumio go-librespot[32471]: time="2026-02-17T13:44:56+07:00" level=info msg="zeroconf server listening on port 42553" Feb 17 13:44:56 volumio go-librespot[32471]: time="2026-02-17T13:44:56+07:00" level=debug msg="obtained new client token: AADgBxxgo2nXJ+JAw5o3S3t1+Id0uaKVqYv+DoCM3XHHuMnX0uKNE543T3mFkr5otPoUCC4glNKf/94mfSQjmi4KsFqUk52wE5fTqc+rXF/WY98tFlsgqJIRgYtDfXW/brVlR0XAQtuSDGrOuJDD/N7EpKD9ZPAzkLpEJ42I42zm0QLMizpKpflS3q5/fl4njaFtsjroOyiXczJjmBAOsd2Z/wLl9LP702x3X1xnxKW837Cnpu6lKERQQA==" Feb 17 13:44:57 volumio go-librespot[32471]: time="2026-02-17T13:44:57+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 13:44:57 volumio volumio[32108]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 17 13:44:57 volumio volumio[32108]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 17 13:44:57 volumio volumio[32108]: info: Streaming services startup Feb 17 13:44:57 volumio volumio[32108]: info: Starting Streaming Daemon Feb 17 13:44:57 volumio sudo[32481]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 17 13:44:57 volumio sudo[32481]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 13:44:57 volumio volumio[32108]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 17 13:44:57 volumio go-librespot[32471]: time="2026-02-17T13:44:57+07:00" level=debug msg="completed keyexchange" Feb 17 13:44:57 volumio go-librespot[32471]: time="2026-02-17T13:44:57+07:00" level=debug msg="completed challenge" Feb 17 13:44:57 volumio sudo[32481]: pam_unix(sudo:session): session closed for user root Feb 17 13:44:57 volumio go-librespot[32471]: time="2026-02-17T13:44:57+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 17 13:44:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 13:44:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 13:44:57 volumio volumio[32108]: info: Getting Spotify volume Feb 17 13:44:57 volumio volumio[32108]: info: Initializing connection to go-librespot Websocket Feb 17 13:44:57 volumio volumio[32108]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 13:44:57 volumio volumio[32108]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 13:44:57 volumio volumio[32108]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 17 13:44:57 volumio volumio[32108]: errno: -111, Feb 17 13:44:57 volumio volumio[32108]: code: 'ECONNREFUSED', Feb 17 13:44:57 volumio volumio[32108]: syscall: 'connect', Feb 17 13:44:57 volumio volumio[32108]: address: '127.0.0.1', Feb 17 13:44:57 volumio volumio[32108]: port: 9879, Feb 17 13:44:57 volumio volumio[32108]: response: undefined Feb 17 13:44:57 volumio volumio[32108]: } Feb 17 13:44:57 volumio volumio[32108]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 13:44:58 volumio sudo[32501]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-17 13:43' Feb 17 13:44:58 volumio sudo[32501]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="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"