Feb 10 20:10:00 volumio volumio[15878]: info: ControllerMpd::onStart: Initializing MPD Feb 10 20:10:00 volumio volumio[15878]: info: Creating MPD Configuration file Feb 10 20:10:00 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 10 20:10:00 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 20:10:00 volumio volumio[15878]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 20:10:00 volumio volumio[15878]: info: [1770729000152] CoreMusicLibrary::Adding element Media Servers Feb 10 20:10:00 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 20:10:00 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 10 20:10:00 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 10 20:10:00 volumio systemd[1]: mpd.service: Consumed 7.129s CPU time. Feb 10 20:10:00 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 10 20:10:00 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 10 20:10:00 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 10 20:10:00 volumio sudo[16075]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 20:10:00 volumio sudo[16075]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:10:00 volumio sudo[16073]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 20:10:00 volumio sudo[16073]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:10:00 volumio volumio[15878]: info: UPNP Browser: Client initialized successfully Feb 10 20:10:00 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 10 20:10:00 volumio sudo[16073]: pam_unix(sudo:session): session closed for user root Feb 10 20:10:00 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 10 20:10:00 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:00 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 20:10:00 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 10 20:10:00 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 10 20:10:00 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 10 20:10:00 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 10 20:10:00 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 10 20:10:00 volumio volumio[15878]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 20:10:00 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:00 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 20:10:00 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 10 20:10:00 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 10 20:10:00 volumio volumio[15878]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 20:10:00 volumio volumio[15878]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 20:10:00 volumio volumio[15878]: info: [1770729000514] CoreMusicLibrary::Adding element Last_100 Feb 10 20:10:00 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 20:10:00 volumio volumio[15878]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 20:10:00 volumio volumio[15878]: info: [1770729000531] CoreMusicLibrary::Adding element Webradio Feb 10 20:10:00 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 20:10:00 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 20:10:00 volumio volumio[15878]: info: Initializing BBC Radios Feb 10 20:10:00 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 20:10:00 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 20:10:00 volumio volumio[15878]: info: Creating Spotify config file Feb 10 20:10:00 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:00 volumio sudo[16089]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 10 20:10:00 volumio sudo[16089]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 10 20:10:00 volumio sudo[16089]: pam_unix(sudo:session): session closed for user root Feb 10 20:10:01 volumio volumio[16008]: Starting albumart workers Feb 10 20:10:01 volumio volumio[16010]: Starting albumart workers Feb 10 20:10:01 volumio volumio[15878]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 20:10:01 volumio volumio[15878]: info: [1770729001977] CoreMusicLibrary::Adding element YouTube Music Feb 10 20:10:01 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 20:10:01 volumio volumio[15878]: Cannot find translation for source YouTube Music Feb 10 20:10:02 volumio volumio[16009]: Starting albumart workers Feb 10 20:10:02 volumio volumio[15878]: info: Volumio Calling Home Feb 10 20:10:02 volumio sudo[16106]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 10 20:10:02 volumio sudo[16106]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:10:02 volumio sudo[16106]: pam_unix(sudo:session): session closed for user root Feb 10 20:10:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 10 20:10:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:10:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:10:02 volumio go-librespot[16111]: go-librespot daemon starting... Feb 10 20:10:02 volumio go-librespot[16112]: time="2026-02-10T20:10:02+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 20:10:03 volumio volumio[15878]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 10 20:10:03 volumio volumio[15878]: info: Discovery: Found device Volumio Feb 10 20:10:03 volumio volumio[15878]: info: CoreCommandRouter::volumioGetState Feb 10 20:10:03 volumio volumio[15878]: info: CorePlayQueue::getTrack 0 Feb 10 20:10:03 volumio volumio[15878]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 10 20:10:03 volumio volumio[15878]: info: Discovery: Found device Volumio Feb 10 20:10:03 volumio volumio[15878]: info: CoreCommandRouter::volumioGetState Feb 10 20:10:03 volumio volumio[15878]: info: CorePlayQueue::getTrack 0 Feb 10 20:10:03 volumio go-librespot[16112]: time="2026-02-10T20:10:03+07:00" level=info msg="zeroconf server listening on port 45649" Feb 10 20:10:03 volumio volumio[15878]: info: MPD Permissions set Feb 10 20:10:03 volumio volumio[15878]: info: MPD Permissions set Feb 10 20:10:03 volumio volumio[15878]: info: Upmpdcli Daemon Started Feb 10 20:10:03 volumio volumio[15878]: info: Volumio called home Feb 10 20:10:03 volumio volumio[15878]: info: Spotify config file written Feb 10 20:10:03 volumio sudo[16127]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 10 20:10:03 volumio sudo[16127]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:10:03 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 10 20:10:03 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 10 20:10:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:10:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:10:04 volumio go-librespot[16135]: go-librespot daemon starting... Feb 10 20:10:04 volumio sudo[16127]: pam_unix(sudo:session): session closed for user root Feb 10 20:10:04 volumio volumio[15878]: 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 10 20:10:04 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:04 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:04 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:04 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:04 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:04 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:04 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:04 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:04 volumio go-librespot[16136]: time="2026-02-10T20:10:04+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 20:10:04 volumio go-librespot[16136]: time="2026-02-10T20:10:04+07:00" level=debug msg="app state loaded" Feb 10 20:10:04 volumio go-librespot[16136]: time="2026-02-10T20:10:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 20:10:04 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 20:10:04 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:04 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:04 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:04 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:04 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:04 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:04 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:04 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:04 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:04 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 20:10:04 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:04 volumio volumio[15878]: info: No need to fix Spotify hosts Feb 10 20:10:04 volumio go-librespot[16136]: time="2026-02-10T20:10: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 20:10:04 volumio go-librespot[16136]: time="2026-02-10T20:10:04+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 10 20:10:04 volumio go-librespot[16136]: time="2026-02-10T20:10:04+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 10 20:10:04 volumio go-librespot[16136]: time="2026-02-10T20:10:04+07:00" level=info msg="zeroconf server listening on port 44229" Feb 10 20:10:04 volumio volumio[15878]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 20:10:04 volumio volumio[15878]: SPOTIFY: BQChT5S_VMbursXX88z39EmFMzk80oaTc2SXpOvESW13M2RvA9LdLPn_wGL4jAocBby2su3NApOcO-RCmNbMBiYUtA1wJI5k36BQDUDZ1Gd91Y6ewjlBOZmuYbzakEgl-GzwUPQyrrbt3BkaO8quwrcHNNUHxrHFupToeEc-eAPn3jhcGq-i4uAzWkY5Kmw8ho_0aO8dqRIB0TWG9r6XZvDDpd3u2FjcJAXxh5-AfNVJIh3aBBtddmx5sE41eX2cLL8feo8iFnj9yFr5Yevf2_7F0bBOMWBj_zku3OqjxEnEkhYRjmQhnIGo Feb 10 20:10:04 volumio volumio[15878]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 20:10:04 volumio volumio[15878]: info: New Spotify access token = BQChT5S_VMbursXX88z39EmFMzk80oaTc2SXpOvESW13M2RvA9LdLPn_wGL4jAocBby2su3NApOcO-RCmNbMBiYUtA1wJI5k36BQDUDZ1Gd91Y6ewjlBOZmuYbzakEgl-GzwUPQyrrbt3BkaO8quwrcHNNUHxrHFupToeEc-eAPn3jhcGq-i4uAzWkY5Kmw8ho_0aO8dqRIB0TWG9r6XZvDDpd3u2FjcJAXxh5-AfNVJIh3aBBtddmx5sE41eX2cLL8feo8iFnj9yFr5Yevf2_7F0bBOMWBj_zku3OqjxEnEkhYRjmQhnIGo Feb 10 20:10:04 volumio volumio[15878]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 10 20:10:04 volumio volumio[15878]: info: Starting Shairport Sync Feb 10 20:10:04 volumio volumio[15878]: info: Starting Shairport Sync Feb 10 20:10:05 volumio sudo[16160]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 20:10:05 volumio volumio[15878]: info: Starting Shairport Sync Feb 10 20:10:05 volumio sudo[16160]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:10:05 volumio go-librespot[16136]: time="2026-02-10T20:10:05+07:00" level=debug msg="obtained new client token: AABF5fWT/LK1wty7Ftkym2VwzRVK43Z4hsIQlj98hRUATV2slUMPTTmauNwVZoY0aiHDh/C7yghllZwlQdUvqZyy5EgDaykV2Buo6xfwTzQxGPrPPhlfwKqbp8Dezpms6keX78bzhZu49RMfNv4BOvPJS8T1E0KQ2yRby3q6fkH7JJfCRj6iyLCtLwPYXOBczF9/ZYTEn3D2bjRKJqBvpaq15doFc5IW1/niyy3nW7Q/66A/Jl5aqLY=" Feb 10 20:10:05 volumio sudo[16162]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 20:10:05 volumio sudo[16162]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:10:05 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 10 20:10:05 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 10 20:10:05 volumio sudo[16165]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 20:10:05 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 20:10:05 volumio systemd[1]: shairport-sync.service: Consumed 2.234s CPU time. Feb 10 20:10:05 volumio sudo[16165]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:10:05 volumio go-librespot[16136]: time="2026-02-10T20:10:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 20:10:05 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 20:10:05 volumio sudo[16160]: pam_unix(sudo:session): session closed for user root Feb 10 20:10:05 volumio go-librespot[16136]: time="2026-02-10T20:10:05+07:00" level=debug msg="completed keyexchange" Feb 10 20:10:05 volumio go-librespot[16136]: time="2026-02-10T20:10:05+07:00" level=debug msg="completed challenge" Feb 10 20:10:05 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 10 20:10:05 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 10 20:10:05 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 20:10:05 volumio go-librespot[16136]: time="2026-02-10T20:10:05+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 10 20:10:05 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 20:10:05 volumio volumio[15878]: info: CoreCommandRouter::volumioGetState Feb 10 20:10:05 volumio volumio[15878]: info: CorePlayQueue::getTrack 0 Feb 10 20:10:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 20:10:05 volumio sudo[16162]: pam_unix(sudo:session): session closed for user root Feb 10 20:10:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 20:10:05 volumio volumio[15878]: info: Shairport-Sync Started Feb 10 20:10:05 volumio volumio[15878]: Error adding Membership: Error: addMembership EINVAL Feb 10 20:10:05 volumio sudo[16165]: pam_unix(sudo:session): session closed for user root Feb 10 20:10:05 volumio volumio[15878]: info: Shairport-Sync Started Feb 10 20:10:05 volumio volumio[15878]: info: Shairport-Sync Started Feb 10 20:10:05 volumio volumio[15878]: 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 10 20:10:05 volumio volumio[15878]: info: Spotify Successfully logged in Feb 10 20:10:05 volumio volumio[15878]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 20:10:05 volumio volumio[15878]: info: [1770729005838] CoreMusicLibrary::Adding element Spotify Feb 10 20:10:05 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 20:10:05 volumio volumio[15878]: Cannot find translation for source YouTube Music Feb 10 20:10:05 volumio volumio[15878]: Cannot find translation for source Spotify Feb 10 20:10:06 volumio volumio[15878]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 10 20:10:06 volumio volumio[15878]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 20:10:06 volumio volumio[15878]: info: VolumeController:: Volume=100 Mute =false Feb 10 20:10:06 volumio volumio[15878]: info: CoreCommandRouter::volumioGetState Feb 10 20:10:06 volumio volumio[15878]: info: CorePlayQueue::getTrack 0 Feb 10 20:10:06 volumio volumio[15878]: info: CoreStateMachine::pushState Feb 10 20:10:06 volumio volumio[15878]: info: CorePlayQueue::getTrack 0 Feb 10 20:10:06 volumio volumio[15878]: info: CoreCommandRouter::volumioPushState Feb 10 20:10:07 volumio volumio[15878]: info: go-librespot daemon successfully initialized Feb 10 20:10:07 volumio mpd[16104]: 2026-02-10T20:10:07 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 10 20:10:07 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 10 20:10:07 volumio sudo[16075]: pam_unix(sudo:session): session closed for user root Feb 10 20:10:08 volumio sudo[16065]: pam_unix(sudo:session): session closed for user root Feb 10 20:10:08 volumio volumio[15878]: error: MPD error: The expression evaluated to a falsy value: Feb 10 20:10:08 volumio volumio[15878]: assert.ok(self.idling) Feb 10 20:10:08 volumio volumio[15878]: error: The expression evaluated to a falsy value: Feb 10 20:10:08 volumio volumio[15878]: assert.ok(self.idling) Feb 10 20:10:08 volumio volumio[15878]: error: updateQueue error: null Feb 10 20:10:08 volumio volumio[15878]: info: MPD running with PID16104 Feb 10 20:10:08 volumio volumio[15878]: ,establishing connection Feb 10 20:10:08 volumio volumio[15878]: info: Completed starting Core Plugins Feb 10 20:10:08 volumio volumio[15878]: info: ------------------------------------------- Feb 10 20:10:08 volumio volumio[15878]: info: ----- MyVolumio plugins startup ---- Feb 10 20:10:08 volumio volumio[15878]: info: ------------------------------------------- Feb 10 20:10:08 volumio volumio[15878]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 10 20:10:08 volumio volumio[15878]: error: updateQueue error: null Feb 10 20:10:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 10 20:10:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:10:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:10:08 volumio go-librespot[16205]: go-librespot daemon starting... Feb 10 20:10:08 volumio go-librespot[16206]: time="2026-02-10T20:10:08+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 20:10:08 volumio go-librespot[16206]: time="2026-02-10T20:10:08+07:00" level=debug msg="app state loaded" Feb 10 20:10:08 volumio go-librespot[16206]: time="2026-02-10T20:10:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 20:10:09 volumio go-librespot[16206]: time="2026-02-10T20:10: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 20:10:09 volumio go-librespot[16206]: time="2026-02-10T20:10:09+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 10 20:10:09 volumio go-librespot[16206]: time="2026-02-10T20:10:09+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 10 20:10:09 volumio go-librespot[16206]: time="2026-02-10T20:10:09+07:00" level=info msg="zeroconf server listening on port 39345" Feb 10 20:10:09 volumio go-librespot[16206]: time="2026-02-10T20:10:09+07:00" level=debug msg="obtained new client token: AADGH6tFubNmy+xI7WPFSvMcgb+WnYJVWagkXuJMsBGfTmBVNlyzQxrOTuyFD3x5UW/t/fDe3PWAN74HXYiJ8eLAqiCCocNfbK1vDAD17+LjfigMHZeFS91YwMmEP3alFV/QcX2vqkeJxuqHoMJuUR7GrEZv7Nytkdcmaj3TlQIphELDag/FqwoF9pIFgH9Fmn+5GG227isE6qOLdZ5Jbf35OjKNGY4zsk845j8WHtz03bRLlVrignxoug==" Feb 10 20:10:09 volumio go-librespot[16206]: time="2026-02-10T20:10:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 20:10:09 volumio go-librespot[16206]: time="2026-02-10T20:10:09+07:00" level=debug msg="completed keyexchange" Feb 10 20:10:09 volumio go-librespot[16206]: time="2026-02-10T20:10:09+07:00" level=debug msg="completed challenge" Feb 10 20:10:09 volumio go-librespot[16206]: time="2026-02-10T20:10:09+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 10 20:10:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 20:10:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 20:10:10 volumio volumio[15878]: info: Initializing connection to go-librespot Websocket Feb 10 20:10:10 volumio volumio[15878]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 20:10:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 10 20:10:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:10:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:10:12 volumio go-librespot[16214]: go-librespot daemon starting... Feb 10 20:10:12 volumio go-librespot[16215]: time="2026-02-10T20:10:12+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 20:10:12 volumio go-librespot[16215]: time="2026-02-10T20:10:12+07:00" level=debug msg="app state loaded" Feb 10 20:10:12 volumio go-librespot[16215]: time="2026-02-10T20:10:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 20:10:13 volumio volumio[15878]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 10 20:10:13 volumio go-librespot[16215]: time="2026-02-10T20:10: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 20:10:13 volumio go-librespot[16215]: time="2026-02-10T20:10:13+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 10 20:10:13 volumio go-librespot[16215]: time="2026-02-10T20:10:13+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 10 20:10:13 volumio go-librespot[16215]: time="2026-02-10T20:10:13+07:00" level=info msg="zeroconf server listening on port 37671" Feb 10 20:10:13 volumio go-librespot[16215]: time="2026-02-10T20:10:13+07:00" level=debug msg="obtained new client token: AAC59SAIUY5pip4sMgJmfe1T5kWDBVZ+PK4jWQmoWsg078hGx4ylt+ZRhct7Lv3Y3VQ99UkyiZI+fMunxuUV37jp6OKXOAMTb7/D/E+P+JYZjBSECbJgrGDJatSa5pLt2GpmPlpUArb1iJIIXbrbMVu1mfZvH8K+AbI/xYeGnS7S5yKroZbe1i1pH7GCDnvpsLiOVJcp9b+Z4bzkB3JMzq+StswyH6ByNJI1WQ0pV2lQMcb2olCv6mCvcQ==" Feb 10 20:10:13 volumio go-librespot[16215]: time="2026-02-10T20:10:13+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 10 20:10:13 volumio go-librespot[16215]: time="2026-02-10T20:10:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 10 20:10:13 volumio volumio[15878]: info: Initializing connection to go-librespot Websocket Feb 10 20:10:13 volumio go-librespot[16215]: time="2026-02-10T20:10:13+07:00" level=debug msg="new websocket client" Feb 10 20:10:13 volumio volumio[15878]: info: Connection to go-librespot Websocket established Feb 10 20:10:13 volumio go-librespot[16215]: time="2026-02-10T20:10:13+07:00" level=debug msg="completed keyexchange" Feb 10 20:10:13 volumio go-librespot[16215]: time="2026-02-10T20:10:13+07:00" level=debug msg="completed challenge" Feb 10 20:10:13 volumio go-librespot[16215]: time="2026-02-10T20:10:13+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 10 20:10:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 20:10:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 20:10:13 volumio volumio[15878]: info: Connection to go-librespot Websocket closed Feb 10 20:10:16 volumio volumio[15878]: info: Getting Spotify volume Feb 10 20:10:16 volumio volumio[15878]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 20:10:16 volumio volumio[15878]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 20:10:16 volumio volumio[15878]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 10 20:10:16 volumio volumio[15878]: errno: -111, Feb 10 20:10:16 volumio volumio[15878]: code: 'ECONNREFUSED', Feb 10 20:10:16 volumio volumio[15878]: syscall: 'connect', Feb 10 20:10:16 volumio volumio[15878]: address: '127.0.0.1', Feb 10 20:10:16 volumio volumio[15878]: port: 9879, Feb 10 20:10:16 volumio volumio[15878]: response: undefined Feb 10 20:10:16 volumio volumio[15878]: } Feb 10 20:10:16 volumio volumio[15878]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 20:10:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 10 20:10:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:10:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:10:17 volumio go-librespot[16233]: go-librespot daemon starting... Feb 10 20:10:17 volumio go-librespot[16235]: time="2026-02-10T20:10:17+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 20:10:17 volumio go-librespot[16235]: time="2026-02-10T20:10:17+07:00" level=debug msg="app state loaded" Feb 10 20:10:17 volumio go-librespot[16235]: time="2026-02-10T20:10:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 20:10:17 volumio go-librespot[16235]: time="2026-02-10T20:10: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 20:10:17 volumio go-librespot[16235]: time="2026-02-10T20:10:17+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 10 20:10:17 volumio go-librespot[16235]: time="2026-02-10T20:10:17+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 10 20:10:17 volumio go-librespot[16235]: time="2026-02-10T20:10:17+07:00" level=info msg="zeroconf server listening on port 39689" Feb 10 20:10:17 volumio go-librespot[16235]: time="2026-02-10T20:10:17+07:00" level=debug msg="obtained new client token: AABESekILYry23iYb9bjIHPu4vDd+I3d/rCbnio0B/Aie8n79BqN525HjmczPdNsQyy31h460I4w0BEEn+hY/+HjgX+spGbBQ1u7JbCA8wCowIb+dIK/VSJNxfhT9/c5rJX7FCExjhYkdXPk4/hnasX19RmiZTUuKLGCdfjIFY96BDDN6nuxx2/ltOCkcpOFpJ7ZdK//OdvDWyemMY9c6bV+fPJu7VlK3qny5VMRcSprCVuFp/LxineGtw==" Feb 10 20:10:18 volumio go-librespot[16235]: time="2026-02-10T20:10:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 20:10:18 volumio go-librespot[16235]: time="2026-02-10T20:10:18+07:00" level=debug msg="completed keyexchange" Feb 10 20:10:18 volumio go-librespot[16235]: time="2026-02-10T20:10:18+07:00" level=debug msg="completed challenge" Feb 10 20:10:18 volumio go-librespot[16235]: time="2026-02-10T20:10:18+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 10 20:10:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 20:10:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 20:10:18 volumio sudo[16258]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-10 20:09' Feb 10 20:10:18 volumio sudo[16258]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:10:18 volumio sudo[16258]: pam_unix(sudo:session): session closed for user root Feb 10 20:10:18 volumio volumio-remote-updater[643]: [2026-02-10 20:10:18] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 10 20:10:18 volumio volumio-remote-updater[643]: [2026-02-10 20:10:18] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 10 20:10:18 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 10 20:10:18 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 10 20:10:18 volumio systemd[1]: volumio.service: Consumed 49.337s CPU time. Feb 10 20:10:18 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 10 20:10:18 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 10 20:10:19 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10696. Feb 10 20:10:19 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 10 20:10:19 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 10 20:10:19 volumio systemd[1]: volumio.service: Consumed 49.337s CPU time. Feb 10 20:10:19 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 10 20:10:19 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 10 20:10:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 10 20:10:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:10:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:10:21 volumio go-librespot[16285]: go-librespot daemon starting... Feb 10 20:10:21 volumio go-librespot[16286]: time="2026-02-10T20:10:21+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 20:10:21 volumio go-librespot[16286]: time="2026-02-10T20:10:21+07:00" level=debug msg="app state loaded" Feb 10 20:10:21 volumio go-librespot[16286]: time="2026-02-10T20:10:21+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 20:10:21 volumio go-librespot[16286]: time="2026-02-10T20:10: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 10 20:10:21 volumio go-librespot[16286]: time="2026-02-10T20:10: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 10 20:10:21 volumio go-librespot[16286]: time="2026-02-10T20:10: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 10 20:10:21 volumio go-librespot[16286]: time="2026-02-10T20:10:21+07:00" level=info msg="zeroconf server listening on port 33911" Feb 10 20:10:22 volumio go-librespot[16286]: time="2026-02-10T20:10:22+07:00" level=debug msg="obtained new client token: AADvm6xQtvoYhttku7JTl9Ns0hlJKoMEI8VRZxHX+mXz/EOUgXRuzWCmB4CNOOe+7sOHiPFSRhhO4GNvBqp5+mLr+MAJXpi2lkD3RLd70r+4w6P9A2D/liWV2pKHnWQlkfwAET+IYculT1BLnO+mN+/2EGsTuJpX+lI9foTacYIsK9juq3NUZ7FEGzlmSVgxMHFpd/pTOa+JZrMQP1S0KXFP7gqI47WL7mGmzhbCA2WHpwBowTfSsO4=" Feb 10 20:10:22 volumio go-librespot[16286]: time="2026-02-10T20:10:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 20:10:22 volumio go-librespot[16286]: time="2026-02-10T20:10:22+07:00" level=debug msg="completed keyexchange" Feb 10 20:10:22 volumio go-librespot[16286]: time="2026-02-10T20:10:22+07:00" level=debug msg="completed challenge" Feb 10 20:10:22 volumio go-librespot[16286]: time="2026-02-10T20:10:22+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 10 20:10:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 20:10:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 20:10:22 volumio volumio[16270]: info: ------------------------------------------- Feb 10 20:10:22 volumio volumio[16270]: info: ----- Volumio3 ---- Feb 10 20:10:22 volumio volumio[16270]: info: ------------------------------------------- Feb 10 20:10:22 volumio volumio[16270]: info: ----- System startup ---- Feb 10 20:10:22 volumio volumio[16270]: info: ------------------------------------------- Feb 10 20:10:23 volumio volumio-remote-updater[643]: [2026-02-10 20:10:23] [connect] Successful connection Feb 10 20:10:24 volumio volumio[16270]: info: MYVOLUMIO Environment detected Feb 10 20:10:24 volumio volumio[16270]: info: Plugin folders cleanup Feb 10 20:10:24 volumio volumio[16270]: info: Scanning into folder /volumio/app/plugins/ Feb 10 20:10:24 volumio volumio[16270]: info: Scanning category audio_interface Feb 10 20:10:24 volumio volumio[16270]: info: Scanning category miscellanea Feb 10 20:10:24 volumio volumio[16270]: info: Scanning category music_service Feb 10 20:10:24 volumio volumio[16270]: info: Scanning category plugins.json Feb 10 20:10:24 volumio volumio[16270]: info: Scanning category system_controller Feb 10 20:10:24 volumio volumio[16270]: info: Scanning category user_interface Feb 10 20:10:24 volumio volumio[16270]: info: Scanning into folder /data/plugins/ Feb 10 20:10:24 volumio volumio[16270]: info: Scanning category music_service Feb 10 20:10:24 volumio volumio[16270]: info: Plugin folders cleanup completed Feb 10 20:10:24 volumio volumio[16270]: info: ------------------------------------------- Feb 10 20:10:24 volumio volumio[16270]: info: ----- Core plugins startup ---- Feb 10 20:10:24 volumio volumio[16270]: info: ------------------------------------------- Feb 10 20:10:24 volumio volumio[16270]: info: Loading plugins from folder /volumio/app/plugins/ Feb 10 20:10:24 volumio volumio[16270]: info: Adding plugin upnp to MyMusic Plugins Feb 10 20:10:24 volumio volumio[16270]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 10 20:10:24 volumio volumio[16270]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 10 20:10:24 volumio volumio[16270]: info: Loading plugins from folder /data/plugins/ Feb 10 20:10:24 volumio volumio[16270]: info: Loading plugin "system"... Feb 10 20:10:24 volumio volumio[16270]: info: Loading plugin "appearance"... Feb 10 20:10:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 10 20:10:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:10:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:10:25 volumio go-librespot[16306]: go-librespot daemon starting... Feb 10 20:10:25 volumio go-librespot[16307]: time="2026-02-10T20:10:25+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 20:10:25 volumio go-librespot[16307]: time="2026-02-10T20:10:25+07:00" level=debug msg="app state loaded" Feb 10 20:10:25 volumio go-librespot[16307]: time="2026-02-10T20:10:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 20:10:26 volumio go-librespot[16307]: time="2026-02-10T20:10:26+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 10 20:10:26 volumio go-librespot[16307]: time="2026-02-10T20:10:26+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 10 20:10:26 volumio go-librespot[16307]: time="2026-02-10T20:10:26+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 10 20:10:26 volumio go-librespot[16307]: time="2026-02-10T20:10:26+07:00" level=info msg="zeroconf server listening on port 34569" Feb 10 20:10:26 volumio volumio[16270]: info: Loading plugin "network"... Feb 10 20:10:26 volumio volumio[16270]: info: Refreshing Cached IP Addresses Feb 10 20:10:26 volumio sudo[16316]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 10 20:10:26 volumio sudo[16318]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 10 20:10:26 volumio sudo[16318]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:10:26 volumio volumio[16270]: info: Loading plugin "services"... Feb 10 20:10:26 volumio sudo[16316]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:10:26 volumio sudo[16316]: pam_unix(sudo:session): session closed for user root Feb 10 20:10:26 volumio volumio[16270]: info: Loading plugin "alsa_controller"... Feb 10 20:10:26 volumio sudo[16318]: pam_unix(sudo:session): session closed for user root Feb 10 20:10:26 volumio sudo[16325]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 10 20:10:26 volumio sudo[16325]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:10:26 volumio go-librespot[16307]: time="2026-02-10T20:10:26+07:00" level=debug msg="obtained new client token: AACjBm9vdijXvcQV3xsZtLAK6Zd8npUPZ9QmGju3EeKTsSJ05T07HayjJLHf3fw5Ui9tPIQjYjCDrY5QZL0kSicAzG4mAR/gH3qyqXVQQXo2/Ow9E8O8Ltq0XcEgtcWKvuM3vSMWLRy9B13lgAfdVjJODGByOfpmhIsNTCR+dLQSPyHHQXRmmiI3qO3zEqa/VHx1m1EBgsKI9ErS0aCEeVYqlWJiu3soyJ6L6/1qGeR4/mVYI7NRmMR97Q==" Feb 10 20:10:26 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 20:10:26 volumio volumio[16270]: info: Loading plugin "wizard"... Feb 10 20:10:26 volumio go-librespot[16307]: time="2026-02-10T20:10:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 20:10:26 volumio volumio[16270]: info: Loading plugin "networkfs"... Feb 10 20:10:26 volumio volumio[16270]: info: Starting Udev Watcher for removable devices Feb 10 20:10:26 volumio volumio[16270]: info: Ignoring mount for partition: boot Feb 10 20:10:26 volumio volumio[16270]: info: Ignoring mount for partition: volumio Feb 10 20:10:26 volumio volumio[16270]: info: Ignoring mount for partition: volumio_data Feb 10 20:10:26 volumio go-librespot[16307]: time="2026-02-10T20:10:26+07:00" level=debug msg="completed keyexchange" Feb 10 20:10:26 volumio go-librespot[16307]: time="2026-02-10T20:10:26+07:00" level=debug msg="completed challenge" Feb 10 20:10:26 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 20:10:26 volumio volumio[16270]: info: Loading plugin "volumio_command_line_client"... Feb 10 20:10:26 volumio volumio[16270]: info: Loading plugin "upnp"... Feb 10 20:10:26 volumio volumio[16270]: info: [1770729026737] Starting Upmpd Daemon Feb 10 20:10:26 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 20:10:26 volumio volumio[16270]: info: Loading plugin "my_music"... Feb 10 20:10:26 volumio volumio[16270]: info: Loading plugin "mpd"... Feb 10 20:10:26 volumio go-librespot[16307]: time="2026-02-10T20:10:26+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 10 20:10:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 20:10:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 20:10:27 volumio volumio[16270]: info: Loading plugin "upnp_browser"... Feb 10 20:10:29 volumio sudo[16325]: pam_unix(sudo:session): session closed for user root Feb 10 20:10:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 10 20:10:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:10:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:10:30 volumio go-librespot[16350]: go-librespot daemon starting... Feb 10 20:10:30 volumio go-librespot[16351]: time="2026-02-10T20:10:30+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 20:10:30 volumio go-librespot[16351]: time="2026-02-10T20:10:30+07:00" level=debug msg="app state loaded" Feb 10 20:10:30 volumio go-librespot[16351]: time="2026-02-10T20:10:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 20:10:30 volumio volumio[16270]: info: Starting UPNP Browser Feb 10 20:10:30 volumio volumio[16270]: info: Loading plugin "alarm-clock"... Feb 10 20:10:30 volumio volumio[16270]: info: Loading plugin "airplay_emulation"... Feb 10 20:10:30 volumio volumio[16270]: info: Starting Shairport Sync Feb 10 20:10:30 volumio volumio[16270]: info: Loading plugin "last_100"... Feb 10 20:10:30 volumio volumio[16270]: info: Loading plugin "webradio"... Feb 10 20:10:30 volumio go-librespot[16351]: time="2026-02-10T20:10:30+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 10 20:10:30 volumio go-librespot[16351]: time="2026-02-10T20:10:30+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 10 20:10:30 volumio go-librespot[16351]: time="2026-02-10T20:10:30+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 10 20:10:30 volumio go-librespot[16351]: time="2026-02-10T20:10:30+07:00" level=info msg="zeroconf server listening on port 35789" Feb 10 20:10:30 volumio volumio[16270]: info: Loading plugin "i2s_dacs"... Feb 10 20:10:30 volumio volumio[16270]: info: Loading plugin "volumiodiscovery"... Feb 10 20:10:30 volumio volumio[16270]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 20:10:30 volumio volumio[16270]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 20:10:30 volumio volumio[16270]: *** WARNING *** For more information see Feb 10 20:10:30 volumio volumio[16270]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 20:10:30 volumio volumio[16270]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 20:10:30 volumio volumio[16270]: *** WARNING *** For more information see Feb 10 20:10:30 volumio node[16270]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 20:10:30 volumio node[16270]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 20:10:30 volumio node[16270]: *** WARNING *** For more information see Feb 10 20:10:30 volumio node[16270]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 20:10:30 volumio node[16270]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 20:10:30 volumio node[16270]: *** WARNING *** For more information see Feb 10 20:10:30 volumio volumio[16270]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 10 20:10:30 volumio volumio[16270]: info: Discovery: Started advertising with name: Volumio Feb 10 20:10:31 volumio go-librespot[16351]: time="2026-02-10T20:10:31+07:00" level=debug msg="obtained new client token: AACN1jVoof0mpbeyTPMcPL5lNE7vIMWd7Z3Pm9fuSQKkfAhIq73Iaj4PtvVj/m4PkCkUm5lQUyK7YqNex+SWTpZBOW05q4tb6qMYx0C8oh7R16zqA7vp5PzcN88f92DC3IY0gL9n6ef+GUfHISnFhB4V5+MOweM9jX+xURu9SWJn93B32Jaw0R96VEaMG0QwpnLj6d7wucUrw+SNDdDscvcvIQMyls7pVOo11k4925wJPApX9lCWHUtmuw==" Feb 10 20:10:31 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 20:10:31 volumio volumio[16270]: info: Loading plugin "spop"... Feb 10 20:10:31 volumio go-librespot[16351]: time="2026-02-10T20:10:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 20:10:31 volumio go-librespot[16351]: time="2026-02-10T20:10:31+07:00" level=debug msg="completed keyexchange" Feb 10 20:10:31 volumio go-librespot[16351]: time="2026-02-10T20:10:31+07:00" level=debug msg="completed challenge" Feb 10 20:10:31 volumio go-librespot[16351]: time="2026-02-10T20:10:31+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 10 20:10:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 20:10:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 20:10:32 volumio volumio[16270]: info: Loading plugin "ytcr"... Feb 10 20:10:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 10 20:10:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:10:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:10:34 volumio go-librespot[16360]: go-librespot daemon starting... Feb 10 20:10:34 volumio go-librespot[16361]: time="2026-02-10T20:10:34+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 20:10:34 volumio go-librespot[16361]: time="2026-02-10T20:10:34+07:00" level=debug msg="app state loaded" Feb 10 20:10:34 volumio go-librespot[16361]: time="2026-02-10T20:10:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 20:10:35 volumio go-librespot[16361]: time="2026-02-10T20:10: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 10 20:10:35 volumio go-librespot[16361]: time="2026-02-10T20:10: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 10 20:10:35 volumio go-librespot[16361]: time="2026-02-10T20:10: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 10 20:10:35 volumio go-librespot[16361]: time="2026-02-10T20:10:35+07:00" level=info msg="zeroconf server listening on port 43353" Feb 10 20:10:35 volumio go-librespot[16361]: time="2026-02-10T20:10:35+07:00" level=debug msg="obtained new client token: AAArAYRwlcW7vV1p/IzsUgcxIblCtBchdNe+75w1RpsFXwskZVDqMkuYZhuNEoDZlLIilBoM9FfpcJN+VCyL6g+hzmUtjqJ+60FUrzM8rnijYi/FrfGHCDpsaDdX6isEAm3ZP8/GMpuSqa3v5IpvtzkiGY/NMt58hLY2kaTOtjIZUFjBHcxtPaCH6QCh5C+PdPtUr3DQzb+T3zC0ak9EkZnJC4rSg2gneRTetkyyxB+r3jlDXoPW9tOhQg==" Feb 10 20:10:35 volumio volumio[16270]: info: Loading plugin "ytmusic"... Feb 10 20:10:35 volumio go-librespot[16361]: time="2026-02-10T20:10:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 20:10:35 volumio go-librespot[16361]: time="2026-02-10T20:10:35+07:00" level=debug msg="completed keyexchange" Feb 10 20:10:35 volumio go-librespot[16361]: time="2026-02-10T20:10:35+07:00" level=debug msg="completed challenge" Feb 10 20:10:35 volumio go-librespot[16361]: time="2026-02-10T20:10:35+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 20:10:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 20:10:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 20:10:36 volumio volumio-remote-updater[643]: [2026-02-10 20:10:36] [connect] Successful connection Feb 10 20:10:36 volumio volumio[16270]: info: Loading plugin "outputs"... Feb 10 20:10:36 volumio volumio[16270]: info: Loading plugin "albumart"... Feb 10 20:10:36 volumio volumio[16270]: info: Plugin example_plugin is not enabled Feb 10 20:10:36 volumio volumio[16270]: info: Loading plugin "inputs"... Feb 10 20:10:36 volumio volumio[16270]: info: Loading plugin "updater_comm"... Feb 10 20:10:36 volumio volumio[16270]: info: Plugin mpdemulation is not enabled Feb 10 20:10:36 volumio volumio[16270]: info: Loading plugin "rest_api"... Feb 10 20:10:36 volumio volumio[16270]: info: Loading plugin "websocket"... Feb 10 20:10:36 volumio volumio[16270]: info: Starting Socket.io Server version 1.7.4 Feb 10 20:10:36 volumio volumio[16270]: info: Loading plugin "RoonBridge"... Feb 10 20:10:37 volumio volumio[16270]: info: Applying required configuration parameters for plugin RoonBridge Feb 10 20:10:37 volumio volumio[16270]: info: Loading i18n strings for locale en Feb 10 20:10:37 volumio volumio[16270]: Updating browse sources language Feb 10 20:10:37 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 20:10:37 volumio volumio[16382]: Forking 3 albumart workers Feb 10 20:10:37 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 20:10:37 volumio volumio[16270]: info: CoreCommandRouter::initPlayerControls Feb 10 20:10:37 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:37 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:37 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:37 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:37 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:37 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:37 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:37 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:37 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 20:10:37 volumio volumio[16270]: Express server listening on port 3000 Feb 10 20:10:37 volumio volumio[16270]: [Metrics] WebUI: 15s 895.25ms Feb 10 20:10:37 volumio volumio[16270]: info: CoreStateMachine::resetVolumioState Feb 10 20:10:37 volumio volumio[16270]: info: CoreStateMachine::getcurrentVolume Feb 10 20:10:37 volumio volumio[16270]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 20:10:37 volumio sudo[16424]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 10 20:10:38 volumio sudo[16424]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:10:38 volumio volumio[16270]: info: Volumio Network Manager: Network status updated: 1 Feb 10 20:10:38 volumio sudo[16426]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 10 20:10:38 volumio sudo[16426]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:10:38 volumio sudo[16424]: pam_unix(sudo:session): session closed for user root Feb 10 20:10:38 volumio sudo[16426]: pam_unix(sudo:session): session closed for user root Feb 10 20:10:38 volumio volumio[16270]: info: VolumeController:: Volume=100 Mute =false Feb 10 20:10:38 volumio volumio[16270]: info: CoreStateMachine::pushState Feb 10 20:10:38 volumio volumio[16270]: info: CorePlayQueue::getTrack 0 Feb 10 20:10:38 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 10 20:10:38 volumio volumio[16270]: info: CoreCommandRouter::volumioPushState Feb 10 20:10:38 volumio volumio[16270]: info: CoreStateMachine::updateTrackBlock Feb 10 20:10:38 volumio volumio[16270]: info: CorePlayQueue::getTrackBlock Feb 10 20:10:38 volumio volumio[16270]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 20:10:38 volumio volumio-remote-updater[643]: [2026-02-10 20:10:38] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770729036 101 Feb 10 20:10:38 volumio volumio[16270]: 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 10 20:10:38 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 20:10:38 volumio volumio[16270]: info: Reloading queue from file Feb 10 20:10:38 volumio volumio[16270]: info: CoreStateMachine::setRepeat null single undefined Feb 10 20:10:38 volumio volumio[16270]: info: CoreStateMachine::pushState Feb 10 20:10:38 volumio volumio[16270]: info: CorePlayQueue::getTrack 0 Feb 10 20:10:38 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 10 20:10:38 volumio volumio[16270]: info: CoreCommandRouter::volumioPushState Feb 10 20:10:38 volumio volumio[16270]: info: CoreStateMachine::setRandom null Feb 10 20:10:38 volumio volumio[16270]: info: CoreStateMachine::pushState Feb 10 20:10:38 volumio volumio[16270]: info: CorePlayQueue::getTrack 0 Feb 10 20:10:38 volumio volumio[16270]: info: CoreCommandRouter::volumioPushState Feb 10 20:10:38 volumio volumio[16270]: info: Setting Device type: Raspberry PI Feb 10 20:10:38 volumio volumio[16270]: info: Completed loading Core Plugins Feb 10 20:10:38 volumio volumio[16270]: info: Preparing to generate the ALSA configuration file Feb 10 20:10:38 volumio volumio[16270]: info: VolumeController:: Volume=100 Mute =false Feb 10 20:10:38 volumio volumio[16270]: info: CoreStateMachine::pushState Feb 10 20:10:38 volumio volumio[16270]: info: CorePlayQueue::getTrack 0 Feb 10 20:10:38 volumio volumio[16270]: info: CoreCommandRouter::volumioPushState Feb 10 20:10:38 volumio volumio[16270]: info: Asound.conf file unchanged, so no further update is needed Feb 10 20:10:38 volumio volumio[16270]: info: Output device has changed, restarting MPD Feb 10 20:10:38 volumio volumio[16270]: info: Output device has changed, restarting Shairport Sync Feb 10 20:10:38 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:38 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 20:10:38 volumio sudo[16443]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 10 20:10:38 volumio sudo[16443]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:10:38 volumio sudo[16445]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 20:10:38 volumio sudo[16445]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:10:38 volumio sudo[16445]: pam_unix(sudo:session): session closed for user root Feb 10 20:10:38 volumio sudo[16447]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 20:10:38 volumio volumio[16270]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 20:10:38 volumio sudo[16447]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:10:38 volumio volumio[16270]: info: ___________ START PLUGINS ___________ Feb 10 20:10:39 volumio volumio[16270]: info: ControllerMpd::onStart: Initializing MPD Feb 10 20:10:39 volumio volumio[16270]: info: Creating MPD Configuration file Feb 10 20:10:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 10 20:10:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:10:39 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 20:10:39 volumio volumio[16270]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 20:10:39 volumio volumio[16270]: info: [1770729039078] CoreMusicLibrary::Adding element Media Servers Feb 10 20:10:39 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 20:10:39 volumio sudo[16458]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 20:10:39 volumio sudo[16458]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:10:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:10:39 volumio go-librespot[16459]: go-librespot daemon starting... Feb 10 20:10:39 volumio sudo[16457]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 20:10:39 volumio sudo[16457]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:10:39 volumio volumio[16270]: info: UPNP Browser: Client initialized successfully Feb 10 20:10:39 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 10 20:10:39 volumio sudo[16457]: pam_unix(sudo:session): session closed for user root Feb 10 20:10:39 volumio go-librespot[16461]: time="2026-02-10T20:10:39+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 20:10:39 volumio go-librespot[16461]: time="2026-02-10T20:10:39+07:00" level=debug msg="app state loaded" Feb 10 20:10:39 volumio go-librespot[16461]: time="2026-02-10T20:10:39+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 20:10:39 volumio sudo[16443]: pam_unix(sudo:session): session closed for user root Feb 10 20:10:39 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:39 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 20:10:39 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 10 20:10:39 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 10 20:10:39 volumio systemd[1]: mpd.service: Consumed 7.033s CPU time. Feb 10 20:10:39 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 10 20:10:39 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 10 20:10:39 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 10 20:10:39 volumio volumio[16270]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 20:10:39 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:39 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 20:10:39 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 10 20:10:39 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 10 20:10:39 volumio volumio[16270]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 20:10:39 volumio volumio[16270]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 20:10:39 volumio volumio[16270]: info: [1770729039560] CoreMusicLibrary::Adding element Last_100 Feb 10 20:10:39 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 20:10:39 volumio volumio[16270]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 20:10:39 volumio volumio[16270]: info: [1770729039585] CoreMusicLibrary::Adding element Webradio Feb 10 20:10:39 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 20:10:39 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 20:10:39 volumio volumio[16270]: info: Initializing BBC Radios Feb 10 20:10:39 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 20:10:39 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 20:10:39 volumio go-librespot[16461]: time="2026-02-10T20:10: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 10 20:10:39 volumio go-librespot[16461]: time="2026-02-10T20:10: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 10 20:10:39 volumio go-librespot[16461]: time="2026-02-10T20:10: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 10 20:10:39 volumio sudo[16475]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 10 20:10:39 volumio sudo[16475]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 10 20:10:39 volumio go-librespot[16461]: time="2026-02-10T20:10:39+07:00" level=info msg="zeroconf server listening on port 37679" Feb 10 20:10:39 volumio sudo[16475]: pam_unix(sudo:session): session closed for user root Feb 10 20:10:40 volumio volumio[16270]: info: Creating Spotify config file Feb 10 20:10:40 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:40 volumio go-librespot[16461]: time="2026-02-10T20:10:40+07:00" level=debug msg="obtained new client token: AACQReDrS6v7gXu1O4ZiVhDu8wLlIQvqb8inVpCS5GkCncixhqOspVRmQVfLLujxKLxatFdeosQc8Z9iKOeSxvYk+w+p23MrIaOasolfS8z3GzSkAMaxmbEG2c91FxmmvFqCbJuQ5ZJVuxlC7qxpstb7tBQ6c48mRrRq7y6B1r77XWYKMMSjOsXsMQTsdcRvlATQlDn5Lb8G/DLVn6KXSPa8+d3kndVojLrH7nnqZOz8kCm/eV36lEs=" Feb 10 20:10:40 volumio go-librespot[16461]: time="2026-02-10T20:10:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 20:10:40 volumio go-librespot[16461]: time="2026-02-10T20:10: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 10 20:10:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 20:10:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 20:10:40 volumio volumio[16392]: Starting albumart workers Feb 10 20:10:41 volumio volumio[16394]: Starting albumart workers Feb 10 20:10:41 volumio volumio[16393]: Starting albumart workers Feb 10 20:10:41 volumio volumio[16270]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 20:10:41 volumio volumio[16270]: info: [1770729041466] CoreMusicLibrary::Adding element YouTube Music Feb 10 20:10:41 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 20:10:41 volumio volumio[16270]: Cannot find translation for source YouTube Music Feb 10 20:10:41 volumio volumio[16270]: info: Volumio Calling Home Feb 10 20:10:41 volumio sudo[16495]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 10 20:10:41 volumio sudo[16495]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:10:41 volumio sudo[16495]: pam_unix(sudo:session): session closed for user root Feb 10 20:10:42 volumio volumio[16270]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 10 20:10:42 volumio volumio[16270]: info: Discovery: Found device Volumio Feb 10 20:10:42 volumio volumio[16270]: info: CoreCommandRouter::volumioGetState Feb 10 20:10:42 volumio volumio[16270]: info: CorePlayQueue::getTrack 0 Feb 10 20:10:42 volumio volumio[16270]: info: MPD Permissions set Feb 10 20:10:42 volumio volumio[16270]: info: MPD Permissions set Feb 10 20:10:42 volumio volumio[16270]: info: Upmpdcli Daemon Started Feb 10 20:10:42 volumio volumio[16270]: info: Volumio called home Feb 10 20:10:42 volumio volumio[16270]: info: Spotify config file written Feb 10 20:10:42 volumio volumio[16270]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 10 20:10:42 volumio volumio[16270]: info: Discovery: Found device Volumio Feb 10 20:10:42 volumio volumio[16270]: info: CoreCommandRouter::volumioGetState Feb 10 20:10:42 volumio volumio[16270]: info: CorePlayQueue::getTrack 0 Feb 10 20:10:42 volumio sudo[16508]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 10 20:10:42 volumio sudo[16508]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:10:42 volumio volumio[16270]: 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 10 20:10:42 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:42 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:42 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:42 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:10:42 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:42 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:42 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:42 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:10:43 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 20:10:43 volumio go-librespot[16516]: go-librespot daemon starting... Feb 10 20:10:43 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:43 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:43 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:43 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:43 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:43 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:43 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:43 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:43 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:43 volumio sudo[16508]: pam_unix(sudo:session): session closed for user root Feb 10 20:10:43 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 20:10:43 volumio go-librespot[16522]: time="2026-02-10T20:10:43+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 20:10:43 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:10:43 volumio go-librespot[16522]: time="2026-02-10T20:10:43+07:00" level=debug msg="app state loaded" Feb 10 20:10:43 volumio go-librespot[16522]: time="2026-02-10T20:10:43+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 20:10:43 volumio volumio[16270]: info: No need to fix Spotify hosts Feb 10 20:10:43 volumio go-librespot[16522]: time="2026-02-10T20:10:43+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 10 20:10:43 volumio go-librespot[16522]: time="2026-02-10T20:10:43+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 10 20:10:43 volumio go-librespot[16522]: time="2026-02-10T20:10:43+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 10 20:10:43 volumio go-librespot[16522]: time="2026-02-10T20:10:43+07:00" level=info msg="zeroconf server listening on port 39447" Feb 10 20:10:43 volumio volumio[16270]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 20:10:43 volumio volumio[16270]: SPOTIFY: BQC5Hvmt1Z4MUVbE5FPsXpjrKwzIQMSYUdWS8joydNmS6Czv5VRqEryKk72X21BlQXqVfy2SQ4Mp-afCZRhtjXkxgYWrdBGgQzJFoU9labWJ9F778KB4Lt7huzB6YN9ogQEPTLJj2-v_G5qqQ4iX1jfGZ_U7CxxPJZqgLhlOd_AdO6540USo-l9A46DaugtZCmMOqstZxrtikWMvgNB4eo_sFWQkBlUt9Hj7qbMq48EdWDpzmz_CekBpIQMh7qNfCSKRlBp4am8GtViTimv25WJTrayWEoeBZSfUXxc_zGdg0vJAkcDfZ9uo Feb 10 20:10:43 volumio volumio[16270]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 20:10:43 volumio volumio[16270]: info: New Spotify access token = BQC5Hvmt1Z4MUVbE5FPsXpjrKwzIQMSYUdWS8joydNmS6Czv5VRqEryKk72X21BlQXqVfy2SQ4Mp-afCZRhtjXkxgYWrdBGgQzJFoU9labWJ9F778KB4Lt7huzB6YN9ogQEPTLJj2-v_G5qqQ4iX1jfGZ_U7CxxPJZqgLhlOd_AdO6540USo-l9A46DaugtZCmMOqstZxrtikWMvgNB4eo_sFWQkBlUt9Hj7qbMq48EdWDpzmz_CekBpIQMh7qNfCSKRlBp4am8GtViTimv25WJTrayWEoeBZSfUXxc_zGdg0vJAkcDfZ9uo Feb 10 20:10:43 volumio volumio[16270]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 10 20:10:43 volumio go-librespot[16522]: time="2026-02-10T20:10:43+07:00" level=debug msg="obtained new client token: AABPwUMCeHTs5/E1AaC/s3Y8oeZFiYgMXHeiZUoqvK0MXVUYff+KGqVDqso1YxEuJ3O46PlPjQDInNYoNl6YPgpDuY6VtqAbyoZaex/+q/D/JnCbQ2CvSdmMDcRfFOei7Cf+rD6xhZA99lq179LSugZc2tQP7L3M21npvCD0hdpa90Y3IKhCE108DvgBZ3BGqbat3+Ny/Vy722cK3pFYnuZYNRntDBrA2F26FpF4jUtf3d2R8l4N2p+grQ==" Feb 10 20:10:43 volumio volumio[16270]: info: Starting Shairport Sync Feb 10 20:10:44 volumio volumio[16270]: info: Starting Shairport Sync Feb 10 20:10:44 volumio volumio[16270]: info: Starting Shairport Sync Feb 10 20:10:44 volumio sudo[16543]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 20:10:44 volumio go-librespot[16522]: time="2026-02-10T20:10:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 20:10:44 volumio sudo[16543]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:10:44 volumio sudo[16545]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 20:10:44 volumio sudo[16545]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:10:44 volumio sudo[16547]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 20:10:44 volumio sudo[16547]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:10:44 volumio go-librespot[16522]: time="2026-02-10T20:10:44+07:00" level=debug msg="completed keyexchange" Feb 10 20:10:44 volumio go-librespot[16522]: time="2026-02-10T20:10:44+07:00" level=debug msg="completed challenge" Feb 10 20:10:44 volumio go-librespot[16522]: time="2026-02-10T20:10:44+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 20:10:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 20:10:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 20:10:44 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 10 20:10:44 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 10 20:10:44 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 20:10:44 volumio systemd[1]: shairport-sync.service: Consumed 2.201s CPU time. Feb 10 20:10:44 volumio volumio[16270]: info: CoreCommandRouter::volumioGetState Feb 10 20:10:44 volumio volumio[16270]: info: CorePlayQueue::getTrack 0 Feb 10 20:10:44 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 20:10:44 volumio sudo[16547]: pam_unix(sudo:session): session closed for user root Feb 10 20:10:44 volumio sudo[16543]: pam_unix(sudo:session): session closed for user root Feb 10 20:10:44 volumio sudo[16545]: pam_unix(sudo:session): session closed for user root Feb 10 20:10:44 volumio volumio[16270]: info: Shairport-Sync Started Feb 10 20:10:44 volumio volumio[16270]: Error adding Membership: Error: addMembership EINVAL Feb 10 20:10:44 volumio volumio[16270]: info: Shairport-Sync Started Feb 10 20:10:44 volumio volumio[16270]: info: Shairport-Sync Started Feb 10 20:10:44 volumio volumio[16270]: 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 10 20:10:44 volumio volumio[16270]: info: Spotify Successfully logged in Feb 10 20:10:44 volumio volumio[16270]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 20:10:44 volumio volumio[16270]: info: [1770729044695] CoreMusicLibrary::Adding element Spotify Feb 10 20:10:44 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 20:10:44 volumio volumio[16270]: Cannot find translation for source YouTube Music Feb 10 20:10:44 volumio volumio[16270]: Cannot find translation for source Spotify Feb 10 20:10:45 volumio volumio[16270]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 10 20:10:45 volumio volumio[16270]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 20:10:45 volumio volumio[16270]: info: VolumeController:: Volume=100 Mute =false Feb 10 20:10:45 volumio volumio[16270]: info: CoreCommandRouter::volumioGetState Feb 10 20:10:45 volumio volumio[16270]: info: CorePlayQueue::getTrack 0 Feb 10 20:10:45 volumio volumio[16270]: info: CoreStateMachine::pushState Feb 10 20:10:45 volumio volumio[16270]: info: CorePlayQueue::getTrack 0 Feb 10 20:10:45 volumio volumio[16270]: info: CoreCommandRouter::volumioPushState Feb 10 20:10:46 volumio mpd[16493]: 2026-02-10T20:10:46 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 10 20:10:46 volumio volumio[16270]: info: go-librespot daemon successfully initialized Feb 10 20:10:46 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 10 20:10:46 volumio sudo[16447]: pam_unix(sudo:session): session closed for user root Feb 10 20:10:46 volumio sudo[16458]: pam_unix(sudo:session): session closed for user root Feb 10 20:10:47 volumio volumio[16270]: error: MPD error: The expression evaluated to a falsy value: Feb 10 20:10:47 volumio volumio[16270]: assert.ok(self.idling) Feb 10 20:10:47 volumio volumio[16270]: error: The expression evaluated to a falsy value: Feb 10 20:10:47 volumio volumio[16270]: assert.ok(self.idling) Feb 10 20:10:47 volumio volumio[16270]: info: MPD running with PID16493 Feb 10 20:10:47 volumio volumio[16270]: ,establishing connection Feb 10 20:10:47 volumio volumio[16270]: error: updateQueue error: null Feb 10 20:10:47 volumio volumio[16270]: info: Completed starting Core Plugins Feb 10 20:10:47 volumio volumio[16270]: info: ------------------------------------------- Feb 10 20:10:47 volumio volumio[16270]: info: ----- MyVolumio plugins startup ---- Feb 10 20:10:47 volumio volumio[16270]: info: ------------------------------------------- Feb 10 20:10:47 volumio volumio[16270]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 10 20:10:47 volumio volumio[16270]: error: updateQueue error: null Feb 10 20:10:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 10 20:10:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:10:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:10:47 volumio go-librespot[16587]: go-librespot daemon starting... Feb 10 20:10:47 volumio go-librespot[16588]: time="2026-02-10T20:10:47+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 20:10:47 volumio go-librespot[16588]: time="2026-02-10T20:10:47+07:00" level=debug msg="app state loaded" Feb 10 20:10:47 volumio go-librespot[16588]: time="2026-02-10T20:10:47+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 20:10:48 volumio go-librespot[16588]: time="2026-02-10T20:10:48+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 20:10:48 volumio go-librespot[16588]: time="2026-02-10T20:10:48+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 10 20:10:48 volumio go-librespot[16588]: time="2026-02-10T20:10:48+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 10 20:10:48 volumio go-librespot[16588]: time="2026-02-10T20:10:48+07:00" level=info msg="zeroconf server listening on port 39399" Feb 10 20:10:48 volumio go-librespot[16588]: time="2026-02-10T20:10:48+07:00" level=debug msg="obtained new client token: AAAwQuPVOYRMgjqtlDHbcbUy4jIZokDDtYh2s/cNDcYyplRSq1XKvUdOJNBswfPPkWLhd4bxXR026OU5rssyjQBoieSBAUYwIpRfsKrbqVyPgg+cCQrHt2Rf2tfF3mADYIXtga0J7ByKtGO1MJ4+ScYyBHB8dGgj4fxqTdjEh/xLpbd3i24MBe/5YDQ0PvRZs4lBCAw0/IrSOM/4jne2EU9sB8RL9BKdUNHf+3OxpmocvklXRV7s+JlXPQ==" Feb 10 20:10:48 volumio go-librespot[16588]: time="2026-02-10T20:10:48+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 20:10:48 volumio go-librespot[16588]: time="2026-02-10T20:10:48+07:00" level=debug msg="completed keyexchange" Feb 10 20:10:48 volumio go-librespot[16588]: time="2026-02-10T20:10:48+07:00" level=debug msg="completed challenge" Feb 10 20:10:48 volumio go-librespot[16588]: time="2026-02-10T20:10: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 10 20:10:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 20:10:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 20:10:49 volumio volumio[16270]: info: Initializing connection to go-librespot Websocket Feb 10 20:10:49 volumio volumio[16270]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 20:10:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 10 20:10:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:10:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:10:51 volumio go-librespot[16596]: go-librespot daemon starting... Feb 10 20:10:51 volumio go-librespot[16597]: time="2026-02-10T20:10:51+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 20:10:51 volumio go-librespot[16597]: time="2026-02-10T20:10:51+07:00" level=debug msg="app state loaded" Feb 10 20:10:51 volumio go-librespot[16597]: time="2026-02-10T20:10:51+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 20:10:51 volumio volumio[16270]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 10 20:10:52 volumio go-librespot[16597]: time="2026-02-10T20:10: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 10 20:10:52 volumio go-librespot[16597]: time="2026-02-10T20:10: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 10 20:10:52 volumio go-librespot[16597]: time="2026-02-10T20:10: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 10 20:10:52 volumio go-librespot[16597]: time="2026-02-10T20:10:52+07:00" level=info msg="zeroconf server listening on port 46609" Feb 10 20:10:52 volumio go-librespot[16597]: time="2026-02-10T20:10:52+07:00" level=debug msg="obtained new client token: AAD/h6Ap71uYYT25F8SAgYWUZ71Tf6VUVgpnBBHFtStvx1c3wSpt0p+wgrJPmG6XIxZnMNEl99ImO0eE5Iqag/qpIFgvBo6qONAe9fxczbBGFTupYVe1phwqcj4JE0CmWs9VUm7dZDp0J14UQUQNLmHAlIvC0QFHRh2pXzrNgHEHDPGmDZ+kJFneVAis6rgRbZqA8mX9kgOuStUNdh90nBel2TB/8ZtQ6VrC621A/I0BtGBZF6yHRydukg==" Feb 10 20:10:52 volumio go-librespot[16597]: time="2026-02-10T20:10:52+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 20:10:52 volumio go-librespot[16597]: time="2026-02-10T20:10:52+07:00" level=debug msg="completed keyexchange" Feb 10 20:10:52 volumio go-librespot[16597]: time="2026-02-10T20:10:52+07:00" level=debug msg="completed challenge" Feb 10 20:10:52 volumio go-librespot[16597]: time="2026-02-10T20:10:52+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 10 20:10:52 volumio volumio[16270]: info: Initializing connection to go-librespot Websocket Feb 10 20:10:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 20:10:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 20:10:52 volumio volumio[16270]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 20:10:55 volumio volumio[16270]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 10 20:10:55 volumio volumio[16270]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 10 20:10:55 volumio volumio[16270]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 10 20:10:55 volumio volumio[16270]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 10 20:10:55 volumio volumio[16270]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 10 20:10:55 volumio volumio[16270]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 10 20:10:55 volumio volumio[16270]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 10 20:10:55 volumio volumio[16270]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 10 20:10:55 volumio volumio[16270]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 10 20:10:55 volumio volumio[16270]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 10 20:10:55 volumio volumio[16270]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 10 20:10:55 volumio volumio[16270]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 10 20:10:55 volumio volumio[16270]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 10 20:10:55 volumio volumio[16270]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 10 20:10:55 volumio volumio[16270]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 10 20:10:55 volumio volumio[16270]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 10 20:10:55 volumio volumio[16270]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 10 20:10:55 volumio volumio[16270]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 10 20:10:55 volumio volumio[16270]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 10 20:10:55 volumio volumio[16270]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 10 20:10:55 volumio volumio[16270]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 10 20:10:55 volumio volumio[16270]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 10 20:10:55 volumio volumio[16270]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 10 20:10:55 volumio volumio[16270]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 10 20:10:55 volumio volumio[16270]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 10 20:10:55 volumio volumio[16270]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 10 20:10:55 volumio volumio[16270]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 10 20:10:55 volumio volumio[16270]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 10 20:10:55 volumio volumio[16270]: info: Adding plugin bluetooth to MyMusic Plugins Feb 10 20:10:55 volumio volumio[16270]: info: Adding plugin multiroom to MyMusic Plugins Feb 10 20:10:55 volumio volumio[16270]: info: Adding plugin metavolumio to MyMusic Plugins Feb 10 20:10:55 volumio volumio[16270]: info: Adding plugin cd_controller to MyMusic Plugins Feb 10 20:10:55 volumio volumio[16270]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 10 20:10:55 volumio volumio[16270]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 10 20:10:55 volumio volumio[16270]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 10 20:10:55 volumio volumio[16270]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 10 20:10:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 10 20:10:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:10:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:10:56 volumio go-librespot[16605]: go-librespot daemon starting... Feb 10 20:10:56 volumio go-librespot[16606]: time="2026-02-10T20:10:56+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 20:10:56 volumio go-librespot[16606]: time="2026-02-10T20:10:56+07:00" level=debug msg="app state loaded" Feb 10 20:10:56 volumio go-librespot[16606]: time="2026-02-10T20:10:56+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 20:10:56 volumio go-librespot[16606]: time="2026-02-10T20:10: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 20:10:56 volumio go-librespot[16606]: time="2026-02-10T20:10:56+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 10 20:10:56 volumio go-librespot[16606]: time="2026-02-10T20:10:56+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 10 20:10:56 volumio go-librespot[16606]: time="2026-02-10T20:10:56+07:00" level=info msg="zeroconf server listening on port 39287" Feb 10 20:10:56 volumio go-librespot[16606]: time="2026-02-10T20:10:56+07:00" level=debug msg="obtained new client token: AADelI5SUq7pMu82SiigqeFwJKyyR2h7xsdO75/RCpoWxVWMoWByJn+FSN/YaXVNabtpCg9jSj3BXDRC9zwbczwBAXLCZrrSl5sYc3CBYmCHJSCmQ7vC7xHE4lHzrf6Nor9AfgeKpp8nQSwIewTcfP3EKo80cat/RE74Xh7Nz9oxKAmosddJ5IHyE9Yiu3TQU6vSMQ/KBgGSOx5Ur5t32XypddHPIUdC+7d+SEKsieWYy9kz03NWyZmp8w==" Feb 10 20:10:57 volumio go-librespot[16606]: time="2026-02-10T20:10:57+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 10 20:10:57 volumio go-librespot[16606]: time="2026-02-10T20:10:57+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.241.202:443: connect: connection refused" Feb 10 20:10:57 volumio go-librespot[16606]: time="2026-02-10T20:10:57+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 10 20:10:57 volumio go-librespot[16606]: time="2026-02-10T20:10:57+07:00" level=debug msg="completed keyexchange" Feb 10 20:10:57 volumio go-librespot[16606]: time="2026-02-10T20:10:57+07:00" level=debug msg="completed challenge" Feb 10 20:10:57 volumio go-librespot[16606]: time="2026-02-10T20:10: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 10 20:10:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 20:10:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 20:10:57 volumio volumio[16270]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 10 20:10:57 volumio volumio[16270]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 10 20:10:57 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 20:10:57 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 20:10:57 volumio volumio[16270]: info: Starting MyVolumio Remote Streaming Endpoints Feb 10 20:10:57 volumio volumio[16270]: info: MyVolumio login type: Token Feb 10 20:10:57 volumio volumio[16270]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 10 20:10:57 volumio volumio[16270]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 10 20:10:59 volumio volumio[16270]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 10 20:10:59 volumio volumio[16270]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 10 20:10:59 volumio volumio[16270]: info: Streaming services startup Feb 10 20:10:59 volumio volumio[16270]: info: Starting Streaming Daemon Feb 10 20:10:59 volumio sudo[16629]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 10 20:10:59 volumio sudo[16629]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:10:59 volumio volumio[16270]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 10 20:10:59 volumio sudo[16629]: pam_unix(sudo:session): session closed for user root Feb 10 20:10:59 volumio volumio[16270]: info: Initializing connection to go-librespot Websocket Feb 10 20:10:59 volumio volumio[16270]: error: Cannot start Volumio Streaming Daemon Feb 10 20:10:59 volumio volumio[16270]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 10 20:10:59 volumio volumio[16270]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 10 20:10:59 volumio volumio[16270]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 20:11:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 10 20:11:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:11:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:11:00 volumio go-librespot[16636]: go-librespot daemon starting... Feb 10 20:11:00 volumio go-librespot[16637]: time="2026-02-10T20:11:00+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 20:11:00 volumio go-librespot[16637]: time="2026-02-10T20:11:00+07:00" level=debug msg="app state loaded" Feb 10 20:11:00 volumio go-librespot[16637]: time="2026-02-10T20:11:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 20:11:00 volumio volumio[16270]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 10 20:11:01 volumio go-librespot[16637]: time="2026-02-10T20:11: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 20:11:01 volumio go-librespot[16637]: time="2026-02-10T20:11:01+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 10 20:11:01 volumio go-librespot[16637]: time="2026-02-10T20:11:01+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 10 20:11:01 volumio go-librespot[16637]: time="2026-02-10T20:11:01+07:00" level=info msg="zeroconf server listening on port 34989" Feb 10 20:11:01 volumio go-librespot[16637]: time="2026-02-10T20:11:01+07:00" level=debug msg="obtained new client token: AADpZt4wrlUFCJ5XlyLi50xSun03Fh+dJhs/RdIf/W6fRmmuE/BJi3cqDojNdjhkgroW+B4QOPovd//mU2v5i9arjyRwwvKZYDCCXYfwrYNnC6XoAsIa+GeDVbPlgJD8r2HaT4Nzo/IacBqsbLGDMmXgAevc3uqXpwIe4cFo+M8fOMrV9IZUfOqnALBG+nYtVAw505HkeIwC7O5UeAtCd4MSICBzq1dsYl/c9v8aoNV6Do7PIMwUpByWZQ==" Feb 10 20:11:01 volumio go-librespot[16637]: time="2026-02-10T20:11:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 20:11:01 volumio go-librespot[16637]: time="2026-02-10T20:11: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 10 20:11:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 20:11:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 20:11:02 volumio volumio[16270]: info: MyVolumio token set successfully Feb 10 20:11:02 volumio volumio[16270]: info: MYVOLUMIO: Adding device Feb 10 20:11:02 volumio volumio[16270]: info: MYVOLUMIO: Evaluating Server Feb 10 20:11:03 volumio volumio[16270]: info: Initializing connection to go-librespot Websocket Feb 10 20:11:03 volumio volumio[16270]: info: MyVolumio status changed Feb 10 20:11:03 volumio volumio[16270]: info: Streaming services startup Feb 10 20:11:03 volumio volumio[16270]: info: Starting Streaming Daemon Feb 10 20:11:03 volumio volumio[16270]: info: Removing browser output: myVolumio user plan is not superstar Feb 10 20:11:03 volumio volumio[16270]: info: Removing audio output: Feb 10 20:11:03 volumio volumio[16270]: info: Stoppping Tunnel 1 Feb 10 20:11:03 volumio sudo[16665]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 10 20:11:03 volumio sudo[16665]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:11:03 volumio sudo[16665]: pam_unix(sudo:session): session closed for user root Feb 10 20:11:03 volumio sudo[16668]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 10 20:11:03 volumio sudo[16668]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:11:03 volumio volumio[16270]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 20:11:03 volumio volumio[16270]: error: Cannot start Volumio Streaming Daemon Feb 10 20:11:03 volumio volumio[16270]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 10 20:11:03 volumio volumio[16270]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 10 20:11:03 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 10 20:11:03 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 10 20:11:03 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 10 20:11:03 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 10 20:11:03 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 10 20:11:03 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 10 20:11:03 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 10 20:11:03 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 10 20:11:03 volumio sudo[16668]: pam_unix(sudo:session): session closed for user root Feb 10 20:11:03 volumio volumio[16270]: info: Remote SSH Stopped Feb 10 20:11:03 volumio volumio[16270]: info: Setting Geolocation for MyVolumio to as1 Feb 10 20:11:03 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 20:11:03 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 20:11:03 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 20:11:04 volumio volumio[16270]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 10 20:11:04 volumio volumio[16270]: info: Updating MyVolumio device info Feb 10 20:11:04 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 20:11:04 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 20:11:04 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 20:11:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Feb 10 20:11:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:11:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:11:04 volumio go-librespot[16670]: go-librespot daemon starting... Feb 10 20:11:04 volumio go-librespot[16671]: time="2026-02-10T20:11:04+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 20:11:04 volumio go-librespot[16671]: time="2026-02-10T20:11:04+07:00" level=debug msg="app state loaded" Feb 10 20:11:04 volumio go-librespot[16671]: time="2026-02-10T20:11:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 20:11:04 volumio volumio[16270]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 10 20:11:05 volumio go-librespot[16671]: time="2026-02-10T20:11: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 10 20:11:05 volumio go-librespot[16671]: time="2026-02-10T20:11: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 10 20:11:05 volumio go-librespot[16671]: time="2026-02-10T20:11: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 10 20:11:05 volumio go-librespot[16671]: time="2026-02-10T20:11:05+07:00" level=info msg="zeroconf server listening on port 41909" Feb 10 20:11:05 volumio go-librespot[16671]: time="2026-02-10T20:11:05+07:00" level=debug msg="obtained new client token: AACw07NRke/oVudw+gp2EaGTV1fPKKPsz0+111oMt1BcmuCOQLnUdfLpWt/xYgjqtdr5059QBwcXJqutZhCwuh6ClTjF+L7gDMbADeC2WlxPCKAa9fO5aMK9Psy3mFVk/xoSjgtslgbxAzJd/UD0oEwvry6145nXY2zD2tFDZLyW/ia71Zeo2YlbiCXyD06gseb39cVcyTQkXepR2VlkK+nPFuyQ9Kxy/0dmxC/S3bm5mP+PruGuVDLIBQ==" Feb 10 20:11:05 volumio go-librespot[16671]: time="2026-02-10T20:11:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 20:11:05 volumio go-librespot[16671]: time="2026-02-10T20:11:05+07:00" level=debug msg="completed keyexchange" Feb 10 20:11:05 volumio go-librespot[16671]: time="2026-02-10T20:11:05+07:00" level=debug msg="completed challenge" Feb 10 20:11:05 volumio go-librespot[16671]: time="2026-02-10T20:11:05+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 10 20:11:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 20:11:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 20:11:06 volumio volumio[16270]: info: Initializing connection to go-librespot Websocket Feb 10 20:11:06 volumio volumio[16270]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 20:11:08 volumio volumio[16270]: info: MYVOLUMIO: Adding device Feb 10 20:11:08 volumio volumio[16270]: info: MYVOLUMIO: Evaluating Server Feb 10 20:11:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Feb 10 20:11:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:11:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:11:09 volumio go-librespot[16711]: go-librespot daemon starting... Feb 10 20:11:09 volumio go-librespot[16712]: time="2026-02-10T20:11:09+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 20:11:09 volumio go-librespot[16712]: time="2026-02-10T20:11:09+07:00" level=debug msg="app state loaded" Feb 10 20:11:09 volumio go-librespot[16712]: time="2026-02-10T20:11:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 20:11:09 volumio volumio[16270]: info: Setting Geolocation for MyVolumio to as1 Feb 10 20:11:09 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 20:11:09 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 20:11:09 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 20:11:09 volumio volumio[16270]: info: Initializing connection to go-librespot Websocket Feb 10 20:11:09 volumio go-librespot[16712]: time="2026-02-10T20:11:09+07:00" level=debug msg="new websocket client" Feb 10 20:11:09 volumio volumio[16270]: info: Connection to go-librespot Websocket established Feb 10 20:11:09 volumio go-librespot[16712]: time="2026-02-10T20:11: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-gew4.spotify.com:80]" Feb 10 20:11:09 volumio go-librespot[16712]: time="2026-02-10T20:11:09+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 10 20:11:09 volumio go-librespot[16712]: time="2026-02-10T20:11:09+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 10 20:11:09 volumio go-librespot[16712]: time="2026-02-10T20:11:09+07:00" level=info msg="zeroconf server listening on port 33161" Feb 10 20:11:09 volumio volumio[16270]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 10 20:11:09 volumio go-librespot[16712]: time="2026-02-10T20:11:09+07:00" level=debug msg="obtained new client token: AADGQ+OT4pOB90NVjWIl9oo+MijxdJUXtd6EjdJSOLJCDByJZZqM564k7e3H0gFd4cazX/xu1pprcu+eydpHYdGQRXZMhlPX/nmJIe4yPYWq907fJHditYxl8ZXkCNfOxX7lqOpCmlytjOr5mTuzzxqAh+JeMWpooa1uE45TUTpcyVwAcBkUoD0bmnjpk38XggE3aQaaO+ojuF3GfMn3sNgAUGvqv6xAzNiPo22hbAgB6sDsqs/YbhkU8w==" Feb 10 20:11:10 volumio go-librespot[16712]: time="2026-02-10T20:11:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 20:11:10 volumio go-librespot[16712]: time="2026-02-10T20:11:10+07:00" level=debug msg="completed keyexchange" Feb 10 20:11:10 volumio go-librespot[16712]: time="2026-02-10T20:11:10+07:00" level=debug msg="completed challenge" Feb 10 20:11:10 volumio go-librespot[16712]: time="2026-02-10T20:11:10+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 10 20:11:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 20:11:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 20:11:10 volumio volumio[16270]: info: Connection to go-librespot Websocket closed Feb 10 20:11:10 volumio volumio[16270]: info: Updating MyVolumio device info Feb 10 20:11:10 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 20:11:10 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 20:11:10 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 20:11:10 volumio volumio[16270]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 10 20:11:11 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 20:11:11 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 20:11:11 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 10 20:11:11 volumio volumio-remote-updater[643]: Test mode disabled Feb 10 20:11:11 volumio volumio-remote-updater[643]: Alpha mode disabled Feb 10 20:11:11 volumio volumio-remote-updater[643]: Alpha legacy test mode disabled Feb 10 20:11:11 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Feb 10 20:11:12 volumio volumio[16270]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"

FIXES

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

NEW ADDITIONS

\n
    \n
  • Add BLE onboarding plugin
    • \n
  • Enable vc4-kms-v3d for all compatible RPi models
    • \n
  • Update Tidal SDK
    • \n
\n","title":"Update v4.096","updateavailable":true} Feb 10 20:11:12 volumio volumio[16270]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Feb 10 20:11:12 volumio volumio[16270]: info: Getting Spotify volume Feb 10 20:11:12 volumio volumio[16270]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 20:11:12 volumio volumio[16270]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 20:11:12 volumio volumio[16270]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 10 20:11:12 volumio volumio[16270]: errno: -111, Feb 10 20:11:12 volumio volumio[16270]: code: 'ECONNREFUSED', Feb 10 20:11:12 volumio volumio[16270]: syscall: 'connect', Feb 10 20:11:12 volumio volumio[16270]: address: '127.0.0.1', Feb 10 20:11:12 volumio volumio[16270]: port: 9879, Feb 10 20:11:12 volumio volumio[16270]: response: undefined Feb 10 20:11:12 volumio volumio[16270]: } Feb 10 20:11:12 volumio volumio[16270]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 20:11:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Feb 10 20:11:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:11:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:11:13 volumio go-librespot[16736]: go-librespot daemon starting... Feb 10 20:11:13 volumio go-librespot[16737]: time="2026-02-10T20:11:13+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 20:11:13 volumio go-librespot[16737]: time="2026-02-10T20:11:13+07:00" level=debug msg="app state loaded" Feb 10 20:11:13 volumio go-librespot[16737]: time="2026-02-10T20:11:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 20:11:13 volumio sudo[16747]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-10 20:10' Feb 10 20:11:13 volumio sudo[16747]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:11:13 volumio go-librespot[16737]: time="2026-02-10T20:11: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-gew4.spotify.com:80]" Feb 10 20:11:13 volumio go-librespot[16737]: time="2026-02-10T20:11:13+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 10 20:11:13 volumio go-librespot[16737]: time="2026-02-10T20:11:13+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 10 20:11:13 volumio go-librespot[16737]: time="2026-02-10T20:11:13+07:00" level=info msg="zeroconf server listening on port 38631" Feb 10 20:11:14 volumio go-librespot[16737]: time="2026-02-10T20:11:14+07:00" level=debug msg="obtained new client token: AAAma39zYDM4mPVkIuNcAteyXjvL/UL3AZar/I3PlOI+TX8ug21aY6qAD4dqmDdYHpU2AtxdT0+zDWElHmJG60Rug6y83oLimXGDecw4TXiSKPdjDqVT/5Q3D2KIgfIr9j+yFuxW0VGwN4JUw4/LrbjYsJPfAJEMJ+pLcqJiN2N5/hBCxXRqvigG+dmOemsYasjHXKHuAfrUWfL+rXFXLnzHO0vgzRa2qogSpg2JEL+89n4YaOLnh5w=" Feb 10 20:11:14 volumio sudo[16747]: pam_unix(sudo:session): session closed for user root Feb 10 20:11:14 volumio go-librespot[16737]: time="2026-02-10T20:11:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 20:11:14 volumio go-librespot[16737]: time="2026-02-10T20:11:14+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 10 20:11:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 20:11:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 20:11:14 volumio volumio-remote-updater[643]: [2026-02-10 20:11:14] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 10 20:11:14 volumio volumio-remote-updater[643]: [2026-02-10 20:11:14] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 10 20:11:14 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 10 20:11:14 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 10 20:11:14 volumio systemd[1]: volumio.service: Consumed 58.407s CPU time. Feb 10 20:11:14 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 10 20:11:14 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10697. Feb 10 20:11:14 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 10 20:11:14 volumio systemd[1]: volumio.service: Consumed 58.407s CPU time. Feb 10 20:11:14 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 10 20:11:14 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 10 20:11:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Feb 10 20:11:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:11:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:11:17 volumio go-librespot[16774]: go-librespot daemon starting... Feb 10 20:11:17 volumio go-librespot[16775]: time="2026-02-10T20:11:17+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 20:11:17 volumio go-librespot[16775]: time="2026-02-10T20:11:17+07:00" level=debug msg="app state loaded" Feb 10 20:11:17 volumio go-librespot[16775]: time="2026-02-10T20:11:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 20:11:18 volumio volumio[16762]: info: ------------------------------------------- Feb 10 20:11:18 volumio volumio[16762]: info: ----- Volumio3 ---- Feb 10 20:11:18 volumio volumio[16762]: info: ------------------------------------------- Feb 10 20:11:18 volumio volumio[16762]: info: ----- System startup ---- Feb 10 20:11:18 volumio volumio[16762]: info: ------------------------------------------- Feb 10 20:11:18 volumio go-librespot[16775]: time="2026-02-10T20:11:18+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 10 20:11:18 volumio go-librespot[16775]: time="2026-02-10T20:11:18+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 10 20:11:18 volumio go-librespot[16775]: time="2026-02-10T20:11:18+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 10 20:11:18 volumio go-librespot[16775]: time="2026-02-10T20:11:18+07:00" level=info msg="zeroconf server listening on port 41469" Feb 10 20:11:18 volumio go-librespot[16775]: time="2026-02-10T20:11:18+07:00" level=debug msg="obtained new client token: AAC2I73FbjohKqGnutOojLirzBsrvZydPWXvo4F1o7wb+2xZcOLf7lxRYu63oKwU0lWdguGUueYjKpDvkFpS3Jy/haQxuTyZXmJ3phHXVRz3RKw0MyyKPuzBcHUMOVZa2wx3Ddnv27OSb5QuwBPlkwiN2EjW0mqqDylnpt+HFYSA/PyQJoiTx83PNSS+L0p63va4RTsJRXswKjMmYsji5PpyRaVg3JhMQSzghRlrCdne8lVqp28GlgD22Q==" Feb 10 20:11:18 volumio go-librespot[16775]: time="2026-02-10T20:11:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 20:11:18 volumio go-librespot[16775]: time="2026-02-10T20:11:18+07:00" level=debug msg="completed keyexchange" Feb 10 20:11:18 volumio go-librespot[16775]: time="2026-02-10T20:11:18+07:00" level=debug msg="completed challenge" Feb 10 20:11:18 volumio go-librespot[16775]: time="2026-02-10T20:11:18+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 10 20:11:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 20:11:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 20:11:19 volumio volumio-remote-updater[643]: [2026-02-10 20:11:19] [connect] Successful connection Feb 10 20:11:19 volumio volumio[16762]: info: MYVOLUMIO Environment detected Feb 10 20:11:19 volumio volumio[16762]: info: Plugin folders cleanup Feb 10 20:11:19 volumio volumio[16762]: info: Scanning into folder /volumio/app/plugins/ Feb 10 20:11:19 volumio volumio[16762]: info: Scanning category audio_interface Feb 10 20:11:19 volumio volumio[16762]: info: Scanning category miscellanea Feb 10 20:11:19 volumio volumio[16762]: info: Scanning category music_service Feb 10 20:11:19 volumio volumio[16762]: info: Scanning category plugins.json Feb 10 20:11:19 volumio volumio[16762]: info: Scanning category system_controller Feb 10 20:11:19 volumio volumio[16762]: info: Scanning category user_interface Feb 10 20:11:19 volumio volumio[16762]: info: Scanning into folder /data/plugins/ Feb 10 20:11:19 volumio volumio[16762]: info: Scanning category music_service Feb 10 20:11:19 volumio volumio[16762]: info: Plugin folders cleanup completed Feb 10 20:11:19 volumio volumio[16762]: info: ------------------------------------------- Feb 10 20:11:19 volumio volumio[16762]: info: ----- Core plugins startup ---- Feb 10 20:11:19 volumio volumio[16762]: info: ------------------------------------------- Feb 10 20:11:19 volumio volumio[16762]: info: Loading plugins from folder /volumio/app/plugins/ Feb 10 20:11:19 volumio volumio[16762]: info: Adding plugin upnp to MyMusic Plugins Feb 10 20:11:19 volumio volumio[16762]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 10 20:11:19 volumio volumio[16762]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 10 20:11:19 volumio volumio[16762]: info: Loading plugins from folder /data/plugins/ Feb 10 20:11:19 volumio volumio[16762]: info: Loading plugin "system"... Feb 10 20:11:19 volumio volumio[16762]: info: Loading plugin "appearance"... Feb 10 20:11:21 volumio volumio[16762]: info: Loading plugin "network"... Feb 10 20:11:21 volumio volumio[16762]: info: Refreshing Cached IP Addresses Feb 10 20:11:21 volumio sudo[16796]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 10 20:11:21 volumio sudo[16796]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:11:21 volumio sudo[16798]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 10 20:11:21 volumio sudo[16798]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:11:21 volumio sudo[16796]: pam_unix(sudo:session): session closed for user root Feb 10 20:11:21 volumio volumio[16762]: info: Loading plugin "services"... Feb 10 20:11:21 volumio volumio[16762]: info: Loading plugin "alsa_controller"... Feb 10 20:11:21 volumio sudo[16798]: pam_unix(sudo:session): session closed for user root Feb 10 20:11:21 volumio sudo[16806]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 10 20:11:21 volumio sudo[16806]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:11:22 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 20:11:22 volumio volumio[16762]: info: Loading plugin "wizard"... Feb 10 20:11:22 volumio volumio[16762]: info: Loading plugin "networkfs"... Feb 10 20:11:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Feb 10 20:11:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:11:22 volumio volumio[16762]: info: Starting Udev Watcher for removable devices Feb 10 20:11:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:11:22 volumio go-librespot[16829]: go-librespot daemon starting... Feb 10 20:11:22 volumio volumio[16762]: info: Ignoring mount for partition: boot Feb 10 20:11:22 volumio volumio[16762]: info: Ignoring mount for partition: volumio Feb 10 20:11:22 volumio volumio[16762]: info: Ignoring mount for partition: volumio_data Feb 10 20:11:22 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 20:11:22 volumio volumio[16762]: info: Loading plugin "volumio_command_line_client"... Feb 10 20:11:22 volumio volumio[16762]: info: Loading plugin "upnp"... Feb 10 20:11:22 volumio volumio[16762]: info: [1770729082179] Starting Upmpd Daemon Feb 10 20:11:22 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 20:11:22 volumio volumio[16762]: info: Loading plugin "my_music"... Feb 10 20:11:22 volumio go-librespot[16830]: time="2026-02-10T20:11:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 20:11:22 volumio go-librespot[16830]: time="2026-02-10T20:11:22+07:00" level=debug msg="app state loaded" Feb 10 20:11:22 volumio go-librespot[16830]: time="2026-02-10T20:11:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 20:11:22 volumio volumio[16762]: info: Loading plugin "mpd"... Feb 10 20:11:22 volumio go-librespot[16830]: time="2026-02-10T20:11: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 10 20:11:22 volumio go-librespot[16830]: time="2026-02-10T20:11: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 10 20:11:22 volumio go-librespot[16830]: time="2026-02-10T20:11: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 10 20:11:22 volumio go-librespot[16830]: time="2026-02-10T20:11:22+07:00" level=info msg="zeroconf server listening on port 39041" Feb 10 20:11:22 volumio volumio[16762]: info: Loading plugin "upnp_browser"... Feb 10 20:11:22 volumio go-librespot[16830]: time="2026-02-10T20:11:22+07:00" level=debug msg="obtained new client token: AADG2OVfXRHTEon7gQ2mxOmRyrQ31Na7+X/FqsswiHGvFxuM4/APWPKlqyeoY8dUtgRNSDaqfvkkB+wF9xlLIYvCCoaxsP2kpwr36YrTyLYhK8lDT7yZ7IKrMQ+fslpn0J6mRBN2yjaD8w1DU6x/irt82sY2tgU/0/eQddlLvn3HFLGUgHhyPsfVkcDPXtpZEtyGTHDDVLRypYIBS3wt5X+LfDGXJOKP0d9ZLfJyvEsalJUddtQ3cZwKnw==" Feb 10 20:11:23 volumio go-librespot[16830]: time="2026-02-10T20:11:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 20:11:23 volumio go-librespot[16830]: time="2026-02-10T20:11: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 10 20:11:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 20:11:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 20:11:24 volumio sudo[16806]: pam_unix(sudo:session): session closed for user root Feb 10 20:11:25 volumio volumio[16762]: info: Starting UPNP Browser Feb 10 20:11:25 volumio volumio[16762]: info: Loading plugin "alarm-clock"... Feb 10 20:11:26 volumio volumio[16762]: info: Loading plugin "airplay_emulation"... Feb 10 20:11:26 volumio volumio[16762]: info: Starting Shairport Sync Feb 10 20:11:26 volumio volumio[16762]: info: Loading plugin "last_100"... Feb 10 20:11:26 volumio volumio[16762]: info: Loading plugin "webradio"... Feb 10 20:11:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Feb 10 20:11:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:11:26 volumio volumio[16762]: info: Loading plugin "i2s_dacs"... Feb 10 20:11:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:11:26 volumio volumio[16762]: info: Loading plugin "volumiodiscovery"... Feb 10 20:11:26 volumio go-librespot[16837]: go-librespot daemon starting... Feb 10 20:11:26 volumio go-librespot[16838]: time="2026-02-10T20:11:26+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 20:11:26 volumio go-librespot[16838]: time="2026-02-10T20:11:26+07:00" level=debug msg="app state loaded" Feb 10 20:11:26 volumio go-librespot[16838]: time="2026-02-10T20:11:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 20:11:26 volumio volumio[16762]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 20:11:26 volumio volumio[16762]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 20:11:26 volumio volumio[16762]: *** WARNING *** For more information see Feb 10 20:11:26 volumio volumio[16762]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 20:11:26 volumio volumio[16762]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 20:11:26 volumio volumio[16762]: *** WARNING *** For more information see Feb 10 20:11:26 volumio node[16762]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 20:11:26 volumio node[16762]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 20:11:26 volumio node[16762]: *** WARNING *** For more information see Feb 10 20:11:26 volumio node[16762]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 20:11:26 volumio node[16762]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 20:11:26 volumio node[16762]: *** WARNING *** For more information see Feb 10 20:11:26 volumio volumio[16762]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 10 20:11:26 volumio volumio[16762]: info: Discovery: Started advertising with name: Volumio Feb 10 20:11:26 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 20:11:26 volumio volumio[16762]: info: Loading plugin "spop"... Feb 10 20:11:26 volumio go-librespot[16838]: time="2026-02-10T20:11:26+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 10 20:11:26 volumio go-librespot[16838]: time="2026-02-10T20:11:26+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 10 20:11:26 volumio go-librespot[16838]: time="2026-02-10T20:11:26+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 10 20:11:27 volumio go-librespot[16838]: time="2026-02-10T20:11:27+07:00" level=info msg="zeroconf server listening on port 41947" Feb 10 20:11:27 volumio go-librespot[16838]: time="2026-02-10T20:11:27+07:00" level=debug msg="obtained new client token: AADNYW/VdU66OmcoEVKl48w3WNZOl0mAcIYwhio4Stp/F+/qGzWXydUcNa2j19ecW4qh3I1fyC0xidSDknU/GsXluQGHnlSyuWWKNxCTNy3qjIDBfW26p7Wutm/W2p2BE1yPO/mnl+RJhk4jVqMlQ5gKesJLamHF3qVst/zGd8HjT4QnxFRpubbAZzuMGKS0SrNsEg339JuQY6yzd6HyPppzm25VX6yc3T6pa84k4/HW+eTu0tIMIf4=" Feb 10 20:11:27 volumio go-librespot[16838]: time="2026-02-10T20:11:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 20:11:27 volumio go-librespot[16838]: time="2026-02-10T20:11:27+07:00" level=debug msg="completed keyexchange" Feb 10 20:11:27 volumio go-librespot[16838]: time="2026-02-10T20:11:27+07:00" level=debug msg="completed challenge" Feb 10 20:11:27 volumio go-librespot[16838]: time="2026-02-10T20:11:27+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 10 20:11:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 20:11:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 20:11:28 volumio volumio[16762]: info: Loading plugin "ytcr"... Feb 10 20:11:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Feb 10 20:11:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:11:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:11:30 volumio go-librespot[16848]: go-librespot daemon starting... Feb 10 20:11:30 volumio go-librespot[16849]: time="2026-02-10T20:11:30+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 20:11:30 volumio go-librespot[16849]: time="2026-02-10T20:11:30+07:00" level=debug msg="app state loaded" Feb 10 20:11:30 volumio go-librespot[16849]: time="2026-02-10T20:11:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 20:11:31 volumio volumio[16762]: info: Loading plugin "ytmusic"... Feb 10 20:11:31 volumio go-librespot[16849]: time="2026-02-10T20:11: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 10 20:11:31 volumio go-librespot[16849]: time="2026-02-10T20:11: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 10 20:11:31 volumio go-librespot[16849]: time="2026-02-10T20:11: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 10 20:11:31 volumio go-librespot[16849]: time="2026-02-10T20:11:31+07:00" level=info msg="zeroconf server listening on port 32785" Feb 10 20:11:31 volumio go-librespot[16849]: time="2026-02-10T20:11:31+07:00" level=debug msg="obtained new client token: AAAVWSvdmopzVmzmRsYULy+4fcFEjCak2F3wpIZeKjSrvHaKpsUzIN6DLnoW7ymXy93ZA4kDXZE8bgoLpKBZo2OtxmCg3c2u7+m0N9+uHmEnkhUcPbCL8sCtvJkGtHetczzC6n7PIxY5RZzPWOYUPta4OuW5IKPP7L4OthCMbMkYqgViWGjfjEtEjzdAtlNcXTE5dd3W9l0W1l4fFAYkfmcEB5qDFGcqg7P8dGl4tOgCoxI/Tk1tVa75dg==" Feb 10 20:11:31 volumio go-librespot[16849]: time="2026-02-10T20:11:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 20:11:31 volumio go-librespot[16849]: time="2026-02-10T20:11:31+07:00" level=debug msg="completed keyexchange" Feb 10 20:11:31 volumio go-librespot[16849]: time="2026-02-10T20:11:31+07:00" level=debug msg="completed challenge" Feb 10 20:11:31 volumio go-librespot[16849]: time="2026-02-10T20:11:31+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 10 20:11:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 20:11:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 20:11:31 volumio volumio-remote-updater[643]: [2026-02-10 20:11:31] [connect] Successful connection Feb 10 20:11:32 volumio volumio[16762]: info: Loading plugin "outputs"... Feb 10 20:11:32 volumio volumio[16762]: info: Loading plugin "albumart"... Feb 10 20:11:32 volumio volumio[16762]: info: Plugin example_plugin is not enabled Feb 10 20:11:32 volumio volumio[16762]: info: Loading plugin "inputs"... Feb 10 20:11:32 volumio volumio[16762]: info: Loading plugin "updater_comm"... Feb 10 20:11:32 volumio volumio[16762]: info: Plugin mpdemulation is not enabled Feb 10 20:11:32 volumio volumio[16762]: info: Loading plugin "rest_api"... Feb 10 20:11:32 volumio volumio[16762]: info: Loading plugin "websocket"... Feb 10 20:11:32 volumio volumio[16762]: info: Starting Socket.io Server version 1.7.4 Feb 10 20:11:32 volumio volumio[16762]: info: Loading plugin "RoonBridge"... Feb 10 20:11:33 volumio volumio[16762]: info: Applying required configuration parameters for plugin RoonBridge Feb 10 20:11:33 volumio volumio[16762]: info: Loading i18n strings for locale en Feb 10 20:11:33 volumio volumio[16762]: Updating browse sources language Feb 10 20:11:33 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 20:11:33 volumio volumio[16870]: Forking 3 albumart workers Feb 10 20:11:33 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 20:11:33 volumio volumio[16762]: info: CoreCommandRouter::initPlayerControls Feb 10 20:11:33 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:11:33 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:11:33 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:11:33 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:11:33 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:11:33 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:11:33 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:11:33 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:11:33 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 20:11:33 volumio volumio[16762]: Express server listening on port 3000 Feb 10 20:11:33 volumio volumio[16762]: [Metrics] WebUI: 16s 347.41ms Feb 10 20:11:33 volumio volumio[16762]: info: CoreStateMachine::resetVolumioState Feb 10 20:11:33 volumio volumio[16762]: info: CoreStateMachine::getcurrentVolume Feb 10 20:11:33 volumio volumio[16762]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 20:11:33 volumio sudo[16915]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 10 20:11:33 volumio sudo[16915]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:11:33 volumio sudo[16917]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 10 20:11:33 volumio sudo[16915]: pam_unix(sudo:session): session closed for user root Feb 10 20:11:33 volumio sudo[16917]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:11:33 volumio volumio[16762]: info: Volumio Network Manager: Network status updated: 1 Feb 10 20:11:33 volumio sudo[16917]: pam_unix(sudo:session): session closed for user root Feb 10 20:11:34 volumio volumio[16762]: info: VolumeController:: Volume=100 Mute =false Feb 10 20:11:34 volumio volumio[16762]: info: CoreStateMachine::pushState Feb 10 20:11:34 volumio volumio[16762]: info: CorePlayQueue::getTrack 0 Feb 10 20:11:34 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 10 20:11:34 volumio volumio[16762]: info: CoreCommandRouter::volumioPushState Feb 10 20:11:34 volumio volumio[16762]: info: CoreStateMachine::updateTrackBlock Feb 10 20:11:34 volumio volumio[16762]: info: CorePlayQueue::getTrackBlock Feb 10 20:11:34 volumio volumio[16762]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 20:11:34 volumio volumio-remote-updater[643]: [2026-02-10 20:11:34] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770729091 101 Feb 10 20:11:34 volumio volumio[16762]: 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 10 20:11:34 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 20:11:34 volumio volumio[16762]: info: Reloading queue from file Feb 10 20:11:34 volumio volumio[16762]: info: CoreStateMachine::setRepeat null single undefined Feb 10 20:11:34 volumio volumio[16762]: info: CoreStateMachine::pushState Feb 10 20:11:34 volumio volumio[16762]: info: CorePlayQueue::getTrack 0 Feb 10 20:11:34 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 10 20:11:34 volumio volumio[16762]: info: CoreCommandRouter::volumioPushState Feb 10 20:11:34 volumio volumio[16762]: info: CoreStateMachine::setRandom null Feb 10 20:11:34 volumio volumio[16762]: info: CoreStateMachine::pushState Feb 10 20:11:34 volumio volumio[16762]: info: CorePlayQueue::getTrack 0 Feb 10 20:11:34 volumio volumio[16762]: info: CoreCommandRouter::volumioPushState Feb 10 20:11:34 volumio volumio[16762]: info: Setting Device type: Raspberry PI Feb 10 20:11:34 volumio volumio[16762]: info: Completed loading Core Plugins Feb 10 20:11:34 volumio volumio[16762]: info: Preparing to generate the ALSA configuration file Feb 10 20:11:34 volumio volumio[16762]: info: VolumeController:: Volume=100 Mute =false Feb 10 20:11:34 volumio volumio[16762]: info: CoreStateMachine::pushState Feb 10 20:11:34 volumio volumio[16762]: info: CorePlayQueue::getTrack 0 Feb 10 20:11:34 volumio volumio[16762]: info: CoreCommandRouter::volumioPushState Feb 10 20:11:34 volumio volumio[16762]: info: Asound.conf file unchanged, so no further update is needed Feb 10 20:11:34 volumio volumio[16762]: info: Output device has changed, restarting MPD Feb 10 20:11:34 volumio sudo[16931]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 10 20:11:34 volumio sudo[16931]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:11:34 volumio sudo[16934]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 20:11:34 volumio sudo[16934]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:11:34 volumio sudo[16934]: pam_unix(sudo:session): session closed for user root Feb 10 20:11:34 volumio volumio[16762]: info: Output device has changed, restarting Shairport Sync Feb 10 20:11:34 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:11:34 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 20:11:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Feb 10 20:11:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:11:34 volumio sudo[16937]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 20:11:34 volumio volumio[16762]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 20:11:34 volumio sudo[16937]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:11:34 volumio volumio[16762]: info: ___________ START PLUGINS ___________ Feb 10 20:11:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:11:34 volumio go-librespot[16942]: go-librespot daemon starting... Feb 10 20:11:34 volumio volumio[16762]: info: ControllerMpd::onStart: Initializing MPD Feb 10 20:11:34 volumio volumio[16762]: info: Creating MPD Configuration file Feb 10 20:11:34 volumio sudo[16931]: pam_unix(sudo:session): session closed for user root Feb 10 20:11:35 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 10 20:11:35 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 20:11:35 volumio volumio[16762]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 20:11:35 volumio volumio[16762]: info: [1770729095015] CoreMusicLibrary::Adding element Media Servers Feb 10 20:11:35 volumio go-librespot[16944]: time="2026-02-10T20:11:35+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 20:11:35 volumio go-librespot[16944]: time="2026-02-10T20:11:35+07:00" level=debug msg="app state loaded" Feb 10 20:11:35 volumio go-librespot[16944]: time="2026-02-10T20:11:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 20:11:35 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 20:11:35 volumio sudo[16950]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 20:11:35 volumio sudo[16950]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:11:35 volumio volumio[16762]: info: UPNP Browser: Client initialized successfully Feb 10 20:11:35 volumio sudo[16950]: pam_unix(sudo:session): session closed for user root Feb 10 20:11:35 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:11:35 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 20:11:35 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 10 20:11:35 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 10 20:11:35 volumio systemd[1]: mpd.service: Consumed 7.114s CPU time. Feb 10 20:11:35 volumio sudo[16953]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 20:11:35 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 10 20:11:35 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 10 20:11:35 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 10 20:11:35 volumio sudo[16953]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:11:35 volumio volumio[16762]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 20:11:35 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:11:35 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 20:11:35 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 10 20:11:35 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 10 20:11:35 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 10 20:11:35 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 10 20:11:35 volumio volumio[16762]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 20:11:35 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 10 20:11:35 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 10 20:11:35 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 10 20:11:35 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 10 20:11:35 volumio volumio[16762]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 20:11:35 volumio volumio[16762]: info: [1770729095430] CoreMusicLibrary::Adding element Last_100 Feb 10 20:11:35 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 20:11:35 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 10 20:11:35 volumio volumio[16762]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 20:11:35 volumio volumio[16762]: info: [1770729095464] CoreMusicLibrary::Adding element Webradio Feb 10 20:11:35 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 20:11:35 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 20:11:35 volumio volumio[16762]: info: Initializing BBC Radios Feb 10 20:11:35 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 20:11:35 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 20:11:35 volumio go-librespot[16944]: time="2026-02-10T20:11: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-gew4.spotify.com:80]" Feb 10 20:11:35 volumio go-librespot[16944]: time="2026-02-10T20:11:35+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 10 20:11:35 volumio go-librespot[16944]: time="2026-02-10T20:11:35+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 10 20:11:35 volumio go-librespot[16944]: time="2026-02-10T20:11:35+07:00" level=info msg="zeroconf server listening on port 39749" Feb 10 20:11:35 volumio volumio[16762]: info: Creating Spotify config file Feb 10 20:11:35 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:11:35 volumio sudo[16967]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 10 20:11:35 volumio sudo[16967]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 10 20:11:35 volumio sudo[16967]: pam_unix(sudo:session): session closed for user root Feb 10 20:11:36 volumio go-librespot[16944]: time="2026-02-10T20:11:36+07:00" level=debug msg="obtained new client token: AAAj0dmKeMJ2fWP1MdOTnN/0ozDwf2LBM0qQQB3euJKszGuitjN4+yUGMyQEY9Ir0V7qkH6ORkK3wHO8BLrTGC8/1m8mET4Rj0z3sxTkzKhhd8/xaFXs4Vd2p3ob2hv7ZkCo1yOTN5lPfaKX8XSeIQ9/eJVKinLUCLwGdiinu9UlA/7YsDtWMeQG7EtXr2D1wunpspcWvodzZGoVs5K9LS/LILISZPBL7stse6oAkln3y5vhhUBHM/Y=" Feb 10 20:11:36 volumio go-librespot[16944]: time="2026-02-10T20:11:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 20:11:36 volumio go-librespot[16944]: time="2026-02-10T20:11:36+07:00" level=debug msg="completed keyexchange" Feb 10 20:11:36 volumio go-librespot[16944]: time="2026-02-10T20:11:36+07:00" level=debug msg="completed challenge" Feb 10 20:11:36 volumio go-librespot[16944]: time="2026-02-10T20:11:36+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 10 20:11:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 20:11:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 20:11:36 volumio volumio[16880]: Starting albumart workers Feb 10 20:11:36 volumio volumio[16762]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 20:11:36 volumio volumio[16762]: info: [1770729096829] CoreMusicLibrary::Adding element YouTube Music Feb 10 20:11:36 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 20:11:36 volumio volumio[16762]: Cannot find translation for source YouTube Music Feb 10 20:11:36 volumio volumio[16762]: info: Volumio Calling Home Feb 10 20:11:37 volumio sudo[16985]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 10 20:11:37 volumio sudo[16985]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:11:37 volumio sudo[16985]: pam_unix(sudo:session): session closed for user root Feb 10 20:11:37 volumio volumio[16882]: Starting albumart workers Feb 10 20:11:37 volumio volumio[16881]: Starting albumart workers Feb 10 20:11:37 volumio volumio[16762]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 10 20:11:37 volumio volumio[16762]: info: Discovery: Found device Volumio Feb 10 20:11:37 volumio volumio[16762]: info: CoreCommandRouter::volumioGetState Feb 10 20:11:37 volumio volumio[16762]: info: CorePlayQueue::getTrack 0 Feb 10 20:11:37 volumio volumio[16762]: info: MPD Permissions set Feb 10 20:11:37 volumio volumio[16762]: info: MPD Permissions set Feb 10 20:11:37 volumio volumio[16762]: info: Upmpdcli Daemon Started Feb 10 20:11:37 volumio volumio[16762]: info: Spotify config file written Feb 10 20:11:37 volumio volumio[16762]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 10 20:11:37 volumio volumio[16762]: info: Discovery: Found device Volumio Feb 10 20:11:37 volumio volumio[16762]: info: CoreCommandRouter::volumioGetState Feb 10 20:11:37 volumio volumio[16762]: info: CorePlayQueue::getTrack 0 Feb 10 20:11:37 volumio sudo[16991]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 10 20:11:37 volumio sudo[16991]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:11:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:11:37 volumio volumio[16762]: 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 10 20:11:37 volumio go-librespot[16993]: go-librespot daemon starting... Feb 10 20:11:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:11:37 volumio volumio[16762]: info: Volumio called home Feb 10 20:11:37 volumio sudo[16991]: pam_unix(sudo:session): session closed for user root Feb 10 20:11:38 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:11:38 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:11:38 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:11:38 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:11:38 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:11:38 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:11:38 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:11:38 volumio go-librespot[16994]: time="2026-02-10T20:11:38+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 20:11:38 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:11:38 volumio go-librespot[16994]: time="2026-02-10T20:11:38+07:00" level=debug msg="app state loaded" Feb 10 20:11:38 volumio go-librespot[16994]: time="2026-02-10T20:11:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 20:11:38 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 20:11:38 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:11:38 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:11:38 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:11:38 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:11:38 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:11:38 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:11:38 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:11:38 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:11:38 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:11:38 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 20:11:38 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 20:11:38 volumio volumio[16762]: info: No need to fix Spotify hosts Feb 10 20:11:38 volumio go-librespot[16994]: time="2026-02-10T20:11:38+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 10 20:11:38 volumio go-librespot[16994]: time="2026-02-10T20:11:38+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 10 20:11:38 volumio go-librespot[16994]: time="2026-02-10T20:11:38+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 10 20:11:38 volumio go-librespot[16994]: time="2026-02-10T20:11:38+07:00" level=info msg="zeroconf server listening on port 40307" Feb 10 20:11:39 volumio go-librespot[16994]: time="2026-02-10T20:11:39+07:00" level=debug msg="obtained new client token: AADCISAebkVkd+ICCFtwViN0nnhUcADl5ImbQnWSbuApIN1fy4w5iQq7/2v4LtbGQghB4Gh7JKJfh7zNUeerMujHAnFjTetB/bb0r+77rzSyzBr8TzKpPOkT2WBRcb/+6itM8Z/iQRsai6IaFAn7adqfvgMCAV8MmvXlYelnas6iGyuMsQAM+b9p6XE4cQYegcHFTL/J98D7TC2knuw+V6ZguykZYxlgJnwxe8rGd9NZY4c4IFa8IXY=" Feb 10 20:11:39 volumio go-librespot[16994]: time="2026-02-10T20:11:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 20:11:39 volumio go-librespot[16994]: time="2026-02-10T20:11:39+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 10 20:11:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 20:11:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 20:11:39 volumio volumio[16762]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 20:11:39 volumio volumio[16762]: SPOTIFY: BQD6wa7SnWBHIZbVz6nlPD04MYhfYVoCsnGkgPpJ75nu3iN9xU0QhC6ByGW6nPlECkOfWJX5VAsWtzF5JPZNGyzquUyl5XPF4Ar4jFF2Z4DeD-x8LhOAeqzkgop7VRmoctS-vnzK6J9xDsYg4V-lhOdMZjgE9oeNXkGdyNO7s9UCAvIe_mQUyZ4O3owEixj8ymO8Fj1H_usU-b_keh1yuXXCCnTL-0mXUcPIWFOt36OEAg7QDXYyIsQ4T475kZlvZtcSs_geiSwUofHuIA0MTQUbW5SI3TsoMPrhfEvvY7j0UM_YYpn20zEk Feb 10 20:11:39 volumio volumio[16762]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 20:11:39 volumio volumio[16762]: info: New Spotify access token = BQD6wa7SnWBHIZbVz6nlPD04MYhfYVoCsnGkgPpJ75nu3iN9xU0QhC6ByGW6nPlECkOfWJX5VAsWtzF5JPZNGyzquUyl5XPF4Ar4jFF2Z4DeD-x8LhOAeqzkgop7VRmoctS-vnzK6J9xDsYg4V-lhOdMZjgE9oeNXkGdyNO7s9UCAvIe_mQUyZ4O3owEixj8ymO8Fj1H_usU-b_keh1yuXXCCnTL-0mXUcPIWFOt36OEAg7QDXYyIsQ4T475kZlvZtcSs_geiSwUofHuIA0MTQUbW5SI3TsoMPrhfEvvY7j0UM_YYpn20zEk Feb 10 20:11:39 volumio volumio[16762]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 10 20:11:39 volumio volumio[16762]: info: Starting Shairport Sync Feb 10 20:11:39 volumio volumio[16762]: info: Starting Shairport Sync Feb 10 20:11:39 volumio volumio[16762]: info: Starting Shairport Sync Feb 10 20:11:39 volumio sudo[17030]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 20:11:39 volumio sudo[17030]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:11:39 volumio sudo[17032]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 20:11:39 volumio sudo[17032]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:11:39 volumio sudo[17034]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 20:11:39 volumio sudo[17034]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:11:39 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 10 20:11:39 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 10 20:11:39 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 20:11:39 volumio systemd[1]: shairport-sync.service: Consumed 2.391s CPU time. Feb 10 20:11:40 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 20:11:40 volumio sudo[17030]: pam_unix(sudo:session): session closed for user root Feb 10 20:11:40 volumio sudo[17032]: pam_unix(sudo:session): session closed for user root Feb 10 20:11:40 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 10 20:11:40 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 10 20:11:40 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 20:11:40 volumio volumio[16762]: info: CoreCommandRouter::volumioGetState Feb 10 20:11:40 volumio volumio[16762]: info: CorePlayQueue::getTrack 0 Feb 10 20:11:40 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 20:11:40 volumio volumio[16762]: info: Shairport-Sync Started Feb 10 20:11:40 volumio volumio[16762]: Error adding Membership: Error: addMembership EINVAL Feb 10 20:11:40 volumio volumio[16762]: info: Shairport-Sync Started Feb 10 20:11:40 volumio sudo[17034]: pam_unix(sudo:session): session closed for user root Feb 10 20:11:40 volumio volumio[16762]: info: Shairport-Sync Started Feb 10 20:11:40 volumio volumio[16762]: 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 10 20:11:40 volumio volumio[16762]: info: Spotify Successfully logged in Feb 10 20:11:40 volumio volumio[16762]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 20:11:40 volumio volumio[16762]: info: [1770729100563] CoreMusicLibrary::Adding element Spotify Feb 10 20:11:40 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 20:11:40 volumio volumio[16762]: Cannot find translation for source YouTube Music Feb 10 20:11:40 volumio volumio[16762]: Cannot find translation for source Spotify Feb 10 20:11:41 volumio volumio[16762]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 10 20:11:41 volumio volumio[16762]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 20:11:41 volumio volumio[16762]: info: VolumeController:: Volume=100 Mute =false Feb 10 20:11:41 volumio volumio[16762]: info: CoreCommandRouter::volumioGetState Feb 10 20:11:41 volumio volumio[16762]: info: CorePlayQueue::getTrack 0 Feb 10 20:11:41 volumio volumio[16762]: info: CoreStateMachine::pushState Feb 10 20:11:41 volumio volumio[16762]: info: CorePlayQueue::getTrack 0 Feb 10 20:11:41 volumio volumio[16762]: info: CoreCommandRouter::volumioPushState Feb 10 20:11:42 volumio volumio[16762]: info: go-librespot daemon successfully initialized Feb 10 20:11:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Feb 10 20:11:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:11:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:11:42 volumio go-librespot[17071]: go-librespot daemon starting... Feb 10 20:11:42 volumio go-librespot[17072]: time="2026-02-10T20:11:42+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 20:11:42 volumio go-librespot[17072]: time="2026-02-10T20:11:42+07:00" level=debug msg="app state loaded" Feb 10 20:11:42 volumio go-librespot[17072]: time="2026-02-10T20:11:42+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 20:11:42 volumio mpd[16983]: 2026-02-10T20:11:42 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 10 20:11:42 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 10 20:11:42 volumio sudo[16937]: pam_unix(sudo:session): session closed for user root Feb 10 20:11:42 volumio sudo[16953]: pam_unix(sudo:session): session closed for user root Feb 10 20:11:42 volumio go-librespot[17072]: time="2026-02-10T20:11: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 20:11:42 volumio go-librespot[17072]: time="2026-02-10T20:11:42+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 10 20:11:42 volumio go-librespot[17072]: time="2026-02-10T20:11:42+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 10 20:11:43 volumio go-librespot[17072]: time="2026-02-10T20:11:43+07:00" level=info msg="zeroconf server listening on port 43209" Feb 10 20:11:43 volumio volumio[16762]: error: MPD error: The expression evaluated to a falsy value: Feb 10 20:11:43 volumio volumio[16762]: assert.ok(self.idling) Feb 10 20:11:43 volumio volumio[16762]: error: The expression evaluated to a falsy value: Feb 10 20:11:43 volumio volumio[16762]: assert.ok(self.idling) Feb 10 20:11:43 volumio volumio[16762]: error: updateQueue error: null Feb 10 20:11:43 volumio volumio[16762]: info: MPD running with PID16983 Feb 10 20:11:43 volumio volumio[16762]: ,establishing connection Feb 10 20:11:43 volumio go-librespot[17072]: time="2026-02-10T20:11:43+07:00" level=debug msg="obtained new client token: AADnQe9p7b0cN9AJKzM96GPzzkgfC9307idn0mvnGd8LEeWcsWtY/MHWO8lW6c01aVYVVebcEPbdU761OwXa7VyeAb6r2d5RzHlFlv9wRT1MyQZOOQYJ2TcDPLPHqhXzLk67pnSzJddFeov0fup6aEPqxMzlL2JW6Fu60EzgM6wnawmEzqmCvgDxB9VfB56lJCKomMbb9sYVu8MRaOmK5lPQKSGbPQ6iKQn88u+E4wVVhoCEwKL8uzc=" Feb 10 20:11:43 volumio volumio[16762]: info: Completed starting Core Plugins Feb 10 20:11:43 volumio volumio[16762]: info: ------------------------------------------- Feb 10 20:11:43 volumio volumio[16762]: info: ----- MyVolumio plugins startup ---- Feb 10 20:11:43 volumio volumio[16762]: info: ------------------------------------------- Feb 10 20:11:43 volumio volumio[16762]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 10 20:11:43 volumio volumio[16762]: error: updateQueue error: null Feb 10 20:11:43 volumio go-librespot[17072]: time="2026-02-10T20:11:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 20:11:43 volumio go-librespot[17072]: time="2026-02-10T20:11:43+07:00" level=debug msg="completed keyexchange" Feb 10 20:11:43 volumio go-librespot[17072]: time="2026-02-10T20:11:43+07:00" level=debug msg="completed challenge" Feb 10 20:11:43 volumio go-librespot[17072]: time="2026-02-10T20:11:43+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 10 20:11:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 20:11:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 20:11:45 volumio volumio[16762]: info: Initializing connection to go-librespot Websocket Feb 10 20:11:45 volumio volumio[16762]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 20:11:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Feb 10 20:11:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:11:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:11:46 volumio go-librespot[17083]: go-librespot daemon starting... Feb 10 20:11:46 volumio go-librespot[17084]: time="2026-02-10T20:11:46+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 20:11:46 volumio go-librespot[17084]: time="2026-02-10T20:11:46+07:00" level=debug msg="app state loaded" Feb 10 20:11:46 volumio go-librespot[17084]: time="2026-02-10T20:11:46+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 20:11:47 volumio go-librespot[17084]: time="2026-02-10T20:11:47+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 10 20:11:47 volumio go-librespot[17084]: time="2026-02-10T20:11:47+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 10 20:11:47 volumio go-librespot[17084]: time="2026-02-10T20:11:47+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 10 20:11:47 volumio go-librespot[17084]: time="2026-02-10T20:11:47+07:00" level=info msg="zeroconf server listening on port 45757" Feb 10 20:11:47 volumio go-librespot[17084]: time="2026-02-10T20:11:47+07:00" level=debug msg="obtained new client token: AACuBva/4bFh30vw8OQCU//8Dcj26ytnWFA65wa1ay/p12fD8g8/cFvMbH4h2lmw1kPRBSJLvR2tavEHQ/sxZmSu4pxkB62M7bHNXhC2Tu5WHGpDRMoAvMBMtgquFT9Kc2bIHF+BEmkhvLb/H1v2brwrXKi9Thzdm4yA5kYR+7mhEv49E74EvLH/S0upyKKgE5lfim9/vTzXiNJ3KQzJao84w96BLunXoqBJORJIzoEdr3yBeUeQx0hFWg==" Feb 10 20:11:47 volumio go-librespot[17084]: time="2026-02-10T20:11:47+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 20:11:47 volumio go-librespot[17084]: time="2026-02-10T20:11:47+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 10 20:11:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 20:11:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 20:11:48 volumio volumio[16762]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 10 20:11:48 volumio volumio[16762]: info: Initializing connection to go-librespot Websocket Feb 10 20:11:48 volumio volumio[16762]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 20:11:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Feb 10 20:11:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:11:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:11:50 volumio go-librespot[17092]: go-librespot daemon starting... Feb 10 20:11:50 volumio go-librespot[17093]: time="2026-02-10T20:11:50+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 20:11:50 volumio go-librespot[17093]: time="2026-02-10T20:11:50+07:00" level=debug msg="app state loaded" Feb 10 20:11:50 volumio go-librespot[17093]: time="2026-02-10T20:11:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 20:11:51 volumio volumio[16762]: info: Initializing connection to go-librespot Websocket Feb 10 20:11:51 volumio go-librespot[17093]: time="2026-02-10T20:11:51+07:00" level=debug msg="new websocket client" Feb 10 20:11:51 volumio volumio[16762]: info: Connection to go-librespot Websocket established Feb 10 20:11:51 volumio go-librespot[17093]: time="2026-02-10T20:11:51+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 20:11:51 volumio go-librespot[17093]: time="2026-02-10T20:11:51+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 10 20:11:51 volumio go-librespot[17093]: time="2026-02-10T20:11:51+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 10 20:11:51 volumio go-librespot[17093]: time="2026-02-10T20:11:51+07:00" level=info msg="zeroconf server listening on port 43901" Feb 10 20:11:51 volumio go-librespot[17093]: time="2026-02-10T20:11:51+07:00" level=debug msg="obtained new client token: AAD/YWe1SWvYiwJXiyRdXsieaTnd6PfQcY4CSUUP1iSnIUfD/RJVe1sF+pGpOh/6+qdTjEkz9750Ia2/XErdVJ1Ix5d7FmXKiQRqWM2F4QAjOnEkcGn9udG9WvdS6rWPRJt1cKmsn/20fP4YSLXk314fhZpEYgx5z3JDxW14JosTSB/LOQRkpDa/W/3PhvOC9UXqSAOWrs4ucF5aFYkvoAfzUQxNJJqfRXMKmvSgJcAUav1VK4Ubj04LaA==" Feb 10 20:11:51 volumio go-librespot[17093]: time="2026-02-10T20:11:51+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 20:11:51 volumio go-librespot[17093]: time="2026-02-10T20:11: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 10 20:11:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 20:11:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 20:11:51 volumio volumio[16762]: info: Connection to go-librespot Websocket closed Feb 10 20:11:52 volumio volumio[16762]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 10 20:11:52 volumio volumio[16762]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 10 20:11:52 volumio volumio[16762]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 10 20:11:52 volumio volumio[16762]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 10 20:11:52 volumio volumio[16762]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 10 20:11:52 volumio volumio[16762]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 10 20:11:52 volumio volumio[16762]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 10 20:11:52 volumio volumio[16762]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 10 20:11:52 volumio volumio[16762]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 10 20:11:52 volumio volumio[16762]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 10 20:11:52 volumio volumio[16762]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 10 20:11:52 volumio volumio[16762]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 10 20:11:52 volumio volumio[16762]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 10 20:11:52 volumio volumio[16762]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 10 20:11:52 volumio volumio[16762]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 10 20:11:52 volumio volumio[16762]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 10 20:11:52 volumio volumio[16762]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 10 20:11:52 volumio volumio[16762]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 10 20:11:52 volumio volumio[16762]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 10 20:11:52 volumio volumio[16762]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 10 20:11:52 volumio volumio[16762]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 10 20:11:52 volumio volumio[16762]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 10 20:11:52 volumio volumio[16762]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 10 20:11:52 volumio volumio[16762]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 10 20:11:52 volumio volumio[16762]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 10 20:11:52 volumio volumio[16762]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 10 20:11:52 volumio volumio[16762]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 10 20:11:52 volumio volumio[16762]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 10 20:11:52 volumio volumio[16762]: info: Adding plugin bluetooth to MyMusic Plugins Feb 10 20:11:52 volumio volumio[16762]: info: Adding plugin multiroom to MyMusic Plugins Feb 10 20:11:52 volumio volumio[16762]: info: Adding plugin metavolumio to MyMusic Plugins Feb 10 20:11:52 volumio volumio[16762]: info: Adding plugin cd_controller to MyMusic Plugins Feb 10 20:11:52 volumio volumio[16762]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 10 20:11:52 volumio volumio[16762]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 10 20:11:52 volumio volumio[16762]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 10 20:11:52 volumio volumio[16762]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 10 20:11:53 volumio volumio[16762]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 10 20:11:53 volumio volumio[16762]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 10 20:11:53 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 20:11:53 volumio volumio[16762]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 20:11:53 volumio volumio[16762]: info: Starting MyVolumio Remote Streaming Endpoints Feb 10 20:11:53 volumio volumio[16762]: info: MyVolumio login type: Token Feb 10 20:11:54 volumio volumio[16762]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 10 20:11:54 volumio volumio[16762]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 10 20:11:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Feb 10 20:11:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:11:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 20:11:55 volumio go-librespot[17114]: go-librespot daemon starting... Feb 10 20:11:55 volumio go-librespot[17115]: time="2026-02-10T20:11:55+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 20:11:55 volumio go-librespot[17115]: time="2026-02-10T20:11:55+07:00" level=debug msg="app state loaded" Feb 10 20:11:55 volumio go-librespot[17115]: time="2026-02-10T20:11:55+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 20:11:55 volumio go-librespot[17115]: time="2026-02-10T20:11:55+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 20:11:55 volumio go-librespot[17115]: time="2026-02-10T20:11:55+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 10 20:11:55 volumio go-librespot[17115]: time="2026-02-10T20:11:55+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 10 20:11:55 volumio go-librespot[17115]: time="2026-02-10T20:11:55+07:00" level=info msg="zeroconf server listening on port 35625" Feb 10 20:11:55 volumio volumio[16762]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 10 20:11:55 volumio volumio[16762]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 10 20:11:55 volumio volumio[16762]: info: Streaming services startup Feb 10 20:11:55 volumio volumio[16762]: info: Starting Streaming Daemon Feb 10 20:11:55 volumio sudo[17124]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 10 20:11:55 volumio sudo[17124]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 20:11:55 volumio volumio[16762]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 10 20:11:55 volumio sudo[17124]: pam_unix(sudo:session): session closed for user root Feb 10 20:11:56 volumio go-librespot[17115]: time="2026-02-10T20:11:56+07:00" level=debug msg="obtained new client token: AABxckocX2SVSQdI+gGYww9Ceh9LcNylxOsO3mdGTzyEMl+JfQnJITfNfwSbTr79JcLKJsgrm3DO8IK03xKFS/AOdgW+BdienWExf6cLxsZhpI/jLspSec11wnPVwhY6Fj7DqtqD/FUdioN7IzldRnIdQoeM8rCRNgwUaDFmUmoe901pigNl+wfqZN/tcJqF1FYSoReobI5lpkWTbUk0TvNuz3E85R2KXD0dxwb1Lbt/iJs7r27w/ITLcw==" Feb 10 20:11:56 volumio volumio[16762]: info: Getting Spotify volume Feb 10 20:11:56 volumio volumio[16762]: info: Initializing connection to go-librespot Websocket Feb 10 20:11:56 volumio volumio[16762]: error: Cannot start Volumio Streaming Daemon Feb 10 20:11:56 volumio volumio[16762]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 10 20:11:56 volumio volumio[16762]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 10 20:11:56 volumio go-librespot[17115]: time="2026-02-10T20:11:56+07:00" level=debug msg="new websocket client" Feb 10 20:11:56 volumio go-librespot[17115]: time="2026-02-10T20:11:56+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 10 20:11:56 volumio volumio[16762]: 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 10 20:11:56 volumio volumio[16762]: info: Connection to go-librespot Websocket established Feb 10 20:11:56 volumio go-librespot[17115]: time="2026-02-10T20:11:56+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 10 20:11:56 volumio go-librespot[17115]: time="2026-02-10T20:11:56+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:51594->104.199.241.202:443: read: connection reset by peer" Feb 10 20:11:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 20:11:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 20:11:56 volumio volumio[16762]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 20:11:56 volumio volumio[16762]: Error: socket hang up Feb 10 20:11:56 volumio volumio[16762]: at connResetException (node:internal/errors:720:14) Feb 10 20:11:56 volumio volumio[16762]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 10 20:11:56 volumio volumio[16762]: at Socket.emit (node:events:526:35) Feb 10 20:11:56 volumio volumio[16762]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 10 20:11:56 volumio volumio[16762]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 10 20:11:56 volumio volumio[16762]: code: 'ECONNRESET', Feb 10 20:11:56 volumio volumio[16762]: response: undefined Feb 10 20:11:56 volumio volumio[16762]: } Feb 10 20:11:56 volumio volumio[16762]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 20:11:57 volumio sudo[17144]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-10 20:10' Feb 10 20:11:57 volumio sudo[17144]: 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"