Feb 12 14:27:00 volumio volumio[4376]: info: MPD Permissions set Feb 12 14:27:00 volumio volumio[4376]: info: MPD Permissions set Feb 12 14:27:00 volumio volumio[4376]: info: Upmpdcli Daemon Started Feb 12 14:27:00 volumio volumio[4503]: Starting albumart workers Feb 12 14:27:00 volumio volumio[4376]: info: Volumio called home Feb 12 14:27:00 volumio volumio[4376]: info: Spotify config file written Feb 12 14:27:00 volumio volumio[4501]: Starting albumart workers Feb 12 14:27:00 volumio sudo[4603]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 12 14:27:00 volumio sudo[4603]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 14:27:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:27:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:27:00 volumio go-librespot[4605]: go-librespot daemon starting... Feb 12 14:27:00 volumio sudo[4603]: pam_unix(sudo:session): session closed for user root Feb 12 14:27:00 volumio go-librespot[4609]: time="2026-02-12T14:27:00+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 14:27:00 volumio go-librespot[4609]: time="2026-02-12T14:27:00+07:00" level=debug msg="app state loaded" Feb 12 14:27:00 volumio go-librespot[4609]: time="2026-02-12T14:27:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 14:27:00 volumio volumio[4376]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 12 14:27:00 volumio volumio[4376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:00 volumio volumio[4376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:00 volumio volumio[4376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:00 volumio volumio[4376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:00 volumio volumio[4376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:00 volumio volumio[4376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:00 volumio volumio[4376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:00 volumio volumio[4376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:00 volumio volumio[4376]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 14:27:00 volumio volumio[4376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:00 volumio volumio[4376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:00 volumio volumio[4376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:00 volumio volumio[4376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:01 volumio volumio[4376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:01 volumio volumio[4376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:01 volumio volumio[4376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:01 volumio volumio[4376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:01 volumio volumio[4376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:01 volumio volumio[4376]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 14:27:01 volumio volumio[4376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:01 volumio volumio[4376]: info: No need to fix Spotify hosts Feb 12 14:27:01 volumio go-librespot[4609]: time="2026-02-12T14:27: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 12 14:27:01 volumio go-librespot[4609]: time="2026-02-12T14:27: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 12 14:27:01 volumio go-librespot[4609]: time="2026-02-12T14:27: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 12 14:27:01 volumio go-librespot[4609]: time="2026-02-12T14:27:01+07:00" level=info msg="zeroconf server listening on port 36029" Feb 12 14:27:01 volumio go-librespot[4609]: time="2026-02-12T14:27:01+07:00" level=debug msg="obtained new client token: AAAWKwUi5V3ayZD3w4Cc71NFcID2ZzRExJ/MMqmMjCuP2A+IDIpTThKMIpkZCWHlhG4Cofmmg8jX4zwIb+qDQEv4/XDwqDS/5u9Y+tEesgYcv+M+oJHee+oM9zTxuOelYySWfh1Wx5iTCxt1WTDTlALh336n+qxFKhOFe2F53PF1gxxcIJ8xKszzexbVAuZJ9jRJNlOKNcgT7gqjxWm6i+UQRIVZKcRxsGP/wqWIR3Ag+4IRlBBjRgeDIg==" Feb 12 14:27:01 volumio go-librespot[4609]: time="2026-02-12T14:27:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 14:27:01 volumio go-librespot[4609]: time="2026-02-12T14:27:01+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 12 14:27:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 14:27:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 14:27:02 volumio volumio[4376]: info: Starting Shairport Sync Feb 12 14:27:02 volumio volumio[4376]: info: Starting Shairport Sync Feb 12 14:27:02 volumio volumio[4376]: info: Starting Shairport Sync Feb 12 14:27:02 volumio sudo[4640]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 14:27:02 volumio sudo[4640]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 14:27:02 volumio volumio[4376]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 14:27:02 volumio volumio[4376]: SPOTIFY: BQAAYjal7xEjM3qMFhAP03LFHYUCn3MWGiPDUlyBwO4lSAUkCab0JTBAKCSSfI7jRObQMD5bzufH9yVjy6M-1ROLxPQWYrfj3iqdvr3p7V8TfF2nBjk0R6h9tCMn35bzLkchV_sudSA1GXdJNbYuOcRIisXWWaMtN-rkR116tr0NOGk0xX8ez1O0A2WhLrqq1zfjBlIoabNYQijvahouWKx2KA6k3s8gPYjSJbQndQvu_czGUay01VkNv1yXbLZBvFSz-kKfnmD9HCoEQGLSVYThefs8flXzsQhFNSRyGwTf-jVfo8rBFi3N Feb 12 14:27:02 volumio volumio[4376]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 14:27:02 volumio volumio[4376]: info: New Spotify access token = BQAAYjal7xEjM3qMFhAP03LFHYUCn3MWGiPDUlyBwO4lSAUkCab0JTBAKCSSfI7jRObQMD5bzufH9yVjy6M-1ROLxPQWYrfj3iqdvr3p7V8TfF2nBjk0R6h9tCMn35bzLkchV_sudSA1GXdJNbYuOcRIisXWWaMtN-rkR116tr0NOGk0xX8ez1O0A2WhLrqq1zfjBlIoabNYQijvahouWKx2KA6k3s8gPYjSJbQndQvu_czGUay01VkNv1yXbLZBvFSz-kKfnmD9HCoEQGLSVYThefs8flXzsQhFNSRyGwTf-jVfo8rBFi3N Feb 12 14:27:02 volumio sudo[4642]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 14:27:02 volumio volumio[4376]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 12 14:27:02 volumio sudo[4642]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 14:27:02 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 12 14:27:02 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 12 14:27:02 volumio sudo[4645]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 14:27:02 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 14:27:02 volumio systemd[1]: shairport-sync.service: Consumed 2.423s CPU time. Feb 12 14:27:02 volumio sudo[4645]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 14:27:02 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 14:27:02 volumio sudo[4640]: pam_unix(sudo:session): session closed for user root Feb 12 14:27:02 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 12 14:27:02 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 12 14:27:02 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 14:27:02 volumio volumio[4376]: info: Shairport-Sync Started Feb 12 14:27:02 volumio volumio[4376]: Error adding Membership: Error: addMembership EINVAL Feb 12 14:27:02 volumio volumio[4376]: info: CoreCommandRouter::volumioGetState Feb 12 14:27:02 volumio volumio[4376]: info: CorePlayQueue::getTrack 0 Feb 12 14:27:02 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 14:27:02 volumio sudo[4642]: pam_unix(sudo:session): session closed for user root Feb 12 14:27:02 volumio sudo[4645]: pam_unix(sudo:session): session closed for user root Feb 12 14:27:02 volumio volumio[4376]: info: Shairport-Sync Started Feb 12 14:27:02 volumio volumio[4376]: info: Shairport-Sync Started Feb 12 14:27:03 volumio volumio[4376]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 12 14:27:03 volumio volumio[4376]: info: Spotify Successfully logged in Feb 12 14:27:03 volumio volumio[4376]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 14:27:03 volumio volumio[4376]: info: [1770881223123] CoreMusicLibrary::Adding element Spotify Feb 12 14:27:03 volumio volumio[4376]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 14:27:03 volumio volumio[4376]: Cannot find translation for source YouTube Music Feb 12 14:27:03 volumio volumio[4376]: Cannot find translation for source Spotify Feb 12 14:27:04 volumio volumio[4376]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 12 14:27:04 volumio volumio[4376]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 14:27:04 volumio volumio[4376]: info: VolumeController:: Volume=100 Mute =false Feb 12 14:27:04 volumio volumio[4376]: info: CoreCommandRouter::volumioGetState Feb 12 14:27:04 volumio volumio[4376]: info: CorePlayQueue::getTrack 0 Feb 12 14:27:04 volumio volumio[4376]: info: CoreStateMachine::pushState Feb 12 14:27:04 volumio volumio[4376]: info: CorePlayQueue::getTrack 0 Feb 12 14:27:04 volumio volumio[4376]: info: CoreCommandRouter::volumioPushState Feb 12 14:27:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Feb 12 14:27:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:27:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:27:04 volumio go-librespot[4687]: go-librespot daemon starting... Feb 12 14:27:04 volumio go-librespot[4688]: time="2026-02-12T14:27:04+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 14:27:04 volumio go-librespot[4688]: time="2026-02-12T14:27:04+07:00" level=debug msg="app state loaded" Feb 12 14:27:04 volumio go-librespot[4688]: time="2026-02-12T14:27:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 14:27:05 volumio volumio[4376]: info: go-librespot daemon successfully initialized Feb 12 14:27:05 volumio mpd[4595]: 2026-02-12T14:27:05 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 12 14:27:05 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 12 14:27:05 volumio sudo[4546]: pam_unix(sudo:session): session closed for user root Feb 12 14:27:05 volumio sudo[4557]: pam_unix(sudo:session): session closed for user root Feb 12 14:27:05 volumio go-librespot[4688]: time="2026-02-12T14:27: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 14:27:05 volumio go-librespot[4688]: time="2026-02-12T14:27:05+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 14:27:05 volumio go-librespot[4688]: time="2026-02-12T14:27:05+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 14:27:05 volumio go-librespot[4688]: time="2026-02-12T14:27:05+07:00" level=info msg="zeroconf server listening on port 41655" Feb 12 14:27:05 volumio volumio[4376]: error: MPD error: The expression evaluated to a falsy value: Feb 12 14:27:05 volumio volumio[4376]: assert.ok(self.idling) Feb 12 14:27:05 volumio volumio[4376]: error: The expression evaluated to a falsy value: Feb 12 14:27:05 volumio volumio[4376]: assert.ok(self.idling) Feb 12 14:27:05 volumio volumio[4376]: error: updateQueue error: null Feb 12 14:27:05 volumio volumio[4376]: info: MPD running with PID4595 Feb 12 14:27:05 volumio volumio[4376]: ,establishing connection Feb 12 14:27:05 volumio go-librespot[4688]: time="2026-02-12T14:27:05+07:00" level=debug msg="obtained new client token: AACpu/t4QgrFMDt683Tw+QkKjWuwP5RQI2qs9CP14ZKDcjjly1GrpoWvc2nT7K8ndibBLZwuy8kaTalTvhYasAv4Z7gDwi0cZ7W3lSB83UaJCsSoQTEXusks+jjIu0XPl6KFM8MqjBZv8LbhXMLuANYx7PGSmfS6inPsBf/OxmN9ZGdlUYZZDDoCK8URkoSeZ5xp4i4dHd8DN2hzOwBRFcmX+4s+hiwdxxhqTrDnnkzU5nxT0XPTemKh5Q==" Feb 12 14:27:05 volumio volumio[4376]: info: Completed starting Core Plugins Feb 12 14:27:05 volumio volumio[4376]: info: ------------------------------------------- Feb 12 14:27:05 volumio volumio[4376]: info: ----- MyVolumio plugins startup ---- Feb 12 14:27:05 volumio volumio[4376]: info: ------------------------------------------- Feb 12 14:27:05 volumio volumio[4376]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 12 14:27:05 volumio volumio[4376]: error: updateQueue error: null Feb 12 14:27:05 volumio go-librespot[4688]: time="2026-02-12T14:27:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 14:27:05 volumio go-librespot[4688]: time="2026-02-12T14:27:05+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 12 14:27:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 14:27:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 14:27:08 volumio volumio[4376]: info: Initializing connection to go-librespot Websocket Feb 12 14:27:08 volumio volumio[4376]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 14:27:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Feb 12 14:27:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:27:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:27:09 volumio go-librespot[4701]: go-librespot daemon starting... Feb 12 14:27:09 volumio go-librespot[4702]: time="2026-02-12T14:27:09+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 14:27:09 volumio go-librespot[4702]: time="2026-02-12T14:27:09+07:00" level=debug msg="app state loaded" Feb 12 14:27:09 volumio go-librespot[4702]: time="2026-02-12T14:27:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 14:27:09 volumio go-librespot[4702]: time="2026-02-12T14:27:09+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 12 14:27:09 volumio go-librespot[4702]: time="2026-02-12T14:27:09+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 12 14:27:09 volumio go-librespot[4702]: time="2026-02-12T14:27:09+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 12 14:27:09 volumio go-librespot[4702]: time="2026-02-12T14:27:09+07:00" level=info msg="zeroconf server listening on port 34207" Feb 12 14:27:09 volumio go-librespot[4702]: time="2026-02-12T14:27:09+07:00" level=debug msg="obtained new client token: AAB86mFyH+vas46zVTrkxTqkAjXpJsO20awME7wAQbaq1GIHmcjMfb2ZYA6ozaXMStKeLJJGOi5UZ9FbniOPwRqJGG1sibfmA1EDSBlp1i4wa/BL7cZkNzU3WaZrIFTIqh2HLzoyxcNT0j2FKoGsbtml4brJhLcZTa0LIgyedhqImxoOEX1dOA+/ctA8qJ6EP4W8U4plLjtrLcJfy0efATMoBEsBuRYXd1GPsA9JdeYSHldw4XOfAsRFSQ==" Feb 12 14:27:10 volumio go-librespot[4702]: time="2026-02-12T14:27:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 14:27:10 volumio go-librespot[4702]: time="2026-02-12T14:27:10+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 12 14:27:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 14:27:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 14:27:10 volumio volumio[4376]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 12 14:27:11 volumio volumio[4376]: info: Initializing connection to go-librespot Websocket Feb 12 14:27:11 volumio volumio[4376]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 14:27:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Feb 12 14:27:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:27:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:27:13 volumio go-librespot[4709]: go-librespot daemon starting... Feb 12 14:27:13 volumio go-librespot[4710]: time="2026-02-12T14:27:13+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 14:27:13 volumio go-librespot[4710]: time="2026-02-12T14:27:13+07:00" level=debug msg="app state loaded" Feb 12 14:27:13 volumio go-librespot[4710]: time="2026-02-12T14:27:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 14:27:13 volumio go-librespot[4710]: time="2026-02-12T14:27: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 12 14:27:13 volumio go-librespot[4710]: time="2026-02-12T14:27: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 12 14:27:13 volumio go-librespot[4710]: time="2026-02-12T14:27: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 12 14:27:13 volumio go-librespot[4710]: time="2026-02-12T14:27:13+07:00" level=info msg="zeroconf server listening on port 42403" Feb 12 14:27:14 volumio volumio[4376]: info: Initializing connection to go-librespot Websocket Feb 12 14:27:14 volumio go-librespot[4710]: time="2026-02-12T14:27:14+07:00" level=debug msg="new websocket client" Feb 12 14:27:14 volumio volumio[4376]: info: Connection to go-librespot Websocket established Feb 12 14:27:14 volumio go-librespot[4710]: time="2026-02-12T14:27:14+07:00" level=debug msg="obtained new client token: AABzUedzp/Joy8wTOwD4E5s4AoEYVdaPNa4f0mQ3i0sr+epBEREyjebX9p49Xl0bF0igm6Wz0TkYrtHkU7rKroi4WxclZVlBkE0qeY4AgummCz3IRXU91HYBGJKfXmeEHFVCTOCGHFiJhvJ9XdxItSDsOzEuamH4YlwMQcHW5FqE/5v+pWs8A8/Ru+S1cQADnkLCTjpNbnEaAMOZYv6XIZ7WvBU9XEQlSt1bllxOrG06qM81a9DPPtM=" Feb 12 14:27:14 volumio go-librespot[4710]: time="2026-02-12T14:27:14+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 12 14:27:14 volumio go-librespot[4710]: time="2026-02-12T14:27:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 12 14:27:14 volumio volumio[4376]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 12 14:27:14 volumio volumio[4376]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 12 14:27:14 volumio volumio[4376]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 12 14:27:14 volumio volumio[4376]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 12 14:27:14 volumio volumio[4376]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 12 14:27:14 volumio volumio[4376]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 12 14:27:14 volumio volumio[4376]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 12 14:27:14 volumio volumio[4376]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 12 14:27:14 volumio volumio[4376]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 12 14:27:14 volumio volumio[4376]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 12 14:27:14 volumio volumio[4376]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 12 14:27:14 volumio volumio[4376]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 12 14:27:14 volumio volumio[4376]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 12 14:27:14 volumio volumio[4376]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 12 14:27:14 volumio volumio[4376]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 12 14:27:14 volumio volumio[4376]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 12 14:27:14 volumio volumio[4376]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 12 14:27:14 volumio volumio[4376]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 12 14:27:14 volumio volumio[4376]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 12 14:27:14 volumio volumio[4376]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 12 14:27:14 volumio volumio[4376]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 12 14:27:14 volumio volumio[4376]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 12 14:27:14 volumio volumio[4376]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 12 14:27:14 volumio volumio[4376]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 12 14:27:14 volumio volumio[4376]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 12 14:27:14 volumio volumio[4376]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 12 14:27:14 volumio volumio[4376]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 12 14:27:14 volumio volumio[4376]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 12 14:27:14 volumio volumio[4376]: info: Adding plugin bluetooth to MyMusic Plugins Feb 12 14:27:14 volumio volumio[4376]: info: Adding plugin multiroom to MyMusic Plugins Feb 12 14:27:14 volumio volumio[4376]: info: Adding plugin metavolumio to MyMusic Plugins Feb 12 14:27:14 volumio volumio[4376]: info: Adding plugin cd_controller to MyMusic Plugins Feb 12 14:27:14 volumio volumio[4376]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 12 14:27:14 volumio volumio[4376]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 12 14:27:14 volumio go-librespot[4710]: time="2026-02-12T14:27: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 12 14:27:14 volumio volumio[4376]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 12 14:27:14 volumio volumio[4376]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 12 14:27:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 14:27:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 14:27:16 volumio volumio[4376]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 12 14:27:16 volumio volumio[4376]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 12 14:27:16 volumio volumio[4376]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 14:27:16 volumio volumio[4376]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 14:27:16 volumio volumio[4376]: info: Starting MyVolumio Remote Streaming Endpoints Feb 12 14:27:16 volumio volumio[4376]: info: MyVolumio login type: Token Feb 12 14:27:16 volumio volumio[4376]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 12 14:27:16 volumio volumio[4376]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 12 14:27:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Feb 12 14:27:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:27:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:27:17 volumio go-librespot[4732]: go-librespot daemon starting... Feb 12 14:27:17 volumio go-librespot[4733]: time="2026-02-12T14:27:17+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 14:27:17 volumio go-librespot[4733]: time="2026-02-12T14:27:17+07:00" level=debug msg="app state loaded" Feb 12 14:27:17 volumio go-librespot[4733]: time="2026-02-12T14:27:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 14:27:18 volumio go-librespot[4733]: time="2026-02-12T14:27: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 12 14:27:18 volumio go-librespot[4733]: time="2026-02-12T14:27: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 12 14:27:18 volumio go-librespot[4733]: time="2026-02-12T14:27: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 12 14:27:18 volumio volumio[4376]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 12 14:27:18 volumio volumio[4376]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 12 14:27:18 volumio volumio[4376]: info: Streaming services startup Feb 12 14:27:18 volumio volumio[4376]: info: Starting Streaming Daemon Feb 12 14:27:18 volumio go-librespot[4733]: time="2026-02-12T14:27:18+07:00" level=info msg="zeroconf server listening on port 35499" Feb 12 14:27:18 volumio sudo[4742]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 12 14:27:18 volumio volumio[4376]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 12 14:27:18 volumio sudo[4742]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 14:27:18 volumio sudo[4742]: pam_unix(sudo:session): session closed for user root Feb 12 14:27:18 volumio volumio[4376]: info: Getting Spotify volume Feb 12 14:27:18 volumio go-librespot[4733]: time="2026-02-12T14:27:18+07:00" level=debug msg="obtained new client token: AAAaIckmBRN35lEPB05Ef3ZYW00QXHCwj+NuZy2XBWNOQVPZOE2wGfUSguLr+i5MCn2k/K+bnCyQOXRLHQ2rPY8JT1dBp5DlS1XikqneJ+cAeRJ0z79dKvA065syH+N9zEYgX5bN5r8NQD+gZ9fmbgcs5LxY03FP8iLNphn9IiKcQXwSamdroSfGhxo5HXIS1seK1NTdoooLgGr1cNuGLoI5mJiL3vlN7MfTFvVdLfwl1QU1LLgtHTdBDw==" Feb 12 14:27:18 volumio volumio[4376]: info: Connection to go-librespot Websocket closed Feb 12 14:27:18 volumio volumio[4376]: error: Cannot start Volumio Streaming Daemon Feb 12 14:27:18 volumio volumio[4376]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 12 14:27:18 volumio volumio[4376]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 12 14:27:18 volumio volumio[4376]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 12 14:27:18 volumio go-librespot[4733]: time="2026-02-12T14:27:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 14:27:18 volumio go-librespot[4733]: time="2026-02-12T14:27:18+07:00" level=debug msg="completed keyexchange" Feb 12 14:27:18 volumio go-librespot[4733]: time="2026-02-12T14:27:18+07:00" level=debug msg="completed challenge" Feb 12 14:27:18 volumio volumio[4376]: info: CoreCommandRouter::volumioGetState Feb 12 14:27:18 volumio volumio[4376]: info: CorePlayQueue::getTrack 0 Feb 12 14:27:18 volumio volumio[4376]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 12 14:27:18 volumio volumio[4376]: SPOTIFY: SPOTIFY VOLUME undefined Feb 12 14:27:18 volumio volumio[4376]: SPOTIFY: VOLUMIO VOLUME 100 Feb 12 14:27:18 volumio volumio[4376]: info: Aligning Spotify Volume to Volumio Volume Feb 12 14:27:18 volumio volumio[4376]: info: CoreCommandRouter::volumioGetState Feb 12 14:27:18 volumio volumio[4376]: info: CorePlayQueue::getTrack 0 Feb 12 14:27:18 volumio volumio[4376]: info: Setting Spotify Volume from Volumio: 100 Feb 12 14:27:18 volumio go-librespot[4733]: time="2026-02-12T14:27: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 12 14:27:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 14:27:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 14:27:18 volumio volumio[4376]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 14:27:18 volumio volumio[4376]: Error: socket hang up Feb 12 14:27:18 volumio volumio[4376]: at connResetException (node:internal/errors:720:14) Feb 12 14:27:18 volumio volumio[4376]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 12 14:27:18 volumio volumio[4376]: at Socket.emit (node:events:526:35) Feb 12 14:27:18 volumio volumio[4376]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 12 14:27:18 volumio volumio[4376]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 12 14:27:18 volumio volumio[4376]: code: 'ECONNRESET', Feb 12 14:27:18 volumio volumio[4376]: response: undefined Feb 12 14:27:18 volumio volumio[4376]: } Feb 12 14:27:18 volumio volumio[4376]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 14:27:20 volumio sudo[4762]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-12 14:26' Feb 12 14:27:20 volumio sudo[4762]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 14:27:20 volumio sudo[4762]: pam_unix(sudo:session): session closed for user root Feb 12 14:27:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Feb 12 14:27:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:27:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:27:21 volumio go-librespot[4770]: go-librespot daemon starting... Feb 12 14:27:21 volumio go-librespot[4771]: time="2026-02-12T14:27:21+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 14:27:21 volumio go-librespot[4771]: time="2026-02-12T14:27:21+07:00" level=debug msg="app state loaded" Feb 12 14:27:21 volumio go-librespot[4771]: time="2026-02-12T14:27:21+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 14:27:22 volumio volumio-remote-updater[643]: [2026-02-12 14:27:22] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Feb 12 14:27:22 volumio volumio-remote-updater[643]: [2026-02-12 14:27:22] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Feb 12 14:27:22 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 12 14:27:22 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 12 14:27:22 volumio systemd[1]: volumio.service: Consumed 55.825s CPU time. Feb 12 14:27:22 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 12 14:27:22 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 12 14:27:22 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 13294. Feb 12 14:27:22 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 12 14:27:22 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 12 14:27:22 volumio systemd[1]: volumio.service: Consumed 55.825s CPU time. Feb 12 14:27:22 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 12 14:27:22 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 12 14:27:22 volumio go-librespot[4771]: time="2026-02-12T14:27: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-gew4.spotify.com:80]" Feb 12 14:27:22 volumio go-librespot[4771]: time="2026-02-12T14:27:22+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 14:27:22 volumio go-librespot[4771]: time="2026-02-12T14:27:22+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 14:27:22 volumio go-librespot[4771]: time="2026-02-12T14:27:22+07:00" level=info msg="zeroconf server listening on port 39287" Feb 12 14:27:22 volumio go-librespot[4771]: time="2026-02-12T14:27:22+07:00" level=debug msg="obtained new client token: AAC/+PDfd1Ho94ypXN9d9Ak4GtjPTn7NaoqHQmC5Wu7/vWGxTzfPqIVpu2agL5J/rPQp2d0FQbG/vy+NMqPFnQQ4YHejzvTVhMSH0ldYf4BIl92ZualRmXmhFgZWzNalYZMr5O7MXNvciuDaYE2eeYoeTt1Scash9x3Gri38x+5G/QosRVKcGNr5MJPzO42BGXW0uzI2NqOacS20BelKwLNUvTivgyIqX983CGkZRA04DcQDhEtKh7rDLQ==" Feb 12 14:27:22 volumio go-librespot[4771]: time="2026-02-12T14:27:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 14:27:22 volumio go-librespot[4771]: time="2026-02-12T14:27:22+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 12 14:27:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 14:27:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 14:27:25 volumio volumio[4790]: info: ------------------------------------------- Feb 12 14:27:25 volumio volumio[4790]: info: ----- Volumio3 ---- Feb 12 14:27:25 volumio volumio[4790]: info: ------------------------------------------- Feb 12 14:27:25 volumio volumio[4790]: info: ----- System startup ---- Feb 12 14:27:25 volumio volumio[4790]: info: ------------------------------------------- Feb 12 14:27:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Feb 12 14:27:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:27:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:27:26 volumio go-librespot[4811]: go-librespot daemon starting... Feb 12 14:27:26 volumio go-librespot[4812]: time="2026-02-12T14:27:26+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 14:27:26 volumio go-librespot[4812]: time="2026-02-12T14:27:26+07:00" level=debug msg="app state loaded" Feb 12 14:27:26 volumio go-librespot[4812]: time="2026-02-12T14:27:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 14:27:26 volumio go-librespot[4812]: time="2026-02-12T14:27: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 14:27:26 volumio go-librespot[4812]: time="2026-02-12T14:27:26+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 14:27:26 volumio go-librespot[4812]: time="2026-02-12T14:27:26+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 14:27:26 volumio go-librespot[4812]: time="2026-02-12T14:27:26+07:00" level=info msg="zeroconf server listening on port 35165" Feb 12 14:27:27 volumio volumio-remote-updater[643]: [2026-02-12 14:27:27] [connect] Successful connection Feb 12 14:27:27 volumio go-librespot[4812]: time="2026-02-12T14:27:27+07:00" level=debug msg="obtained new client token: AAACJedsD3J5ivnA+DdD/KQcq9weO+Hvdwhcz77zn+J9jD0hAwK/kVLfWXofevx4qGWoSt2WbNnCVd06xGp+okc13Z+iIFW9YAKXoQhYrCShtSkJPqWuT9Be72XbAkVG9Ki9O0BuNdIrR+74uGJFx4PmMjVdV9XD2zDY7+Ra9JgMyswvq4wmZjqM23UnSrkUPpMGMdwAqTV2/u1ga8SMBdtJdC59xYrwbOw8lhqleOeebgbhXtLcHxc=" Feb 12 14:27:27 volumio go-librespot[4812]: time="2026-02-12T14:27:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 14:27:27 volumio volumio[4790]: info: MYVOLUMIO Environment detected Feb 12 14:27:27 volumio go-librespot[4812]: time="2026-02-12T14:27:27+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 12 14:27:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 14:27:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 14:27:27 volumio volumio[4790]: info: Plugin folders cleanup Feb 12 14:27:27 volumio volumio[4790]: info: Scanning into folder /volumio/app/plugins/ Feb 12 14:27:27 volumio volumio[4790]: info: Scanning category audio_interface Feb 12 14:27:27 volumio volumio[4790]: info: Scanning category miscellanea Feb 12 14:27:27 volumio volumio[4790]: info: Scanning category music_service Feb 12 14:27:27 volumio volumio[4790]: info: Scanning category plugins.json Feb 12 14:27:27 volumio volumio[4790]: info: Scanning category system_controller Feb 12 14:27:27 volumio volumio[4790]: info: Scanning category user_interface Feb 12 14:27:27 volumio volumio[4790]: info: Scanning into folder /data/plugins/ Feb 12 14:27:27 volumio volumio[4790]: info: Scanning category music_service Feb 12 14:27:27 volumio volumio[4790]: info: Plugin folders cleanup completed Feb 12 14:27:27 volumio volumio[4790]: info: ------------------------------------------- Feb 12 14:27:27 volumio volumio[4790]: info: ----- Core plugins startup ---- Feb 12 14:27:27 volumio volumio[4790]: info: ------------------------------------------- Feb 12 14:27:27 volumio volumio[4790]: info: Loading plugins from folder /volumio/app/plugins/ Feb 12 14:27:27 volumio volumio[4790]: info: Adding plugin upnp to MyMusic Plugins Feb 12 14:27:27 volumio volumio[4790]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 12 14:27:27 volumio volumio[4790]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 12 14:27:27 volumio volumio[4790]: info: Loading plugins from folder /data/plugins/ Feb 12 14:27:27 volumio volumio[4790]: info: Loading plugin "system"... Feb 12 14:27:27 volumio volumio[4790]: info: Loading plugin "appearance"... Feb 12 14:27:29 volumio volumio[4790]: info: Loading plugin "network"... Feb 12 14:27:29 volumio volumio[4790]: info: Refreshing Cached IP Addresses Feb 12 14:27:29 volumio sudo[4826]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 12 14:27:29 volumio sudo[4826]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 14:27:29 volumio volumio[4790]: info: Loading plugin "services"... Feb 12 14:27:29 volumio sudo[4828]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 12 14:27:29 volumio sudo[4828]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 14:27:29 volumio sudo[4826]: pam_unix(sudo:session): session closed for user root Feb 12 14:27:29 volumio volumio[4790]: info: Loading plugin "alsa_controller"... Feb 12 14:27:29 volumio sudo[4828]: pam_unix(sudo:session): session closed for user root Feb 12 14:27:29 volumio sudo[4835]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 12 14:27:29 volumio sudo[4835]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 14:27:29 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 14:27:29 volumio volumio[4790]: info: Loading plugin "wizard"... Feb 12 14:27:29 volumio volumio[4790]: info: Loading plugin "networkfs"... Feb 12 14:27:29 volumio volumio[4790]: info: Starting Udev Watcher for removable devices Feb 12 14:27:29 volumio volumio[4790]: info: Ignoring mount for partition: boot Feb 12 14:27:29 volumio volumio[4790]: info: Ignoring mount for partition: volumio Feb 12 14:27:29 volumio volumio[4790]: info: Ignoring mount for partition: volumio_data Feb 12 14:27:29 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 14:27:29 volumio volumio[4790]: info: Loading plugin "volumio_command_line_client"... Feb 12 14:27:29 volumio volumio[4790]: info: Loading plugin "upnp"... Feb 12 14:27:29 volumio volumio[4790]: info: [1770881249773] Starting Upmpd Daemon Feb 12 14:27:29 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 14:27:29 volumio volumio[4790]: info: Loading plugin "my_music"... Feb 12 14:27:29 volumio volumio[4790]: info: Loading plugin "mpd"... Feb 12 14:27:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Feb 12 14:27:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:27:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:27:30 volumio go-librespot[4859]: go-librespot daemon starting... Feb 12 14:27:30 volumio go-librespot[4860]: time="2026-02-12T14:27:30+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 14:27:30 volumio go-librespot[4860]: time="2026-02-12T14:27:30+07:00" level=debug msg="app state loaded" Feb 12 14:27:30 volumio go-librespot[4860]: time="2026-02-12T14:27:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 14:27:30 volumio volumio[4790]: info: Loading plugin "upnp_browser"... Feb 12 14:27:30 volumio go-librespot[4860]: time="2026-02-12T14:27: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-gew4.spotify.com:80]" Feb 12 14:27:30 volumio go-librespot[4860]: time="2026-02-12T14:27:30+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 14:27:30 volumio go-librespot[4860]: time="2026-02-12T14:27:30+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 14:27:30 volumio go-librespot[4860]: time="2026-02-12T14:27:30+07:00" level=info msg="zeroconf server listening on port 33687" Feb 12 14:27:31 volumio go-librespot[4860]: time="2026-02-12T14:27:31+07:00" level=debug msg="obtained new client token: AAAw69phopIvKlir20oCxmULH/qTNUYAOszSfj0iGeYkIevQ9h01luACPJ6Bm/m7u1eQWjExV/2nW3FF432npJX5LWRBHKCFmz9P0CxrVO76uPyUKCjtnzXvQtaubTJK4NhEDOrF4jljIXpsz2cpUxTJVKvHrW5UK12KMRHPUh6aXIbb2hhqllYcpkKS4L85dktgpDBXG7Xz+jlYm/I055wxsKmk0gxQgVi554dvteeMFcYmnC5APvzodw==" Feb 12 14:27:31 volumio go-librespot[4860]: time="2026-02-12T14:27:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 14:27:31 volumio go-librespot[4860]: time="2026-02-12T14:27:31+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 12 14:27:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 14:27:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 14:27:32 volumio sudo[4835]: pam_unix(sudo:session): session closed for user root Feb 12 14:27:33 volumio volumio[4790]: info: Starting UPNP Browser Feb 12 14:27:33 volumio volumio[4790]: info: Loading plugin "alarm-clock"... Feb 12 14:27:33 volumio volumio[4790]: info: Loading plugin "airplay_emulation"... Feb 12 14:27:33 volumio volumio[4790]: info: Starting Shairport Sync Feb 12 14:27:33 volumio volumio[4790]: info: Loading plugin "last_100"... Feb 12 14:27:33 volumio volumio[4790]: info: Loading plugin "webradio"... Feb 12 14:27:33 volumio volumio[4790]: info: Loading plugin "i2s_dacs"... Feb 12 14:27:33 volumio volumio[4790]: info: Loading plugin "volumiodiscovery"... Feb 12 14:27:33 volumio volumio[4790]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 12 14:27:33 volumio volumio[4790]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 14:27:33 volumio volumio[4790]: *** WARNING *** For more information see Feb 12 14:27:33 volumio volumio[4790]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 12 14:27:33 volumio volumio[4790]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 14:27:33 volumio volumio[4790]: *** WARNING *** For more information see Feb 12 14:27:33 volumio node[4790]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 12 14:27:33 volumio node[4790]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 14:27:33 volumio node[4790]: *** WARNING *** For more information see Feb 12 14:27:33 volumio node[4790]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 12 14:27:33 volumio node[4790]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 14:27:33 volumio node[4790]: *** WARNING *** For more information see Feb 12 14:27:33 volumio volumio[4790]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 12 14:27:33 volumio volumio[4790]: info: Discovery: Started advertising with name: Volumio Feb 12 14:27:34 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 14:27:34 volumio volumio[4790]: info: Loading plugin "spop"... Feb 12 14:27:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Feb 12 14:27:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:27:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:27:34 volumio go-librespot[4871]: go-librespot daemon starting... Feb 12 14:27:34 volumio go-librespot[4872]: time="2026-02-12T14:27:34+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 14:27:34 volumio go-librespot[4872]: time="2026-02-12T14:27:34+07:00" level=debug msg="app state loaded" Feb 12 14:27:34 volumio go-librespot[4872]: time="2026-02-12T14:27:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 14:27:35 volumio go-librespot[4872]: time="2026-02-12T14:27:35+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 12 14:27:35 volumio go-librespot[4872]: time="2026-02-12T14:27:35+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 12 14:27:35 volumio go-librespot[4872]: time="2026-02-12T14:27:35+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 12 14:27:35 volumio go-librespot[4872]: time="2026-02-12T14:27:35+07:00" level=info msg="zeroconf server listening on port 39419" Feb 12 14:27:35 volumio go-librespot[4872]: time="2026-02-12T14:27:35+07:00" level=debug msg="obtained new client token: AAC6Wm4Cv5l5At94bzPvAvbDPJ5hnYePuFpqIjnrEsx7Ll+aZob51UzQNUCqzEX7IdaoTQ8e8c9tANuJKllTSAdAM6co20aj8gXsZfsYFWaEYwbUqz9cDQiRmJF52+QqhstZNcW83C22XIdfJ+EfFcJrcZaajlgLCPtKRA38LrnvstafIIN/mkaVKwnsKMelVtNJrGD3JBd0xfRtKfgSnrsg4APOy3PJ/uT8y8MYjZjPw88iINQyqqCUZA==" Feb 12 14:27:35 volumio go-librespot[4872]: time="2026-02-12T14:27:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 14:27:35 volumio go-librespot[4872]: time="2026-02-12T14:27:35+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 12 14:27:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 14:27:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 14:27:35 volumio volumio[4790]: info: Loading plugin "ytcr"... Feb 12 14:27:38 volumio volumio[4790]: info: Loading plugin "ytmusic"... Feb 12 14:27:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Feb 12 14:27:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:27:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:27:38 volumio go-librespot[4880]: go-librespot daemon starting... Feb 12 14:27:38 volumio go-librespot[4881]: time="2026-02-12T14:27:38+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 14:27:38 volumio go-librespot[4881]: time="2026-02-12T14:27:38+07:00" level=debug msg="app state loaded" Feb 12 14:27:38 volumio go-librespot[4881]: time="2026-02-12T14:27:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 14:27:39 volumio go-librespot[4881]: time="2026-02-12T14:27:39+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 14:27:39 volumio go-librespot[4881]: time="2026-02-12T14:27:39+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 14:27:39 volumio go-librespot[4881]: time="2026-02-12T14:27:39+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 14:27:39 volumio go-librespot[4881]: time="2026-02-12T14:27:39+07:00" level=info msg="zeroconf server listening on port 45575" Feb 12 14:27:39 volumio volumio-remote-updater[643]: [2026-02-12 14:27:39] [connect] Successful connection Feb 12 14:27:39 volumio volumio[4790]: info: Loading plugin "outputs"... Feb 12 14:27:39 volumio volumio[4790]: info: Loading plugin "albumart"... Feb 12 14:27:39 volumio go-librespot[4881]: time="2026-02-12T14:27:39+07:00" level=debug msg="obtained new client token: AAC4YajRESWaKLOxI2+fLGzWRQT0O7xTSvJLgeZcY5QG3TjZxfE2+65R3ssLfUEuL42eaK1kAHe9ym4YiPkDbzslY+G/q1tnZSepWZJYVyNCBRMcr+CNmvKf1WJSqQN9m4JVjDuARUw8XbG+RlQnqkevmCzeNwetVU368i4lS9Cl7d5lFnsnKGzr61qAzP0MOlRe4EjmHKA5OLZ9jkhpXR8bOrBQc5d8AzI9fGJdK7ScP485kZ0Hugd2NQ==" Feb 12 14:27:39 volumio volumio[4790]: info: Plugin example_plugin is not enabled Feb 12 14:27:39 volumio volumio[4790]: info: Loading plugin "inputs"... Feb 12 14:27:39 volumio volumio[4790]: info: Loading plugin "updater_comm"... Feb 12 14:27:39 volumio go-librespot[4881]: time="2026-02-12T14:27:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 14:27:39 volumio go-librespot[4881]: time="2026-02-12T14:27: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 12 14:27:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 14:27:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 14:27:40 volumio volumio[4790]: info: Plugin mpdemulation is not enabled Feb 12 14:27:40 volumio volumio[4790]: info: Loading plugin "rest_api"... Feb 12 14:27:40 volumio volumio[4790]: info: Loading plugin "websocket"... Feb 12 14:27:40 volumio volumio[4790]: info: Starting Socket.io Server version 1.7.4 Feb 12 14:27:40 volumio volumio[4790]: info: Loading plugin "RoonBridge"... Feb 12 14:27:40 volumio volumio[4790]: info: Applying required configuration parameters for plugin RoonBridge Feb 12 14:27:40 volumio volumio[4790]: info: Loading i18n strings for locale en Feb 12 14:27:40 volumio volumio[4790]: Updating browse sources language Feb 12 14:27:40 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 14:27:40 volumio volumio[4903]: Forking 3 albumart workers Feb 12 14:27:40 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 14:27:40 volumio volumio[4790]: info: CoreCommandRouter::initPlayerControls Feb 12 14:27:40 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:40 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:40 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:40 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:40 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:40 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:40 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:40 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:40 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 14:27:40 volumio volumio[4790]: Express server listening on port 3000 Feb 12 14:27:40 volumio volumio[4790]: [Metrics] WebUI: 16s 111.50ms Feb 12 14:27:41 volumio volumio[4790]: info: CoreStateMachine::resetVolumioState Feb 12 14:27:41 volumio volumio[4790]: info: CoreStateMachine::getcurrentVolume Feb 12 14:27:41 volumio volumio[4790]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 14:27:41 volumio sudo[4948]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 12 14:27:41 volumio sudo[4948]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 14:27:41 volumio sudo[4948]: pam_unix(sudo:session): session closed for user root Feb 12 14:27:41 volumio sudo[4950]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 12 14:27:41 volumio sudo[4950]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 14:27:41 volumio sudo[4950]: pam_unix(sudo:session): session closed for user root Feb 12 14:27:41 volumio volumio[4790]: info: Volumio Network Manager: Network status updated: 1 Feb 12 14:27:41 volumio volumio[4790]: info: VolumeController:: Volume=100 Mute =false Feb 12 14:27:41 volumio volumio[4790]: info: CoreStateMachine::pushState Feb 12 14:27:41 volumio volumio[4790]: info: CorePlayQueue::getTrack 0 Feb 12 14:27:41 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 14:27:41 volumio volumio[4790]: info: CoreCommandRouter::volumioPushState Feb 12 14:27:41 volumio volumio[4790]: info: CoreStateMachine::updateTrackBlock Feb 12 14:27:41 volumio volumio[4790]: info: CorePlayQueue::getTrackBlock Feb 12 14:27:41 volumio volumio[4790]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 14:27:41 volumio volumio-remote-updater[643]: [2026-02-12 14:27:41] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770881259 101 Feb 12 14:27:41 volumio volumio[4790]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 12 14:27:41 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 14:27:41 volumio volumio[4790]: info: Reloading queue from file Feb 12 14:27:41 volumio volumio[4790]: info: CoreStateMachine::setRepeat null single undefined Feb 12 14:27:41 volumio volumio[4790]: info: CoreStateMachine::pushState Feb 12 14:27:41 volumio volumio[4790]: info: CorePlayQueue::getTrack 0 Feb 12 14:27:41 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 14:27:41 volumio volumio[4790]: info: CoreCommandRouter::volumioPushState Feb 12 14:27:41 volumio volumio[4790]: info: CoreStateMachine::setRandom null Feb 12 14:27:41 volumio volumio[4790]: info: CoreStateMachine::pushState Feb 12 14:27:41 volumio volumio[4790]: info: CorePlayQueue::getTrack 0 Feb 12 14:27:41 volumio volumio[4790]: info: CoreCommandRouter::volumioPushState Feb 12 14:27:41 volumio volumio[4790]: info: Setting Device type: Raspberry PI Feb 12 14:27:41 volumio volumio[4790]: info: Completed loading Core Plugins Feb 12 14:27:41 volumio volumio[4790]: info: Preparing to generate the ALSA configuration file Feb 12 14:27:42 volumio volumio[4790]: info: VolumeController:: Volume=100 Mute =false Feb 12 14:27:42 volumio volumio[4790]: info: CoreStateMachine::pushState Feb 12 14:27:42 volumio volumio[4790]: info: CorePlayQueue::getTrack 0 Feb 12 14:27:42 volumio volumio[4790]: info: CoreCommandRouter::volumioPushState Feb 12 14:27:42 volumio volumio[4790]: info: Asound.conf file unchanged, so no further update is needed Feb 12 14:27:42 volumio volumio[4790]: info: Output device has changed, restarting MPD Feb 12 14:27:42 volumio volumio[4790]: info: Output device has changed, restarting Shairport Sync Feb 12 14:27:42 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:42 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 14:27:42 volumio sudo[4964]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 12 14:27:42 volumio sudo[4964]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 14:27:42 volumio sudo[4966]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 14:27:42 volumio sudo[4968]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 14:27:42 volumio sudo[4966]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 14:27:42 volumio sudo[4968]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 14:27:42 volumio sudo[4966]: pam_unix(sudo:session): session closed for user root Feb 12 14:27:42 volumio volumio[4790]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 14:27:42 volumio volumio[4790]: info: ___________ START PLUGINS ___________ Feb 12 14:27:42 volumio volumio[4790]: info: ControllerMpd::onStart: Initializing MPD Feb 12 14:27:42 volumio volumio[4790]: info: Creating MPD Configuration file Feb 12 14:27:42 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 14:27:42 volumio volumio[4790]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 14:27:42 volumio volumio[4790]: info: [1770881262380] CoreMusicLibrary::Adding element Media Servers Feb 12 14:27:42 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 12 14:27:42 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 14:27:42 volumio sudo[4964]: pam_unix(sudo:session): session closed for user root Feb 12 14:27:42 volumio sudo[4979]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 14:27:42 volumio sudo[4979]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 14:27:42 volumio volumio[4790]: info: UPNP Browser: Client initialized successfully Feb 12 14:27:42 volumio sudo[4977]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 14:27:42 volumio sudo[4977]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 14:27:42 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 12 14:27:42 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 12 14:27:42 volumio systemd[1]: mpd.service: Consumed 7.204s CPU time. Feb 12 14:27:42 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 12 14:27:42 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 12 14:27:42 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 12 14:27:42 volumio sudo[4977]: pam_unix(sudo:session): session closed for user root Feb 12 14:27:42 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:42 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 14:27:42 volumio volumio[4790]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 14:27:42 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 12 14:27:42 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:42 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 14:27:42 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 12 14:27:42 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 12 14:27:42 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 12 14:27:42 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 12 14:27:42 volumio volumio[4790]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 14:27:42 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 12 14:27:42 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 12 14:27:42 volumio volumio[4790]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 14:27:42 volumio volumio[4790]: info: [1770881262740] CoreMusicLibrary::Adding element Last_100 Feb 12 14:27:42 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 14:27:42 volumio volumio[4790]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 14:27:42 volumio volumio[4790]: info: [1770881262749] CoreMusicLibrary::Adding element Webradio Feb 12 14:27:42 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 14:27:42 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 14:27:42 volumio volumio[4790]: info: Initializing BBC Radios Feb 12 14:27:42 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 12 14:27:42 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 12 14:27:42 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 14:27:42 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 14:27:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Feb 12 14:27:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:27:43 volumio volumio[4790]: info: Creating Spotify config file Feb 12 14:27:43 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:27:43 volumio go-librespot[5007]: go-librespot daemon starting... Feb 12 14:27:43 volumio go-librespot[5009]: time="2026-02-12T14:27:43+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 14:27:43 volumio sudo[4996]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 12 14:27:43 volumio sudo[4996]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 12 14:27:43 volumio sudo[4996]: pam_unix(sudo:session): session closed for user root Feb 12 14:27:43 volumio go-librespot[5009]: time="2026-02-12T14:27:43+07:00" level=info msg="zeroconf server listening on port 37891" Feb 12 14:27:44 volumio volumio[4913]: Starting albumart workers Feb 12 14:27:44 volumio volumio[4914]: Starting albumart workers Feb 12 14:27:44 volumio volumio[4790]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 14:27:44 volumio volumio[4790]: info: [1770881264484] CoreMusicLibrary::Adding element YouTube Music Feb 12 14:27:44 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 14:27:44 volumio volumio[4790]: Cannot find translation for source YouTube Music Feb 12 14:27:44 volumio volumio[4790]: info: Volumio Calling Home Feb 12 14:27:44 volumio volumio[4915]: Starting albumart workers Feb 12 14:27:44 volumio sudo[5019]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 12 14:27:44 volumio sudo[5019]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 14:27:44 volumio sudo[5019]: pam_unix(sudo:session): session closed for user root Feb 12 14:27:45 volumio volumio[4790]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 12 14:27:45 volumio volumio[4790]: info: Discovery: Found device Volumio Feb 12 14:27:45 volumio volumio[4790]: info: CoreCommandRouter::volumioGetState Feb 12 14:27:45 volumio volumio[4790]: info: CorePlayQueue::getTrack 0 Feb 12 14:27:45 volumio volumio[4790]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 12 14:27:45 volumio volumio[4790]: info: Discovery: Found device Volumio Feb 12 14:27:45 volumio volumio[4790]: info: CoreCommandRouter::volumioGetState Feb 12 14:27:45 volumio volumio[4790]: info: CorePlayQueue::getTrack 0 Feb 12 14:27:45 volumio volumio[4790]: info: MPD Permissions set Feb 12 14:27:45 volumio volumio[4790]: info: MPD Permissions set Feb 12 14:27:45 volumio volumio[4790]: info: Upmpdcli Daemon Started Feb 12 14:27:45 volumio volumio[4790]: info: Spotify config file written Feb 12 14:27:45 volumio volumio[4790]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 12 14:27:45 volumio volumio[4790]: info: Volumio called home Feb 12 14:27:45 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:45 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:45 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:45 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:45 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:45 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:45 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:45 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:45 volumio sudo[5025]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 12 14:27:45 volumio sudo[5025]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 14:27:45 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 14:27:45 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:45 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 12 14:27:45 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 12 14:27:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:27:45 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:45 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:45 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:45 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:45 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:45 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:45 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:45 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:27:46 volumio go-librespot[5038]: go-librespot daemon starting... Feb 12 14:27:46 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 14:27:46 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:27:46 volumio sudo[5025]: pam_unix(sudo:session): session closed for user root Feb 12 14:27:46 volumio volumio[4790]: info: No need to fix Spotify hosts Feb 12 14:27:46 volumio go-librespot[5044]: time="2026-02-12T14:27:46+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 14:27:46 volumio go-librespot[5044]: time="2026-02-12T14:27:46+07:00" level=debug msg="app state loaded" Feb 12 14:27:46 volumio go-librespot[5044]: time="2026-02-12T14:27:46+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 14:27:46 volumio go-librespot[5044]: time="2026-02-12T14:27:46+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 12 14:27:46 volumio go-librespot[5044]: time="2026-02-12T14:27:46+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 12 14:27:46 volumio go-librespot[5044]: time="2026-02-12T14:27:46+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 12 14:27:46 volumio go-librespot[5044]: time="2026-02-12T14:27:46+07:00" level=info msg="zeroconf server listening on port 36759" Feb 12 14:27:47 volumio volumio[4790]: info: Starting Shairport Sync Feb 12 14:27:47 volumio volumio[4790]: info: Starting Shairport Sync Feb 12 14:27:47 volumio volumio[4790]: info: Starting Shairport Sync Feb 12 14:27:47 volumio go-librespot[5044]: time="2026-02-12T14:27:47+07:00" level=debug msg="obtained new client token: AAB+/zfGurKc2AyaS7WVAOnbT4tyCWeNRy52tFcQGhBcVsunclkZhwSEhQvxVd66YfNhyjnQS4iqI/9lfSO+i/+khW6Sxm5wpncXXXNMDLvn1qrrLDoDUBfnCPHsQSI1Vg43u3DytnTLXIWK9eFanvAgxh/0HniFPRqOFC41zy9ZwIhEhkmYhjy8eC3IRuFwdRSlzEU6e3ZWDMOMImNdEiOX2bP4iEqY0EegTf5+lPqd3U5dqtGsY/s=" Feb 12 14:27:47 volumio sudo[5065]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 14:27:47 volumio sudo[5065]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 14:27:47 volumio sudo[5069]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 14:27:47 volumio sudo[5069]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 14:27:47 volumio sudo[5067]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 14:27:47 volumio sudo[5067]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 14:27:47 volumio go-librespot[5044]: time="2026-02-12T14:27:47+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 14:27:47 volumio go-librespot[5044]: time="2026-02-12T14:27: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 12 14:27:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 14:27:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 14:27:47 volumio volumio[4790]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 14:27:47 volumio volumio[4790]: SPOTIFY: BQAKwWnBAxjPo4YLka4CFJKAk1kLsE1dcJMr6tj8VEI_x0IxhGliNX7OD8PmMWMf74cqSGypdd2tzO74pMuW7-4eXZ2bKHls3UCvosWz1df9ZzytUMhgjSnxMEKyT4dSSv5PphJ3eBHHFxQ1r_V4c6KjXPP7vwTak8LHk4W915U734O-dXXFcEq1VfMftBY967uouX1nUSCQWeNjwEkTqjbWiZKhWQppcuZM9kSC6oxJBGejeoddgZEgXpP-IPyHGlRscYhV8oR2wxGB2pPJ_XDWae-tAYmmV9jz2XUY84pSMkmNmfp7z9Fd Feb 12 14:27:47 volumio volumio[4790]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 14:27:47 volumio volumio[4790]: info: New Spotify access token = BQAKwWnBAxjPo4YLka4CFJKAk1kLsE1dcJMr6tj8VEI_x0IxhGliNX7OD8PmMWMf74cqSGypdd2tzO74pMuW7-4eXZ2bKHls3UCvosWz1df9ZzytUMhgjSnxMEKyT4dSSv5PphJ3eBHHFxQ1r_V4c6KjXPP7vwTak8LHk4W915U734O-dXXFcEq1VfMftBY967uouX1nUSCQWeNjwEkTqjbWiZKhWQppcuZM9kSC6oxJBGejeoddgZEgXpP-IPyHGlRscYhV8oR2wxGB2pPJ_XDWae-tAYmmV9jz2XUY84pSMkmNmfp7z9Fd Feb 12 14:27:47 volumio volumio[4790]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 12 14:27:47 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 12 14:27:47 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 12 14:27:47 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 14:27:47 volumio systemd[1]: shairport-sync.service: Consumed 2.306s CPU time. Feb 12 14:27:47 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 14:27:47 volumio sudo[5065]: pam_unix(sudo:session): session closed for user root Feb 12 14:27:47 volumio sudo[5067]: pam_unix(sudo:session): session closed for user root Feb 12 14:27:47 volumio sudo[5069]: pam_unix(sudo:session): session closed for user root Feb 12 14:27:47 volumio volumio[4790]: info: CoreCommandRouter::volumioGetState Feb 12 14:27:47 volumio volumio[4790]: info: CorePlayQueue::getTrack 0 Feb 12 14:27:47 volumio volumio[4790]: info: Shairport-Sync Started Feb 12 14:27:47 volumio volumio[4790]: Error adding Membership: Error: addMembership EINVAL Feb 12 14:27:47 volumio volumio[4790]: info: Shairport-Sync Started Feb 12 14:27:47 volumio volumio[4790]: info: Shairport-Sync Started Feb 12 14:27:47 volumio volumio[4790]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 12 14:27:47 volumio volumio[4790]: info: Spotify Successfully logged in Feb 12 14:27:47 volumio volumio[4790]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 14:27:47 volumio volumio[4790]: info: [1770881267952] CoreMusicLibrary::Adding element Spotify Feb 12 14:27:47 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 14:27:47 volumio volumio[4790]: Cannot find translation for source YouTube Music Feb 12 14:27:47 volumio volumio[4790]: Cannot find translation for source Spotify Feb 12 14:27:48 volumio volumio[4790]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 12 14:27:48 volumio volumio[4790]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 14:27:48 volumio volumio[4790]: info: VolumeController:: Volume=100 Mute =false Feb 12 14:27:48 volumio volumio[4790]: info: CoreCommandRouter::volumioGetState Feb 12 14:27:48 volumio volumio[4790]: info: CorePlayQueue::getTrack 0 Feb 12 14:27:48 volumio volumio[4790]: info: CoreStateMachine::pushState Feb 12 14:27:48 volumio volumio[4790]: info: CorePlayQueue::getTrack 0 Feb 12 14:27:48 volumio volumio[4790]: info: CoreCommandRouter::volumioPushState Feb 12 14:27:49 volumio volumio[4790]: info: go-librespot daemon successfully initialized Feb 12 14:27:50 volumio mpd[5016]: 2026-02-12T14:27:50 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 12 14:27:50 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 12 14:27:50 volumio sudo[4979]: pam_unix(sudo:session): session closed for user root Feb 12 14:27:50 volumio sudo[4968]: pam_unix(sudo:session): session closed for user root Feb 12 14:27:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 12 14:27:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:27:50 volumio volumio[4790]: error: MPD error: The expression evaluated to a falsy value: Feb 12 14:27:50 volumio volumio[4790]: assert.ok(self.idling) Feb 12 14:27:50 volumio volumio[4790]: error: The expression evaluated to a falsy value: Feb 12 14:27:50 volumio volumio[4790]: assert.ok(self.idling) Feb 12 14:27:50 volumio volumio[4790]: info: MPD running with PID5016 Feb 12 14:27:50 volumio volumio[4790]: ,establishing connection Feb 12 14:27:50 volumio volumio[4790]: error: updateQueue error: null Feb 12 14:27:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:27:50 volumio go-librespot[5109]: go-librespot daemon starting... Feb 12 14:27:50 volumio volumio[4790]: info: Completed starting Core Plugins Feb 12 14:27:50 volumio volumio[4790]: info: ------------------------------------------- Feb 12 14:27:50 volumio volumio[4790]: info: ----- MyVolumio plugins startup ---- Feb 12 14:27:50 volumio volumio[4790]: info: ------------------------------------------- Feb 12 14:27:50 volumio volumio[4790]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 12 14:27:50 volumio volumio[4790]: error: updateQueue error: null Feb 12 14:27:50 volumio go-librespot[5110]: time="2026-02-12T14:27:50+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 14:27:50 volumio go-librespot[5110]: time="2026-02-12T14:27:50+07:00" level=debug msg="app state loaded" Feb 12 14:27:50 volumio go-librespot[5110]: time="2026-02-12T14:27:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 14:27:51 volumio go-librespot[5110]: time="2026-02-12T14:27:51+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 14:27:51 volumio go-librespot[5110]: time="2026-02-12T14:27:51+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 14:27:51 volumio go-librespot[5110]: time="2026-02-12T14:27:51+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 14:27:51 volumio go-librespot[5110]: time="2026-02-12T14:27:51+07:00" level=info msg="zeroconf server listening on port 45953" Feb 12 14:27:51 volumio go-librespot[5110]: time="2026-02-12T14:27:51+07:00" level=debug msg="obtained new client token: AADxvKxbSQDHUTpksYi8bt+paqSOqbJve1ikvAi4Q68j2KqsV7DRFMjt/xV/DojVV1VYz2KJQkqTs+FgKhB7fT6ef1A4fHYqwql/agEHYsS0a9HdHPfKqxO/+PiODWXf59e8FuFb2dQVEhSb1zShh9Fqgr7Gc3YGE33GVJLPCQ/rxaZvZMJhpaPdxNat5eLgFASZ2g7WwKpV2ja0y/7jlM8DzBrtXsqmf2KhUwUgD2Lnrle7qgK/Fbindw==" Feb 12 14:27:51 volumio go-librespot[5110]: time="2026-02-12T14:27:51+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 14:27:51 volumio go-librespot[5110]: time="2026-02-12T14:27:51+07:00" level=debug msg="completed keyexchange" Feb 12 14:27:51 volumio go-librespot[5110]: time="2026-02-12T14:27:51+07:00" level=debug msg="completed challenge" Feb 12 14:27:51 volumio go-librespot[5110]: time="2026-02-12T14:27:51+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 14:27:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 14:27:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 14:27:52 volumio volumio[4790]: info: Initializing connection to go-librespot Websocket Feb 12 14:27:52 volumio volumio[4790]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 14:27:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 12 14:27:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:27:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:27:54 volumio go-librespot[5117]: go-librespot daemon starting... Feb 12 14:27:54 volumio go-librespot[5118]: time="2026-02-12T14:27:54+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 14:27:54 volumio go-librespot[5118]: time="2026-02-12T14:27:54+07:00" level=debug msg="app state loaded" Feb 12 14:27:54 volumio go-librespot[5118]: time="2026-02-12T14:27:54+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 14:27:55 volumio go-librespot[5118]: time="2026-02-12T14:27:55+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 14:27:55 volumio go-librespot[5118]: time="2026-02-12T14:27:55+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 14:27:55 volumio go-librespot[5118]: time="2026-02-12T14:27:55+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 14:27:55 volumio go-librespot[5118]: time="2026-02-12T14:27:55+07:00" level=info msg="zeroconf server listening on port 34397" Feb 12 14:27:55 volumio volumio[4790]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 12 14:27:55 volumio go-librespot[5118]: time="2026-02-12T14:27:55+07:00" level=debug msg="obtained new client token: AAC/2QWgL/O+t+pGV+04SK2PzShxRLtUuAaz8zWvo9Q4/j/N7Rn3NrIjUJugpmeMu2j6J1MahfjOPxTZGU2MQf6nOjtbEmCyIkxO/YlYmn4LzqZ/mMwf3A6QAQ9KsJzG5gLItVY5w4RgtoppCLUG1p2Xclw3ViaiPipSYvXLBsC7RGfGWacezY/v8qtXaRWJHnplIiMVXGJFKBMpysqZNghBQnR7XF1OBo5CzT6q+7xAtpqz/8JbQXGDFA==" Feb 12 14:27:55 volumio go-librespot[5118]: time="2026-02-12T14:27:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 14:27:55 volumio go-librespot[5118]: time="2026-02-12T14:27:55+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 12 14:27:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 14:27:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 14:27:55 volumio volumio[4790]: info: Initializing connection to go-librespot Websocket Feb 12 14:27:55 volumio volumio[4790]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 14:27:58 volumio volumio[4790]: info: Initializing connection to go-librespot Websocket Feb 12 14:27:58 volumio volumio[4790]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 14:27:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 12 14:27:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:27:59 volumio volumio[4790]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 12 14:27:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:27:59 volumio volumio[4790]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 12 14:27:59 volumio volumio[4790]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 12 14:27:59 volumio volumio[4790]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 12 14:27:59 volumio volumio[4790]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 12 14:27:59 volumio volumio[4790]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 12 14:27:59 volumio volumio[4790]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 12 14:27:59 volumio volumio[4790]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 12 14:27:59 volumio volumio[4790]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 12 14:27:59 volumio go-librespot[5126]: go-librespot daemon starting... Feb 12 14:27:59 volumio volumio[4790]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 12 14:27:59 volumio volumio[4790]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 12 14:27:59 volumio volumio[4790]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 12 14:27:59 volumio volumio[4790]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 12 14:27:59 volumio volumio[4790]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 12 14:27:59 volumio volumio[4790]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 12 14:27:59 volumio volumio[4790]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 12 14:27:59 volumio volumio[4790]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 12 14:27:59 volumio volumio[4790]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 12 14:27:59 volumio volumio[4790]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 12 14:27:59 volumio volumio[4790]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 12 14:27:59 volumio volumio[4790]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 12 14:27:59 volumio volumio[4790]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 12 14:27:59 volumio volumio[4790]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 12 14:27:59 volumio volumio[4790]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 12 14:27:59 volumio volumio[4790]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 12 14:27:59 volumio volumio[4790]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 12 14:27:59 volumio volumio[4790]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 12 14:27:59 volumio volumio[4790]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 12 14:27:59 volumio volumio[4790]: info: Adding plugin bluetooth to MyMusic Plugins Feb 12 14:27:59 volumio volumio[4790]: info: Adding plugin multiroom to MyMusic Plugins Feb 12 14:27:59 volumio volumio[4790]: info: Adding plugin metavolumio to MyMusic Plugins Feb 12 14:27:59 volumio volumio[4790]: info: Adding plugin cd_controller to MyMusic Plugins Feb 12 14:27:59 volumio volumio[4790]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 12 14:27:59 volumio volumio[4790]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 12 14:27:59 volumio volumio[4790]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 12 14:27:59 volumio volumio[4790]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 12 14:27:59 volumio go-librespot[5127]: time="2026-02-12T14:27:59+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 14:27:59 volumio go-librespot[5127]: time="2026-02-12T14:27:59+07:00" level=debug msg="app state loaded" Feb 12 14:27:59 volumio go-librespot[5127]: time="2026-02-12T14:27:59+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 14:27:59 volumio go-librespot[5127]: time="2026-02-12T14:27:59+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 14:27:59 volumio go-librespot[5127]: time="2026-02-12T14:27:59+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 14:27:59 volumio go-librespot[5127]: time="2026-02-12T14:27:59+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 14:27:59 volumio go-librespot[5127]: time="2026-02-12T14:27:59+07:00" level=info msg="zeroconf server listening on port 35845" Feb 12 14:27:59 volumio go-librespot[5127]: time="2026-02-12T14:27:59+07:00" level=debug msg="obtained new client token: AAADCydUNwV+iWRQ9/7C4Agkmr/pTro5b/VH+SVzgOHnS2iDH8fByJs7+TCIh8V5b+wUxqqBPlUtCvsbhznK5dbISKUbCztURE3nF85kelhVSk+8Sn+LP45UgF0jACA20yxD3A/napLljMs+/YJJP91whUGIvc40MjAaOMubCD1iPmRf6AyjWQR3YlV5d8uUIfiEf/vrn86DTjCwiaUAXdDa1CNZzNDx+WzFRFFUcFoRrG1t3Q0Fb/dnmA==" Feb 12 14:28:00 volumio go-librespot[5127]: time="2026-02-12T14:28:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 14:28:00 volumio go-librespot[5127]: time="2026-02-12T14:28:00+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 12 14:28:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 14:28:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 14:28:01 volumio volumio[4790]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 12 14:28:01 volumio volumio[4790]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 12 14:28:01 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 14:28:01 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 14:28:01 volumio volumio[4790]: info: Starting MyVolumio Remote Streaming Endpoints Feb 12 14:28:01 volumio volumio[4790]: info: MyVolumio login type: Token Feb 12 14:28:01 volumio volumio[4790]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 12 14:28:01 volumio volumio[4790]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 12 14:28:02 volumio volumio[4790]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 12 14:28:02 volumio volumio[4790]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 12 14:28:02 volumio volumio[4790]: info: Streaming services startup Feb 12 14:28:02 volumio volumio[4790]: info: Starting Streaming Daemon Feb 12 14:28:02 volumio sudo[5151]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 12 14:28:02 volumio sudo[5151]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 14:28:02 volumio volumio[4790]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 12 14:28:03 volumio sudo[5151]: pam_unix(sudo:session): session closed for user root Feb 12 14:28:03 volumio volumio[4790]: info: Initializing connection to go-librespot Websocket Feb 12 14:28:03 volumio volumio[4790]: error: Cannot start Volumio Streaming Daemon Feb 12 14:28:03 volumio volumio[4790]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 12 14:28:03 volumio volumio[4790]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 12 14:28:03 volumio volumio[4790]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 14:28:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 12 14:28:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:28:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:28:03 volumio go-librespot[5157]: go-librespot daemon starting... Feb 12 14:28:03 volumio go-librespot[5158]: time="2026-02-12T14:28:03+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 14:28:03 volumio go-librespot[5158]: time="2026-02-12T14:28:03+07:00" level=debug msg="app state loaded" Feb 12 14:28:03 volumio go-librespot[5158]: time="2026-02-12T14:28:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 14:28:03 volumio go-librespot[5158]: time="2026-02-12T14:28:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 12 14:28:03 volumio go-librespot[5158]: time="2026-02-12T14:28:03+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 12 14:28:03 volumio go-librespot[5158]: time="2026-02-12T14:28:03+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 12 14:28:03 volumio go-librespot[5158]: time="2026-02-12T14:28:03+07:00" level=info msg="zeroconf server listening on port 33675" Feb 12 14:28:04 volumio volumio[4790]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 12 14:28:04 volumio go-librespot[5158]: time="2026-02-12T14:28:04+07:00" level=debug msg="obtained new client token: AADpc5Z8Mehp1eA+5srpguPUGUpHmSUftSGJdI6YgvPprBKaJ9qT10he8oojFHcqHlSEVWhfYa4eICubNJL4/+jurhd4nJAU9KXtH/A7gZJvQXYdB2+6ggUtANGbaTYYTbWoy/yP4N1ryefR2C6xfCexxp18SZ+KvA92QFTQ6lLZ7xXGJz+0hJKUuTgZVMJZOHCfQbWqLnNQxlLm0Ijqfvkk6+QK/JFuo3GN7pGyVRL/2Q0BqQUydRE=" Feb 12 14:28:04 volumio go-librespot[5158]: time="2026-02-12T14:28:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 14:28:04 volumio go-librespot[5158]: time="2026-02-12T14:28:04+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 12 14:28:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 14:28:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 14:28:05 volumio volumio[4790]: info: MyVolumio token set successfully Feb 12 14:28:05 volumio volumio[4790]: info: MYVOLUMIO: Adding device Feb 12 14:28:05 volumio volumio[4790]: info: MYVOLUMIO: Evaluating Server Feb 12 14:28:05 volumio volumio[4790]: info: MyVolumio status changed Feb 12 14:28:05 volumio volumio[4790]: info: Streaming services startup Feb 12 14:28:05 volumio volumio[4790]: info: Starting Streaming Daemon Feb 12 14:28:05 volumio volumio[4790]: info: Removing browser output: myVolumio user plan is not superstar Feb 12 14:28:05 volumio volumio[4790]: info: Removing audio output: Feb 12 14:28:05 volumio volumio[4790]: info: Stoppping Tunnel 1 Feb 12 14:28:05 volumio sudo[5186]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 12 14:28:05 volumio sudo[5186]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 14:28:05 volumio sudo[5186]: pam_unix(sudo:session): session closed for user root Feb 12 14:28:05 volumio sudo[5189]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 12 14:28:05 volumio sudo[5189]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 14:28:05 volumio volumio[4790]: error: Cannot start Volumio Streaming Daemon Feb 12 14:28:05 volumio volumio[4790]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 12 14:28:05 volumio volumio[4790]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 12 14:28:05 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 12 14:28:05 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 12 14:28:05 volumio volumio[4790]: info: Setting Geolocation for MyVolumio to as1 Feb 12 14:28:05 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 14:28:05 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 14:28:05 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 14:28:05 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 12 14:28:05 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 12 14:28:05 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 12 14:28:05 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 12 14:28:05 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 12 14:28:05 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 12 14:28:05 volumio sudo[5189]: pam_unix(sudo:session): session closed for user root Feb 12 14:28:05 volumio volumio[4790]: info: Remote SSH Stopped Feb 12 14:28:06 volumio volumio[4790]: info: Initializing connection to go-librespot Websocket Feb 12 14:28:06 volumio volumio[4790]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 14:28:06 volumio volumio[4790]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 12 14:28:06 volumio volumio[4790]: info: Updating MyVolumio device info Feb 12 14:28:06 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 14:28:06 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 14:28:06 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 14:28:07 volumio volumio[4790]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 12 14:28:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 12 14:28:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:28:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:28:07 volumio go-librespot[5191]: go-librespot daemon starting... Feb 12 14:28:07 volumio go-librespot[5192]: time="2026-02-12T14:28:07+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 14:28:07 volumio go-librespot[5192]: time="2026-02-12T14:28:07+07:00" level=debug msg="app state loaded" Feb 12 14:28:07 volumio go-librespot[5192]: time="2026-02-12T14:28:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 14:28:08 volumio go-librespot[5192]: time="2026-02-12T14:28:08+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 14:28:08 volumio go-librespot[5192]: time="2026-02-12T14:28:08+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 14:28:08 volumio go-librespot[5192]: time="2026-02-12T14:28:08+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 14:28:08 volumio go-librespot[5192]: time="2026-02-12T14:28:08+07:00" level=info msg="zeroconf server listening on port 45067" Feb 12 14:28:08 volumio go-librespot[5192]: time="2026-02-12T14:28:08+07:00" level=debug msg="obtained new client token: AAAg3Z7FEWcunhjR7Lb/49sNdMQ9ExiRgnONj+4dg9rlgWJSyFz0ZfA0KY0jGsxJ075ZduhayIOlWMjkFTlAhKKXhahoTTlCnKIDqmZyvmki9jS2PxeI9xntIEjN0rae9Fa1n6Jrv8hsbRUOdIMCk/whwZKrqwAURitW0QNXtc1Pw7Lr0cPLz2XJhv8mXcP5bZjdHdZCApkRiI3v2iq3fdXHNyID6n633yr3J6uObiSlmKm8BbguLdA7Jg==" Feb 12 14:28:08 volumio go-librespot[5192]: time="2026-02-12T14:28:08+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 12 14:28:08 volumio go-librespot[5192]: time="2026-02-12T14:28:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 12 14:28:08 volumio go-librespot[5192]: time="2026-02-12T14:28:08+07:00" level=debug msg="completed keyexchange" Feb 12 14:28:08 volumio go-librespot[5192]: time="2026-02-12T14:28:08+07:00" level=debug msg="completed challenge" Feb 12 14:28:08 volumio go-librespot[5192]: time="2026-02-12T14:28:08+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 14:28:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 14:28:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 14:28:09 volumio volumio[4790]: info: Initializing connection to go-librespot Websocket Feb 12 14:28:09 volumio volumio[4790]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 14:28:10 volumio volumio[4790]: info: MYVOLUMIO: Adding device Feb 12 14:28:10 volumio volumio[4790]: info: MYVOLUMIO: Evaluating Server Feb 12 14:28:11 volumio volumio[4790]: info: Setting Geolocation for MyVolumio to as1 Feb 12 14:28:11 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 14:28:11 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 14:28:11 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 14:28:11 volumio volumio[4790]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 12 14:28:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 12 14:28:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:28:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:28:12 volumio go-librespot[5231]: go-librespot daemon starting... Feb 12 14:28:12 volumio volumio[4790]: info: Initializing connection to go-librespot Websocket Feb 12 14:28:12 volumio volumio[4790]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 14:28:12 volumio go-librespot[5232]: time="2026-02-12T14:28:12+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 14:28:12 volumio go-librespot[5232]: time="2026-02-12T14:28:12+07:00" level=debug msg="app state loaded" Feb 12 14:28:12 volumio go-librespot[5232]: time="2026-02-12T14:28:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 14:28:12 volumio volumio[4790]: info: Updating MyVolumio device info Feb 12 14:28:12 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 14:28:12 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 14:28:12 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 14:28:12 volumio go-librespot[5232]: time="2026-02-12T14:28:12+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 14:28:12 volumio go-librespot[5232]: time="2026-02-12T14:28:12+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 14:28:12 volumio go-librespot[5232]: time="2026-02-12T14:28:12+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 14:28:12 volumio go-librespot[5232]: time="2026-02-12T14:28:12+07:00" level=info msg="zeroconf server listening on port 39769" Feb 12 14:28:12 volumio go-librespot[5232]: time="2026-02-12T14:28:12+07:00" level=debug msg="obtained new client token: AACuKrMgGbmotHTlbphGic6smXafWM+D+Yu52E+TxTA0z1scr6Wny1WOh5uJCVVgUJLSNa1pXWBShQOfn45KuWJD+xE4F7I4vkaVw0IQKMMT+jOEJhQrOovzVwAWwE3bZRuMKPPBnlVrBB1ASPeoXWgC+LeoR8C88G8BocTYDdiAGQBoU7zTw2FG855Qi12URpfOGlGY0AqESebzn9rhJtaegr1FpaaLvxFUJACUxz556/CukKFBTCDuBg==" Feb 12 14:28:12 volumio go-librespot[5232]: time="2026-02-12T14:28:12+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 12 14:28:13 volumio go-librespot[5232]: time="2026-02-12T14:28:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 12 14:28:13 volumio go-librespot[5232]: time="2026-02-12T14:28:13+07:00" level=debug msg="completed keyexchange" Feb 12 14:28:13 volumio go-librespot[5232]: time="2026-02-12T14:28:13+07:00" level=debug msg="completed challenge" Feb 12 14:28:13 volumio go-librespot[5232]: time="2026-02-12T14:28: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 12 14:28:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 14:28:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 14:28:13 volumio volumio[4790]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 12 14:28:14 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 14:28:14 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 14:28:14 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 12 14:28:14 volumio volumio-remote-updater[643]: Test mode disabled Feb 12 14:28:14 volumio volumio-remote-updater[643]: Alpha mode disabled Feb 12 14:28:14 volumio volumio-remote-updater[643]: Alpha legacy test mode disabled Feb 12 14:28:14 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Feb 12 14:28:15 volumio volumio[4790]: info: Initializing connection to go-librespot Websocket Feb 12 14:28:15 volumio volumio[4790]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 14:28:15 volumio volumio[4790]: 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 12 14:28:15 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Feb 12 14:28:16 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 12 14:28:16 volumio volumio[4790]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 12 14:28:16 volumio volumio[4790]: info: CoreCommandRouter::volumioGetState Feb 12 14:28:16 volumio volumio[4790]: info: CorePlayQueue::getTrack 0 Feb 12 14:28:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 12 14:28:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:28:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:28:16 volumio go-librespot[5245]: go-librespot daemon starting... Feb 12 14:28:16 volumio go-librespot[5246]: time="2026-02-12T14:28:16+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 14:28:16 volumio go-librespot[5246]: time="2026-02-12T14:28:16+07:00" level=debug msg="app state loaded" Feb 12 14:28:16 volumio go-librespot[5246]: time="2026-02-12T14:28:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 14:28:16 volumio go-librespot[5246]: time="2026-02-12T14:28:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 14:28:16 volumio go-librespot[5246]: time="2026-02-12T14:28:16+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 14:28:16 volumio go-librespot[5246]: time="2026-02-12T14:28:16+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 14:28:16 volumio go-librespot[5246]: time="2026-02-12T14:28:16+07:00" level=info msg="zeroconf server listening on port 34295" Feb 12 14:28:17 volumio go-librespot[5246]: time="2026-02-12T14:28:17+07:00" level=debug msg="obtained new client token: AACj8co69F1X2BxpNBWj9hCjd6UH9EP6RjC2pCVtXjw19GbeJZSMnTeNGl60+1Aab3MKWt2rPW0/JPybQV9IW4YIdWzc7qH85GM1dXutRUyHATy4ErfiuNal+iP75gvkyapq2IvkF3gerJYnf85e2gAi2LuSyph/ldb84gjccAEHWK3DKbuDADBBHhAegXaIDOKDwx+ZqVAPHGgfX78gq0A/kxPfGiN03TqvaJcXOryvyph4yeI336M=" Feb 12 14:28:17 volumio go-librespot[5246]: time="2026-02-12T14:28:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 14:28:17 volumio go-librespot[5246]: time="2026-02-12T14:28:17+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 12 14:28:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 14:28:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 14:28:18 volumio volumio[4790]: info: Initializing connection to go-librespot Websocket Feb 12 14:28:18 volumio volumio[4790]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 14:28:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 12 14:28:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:28:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:28:20 volumio go-librespot[5267]: go-librespot daemon starting... Feb 12 14:28:20 volumio go-librespot[5268]: time="2026-02-12T14:28:20+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 14:28:20 volumio go-librespot[5268]: time="2026-02-12T14:28:20+07:00" level=debug msg="app state loaded" Feb 12 14:28:20 volumio go-librespot[5268]: time="2026-02-12T14:28:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 14:28:21 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:28:21 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:28:21 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Feb 12 14:28:21 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Feb 12 14:28:21 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Feb 12 14:28:21 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Feb 12 14:28:21 volumio volumio[4790]: info: CoreCommandRouter::volumioGetBrowseSources Feb 12 14:28:21 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 14:28:21 volumio go-librespot[5268]: time="2026-02-12T14:28: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 14:28:21 volumio go-librespot[5268]: time="2026-02-12T14:28:21+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 14:28:21 volumio go-librespot[5268]: time="2026-02-12T14:28:21+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 14:28:21 volumio go-librespot[5268]: time="2026-02-12T14:28:21+07:00" level=info msg="zeroconf server listening on port 46099" Feb 12 14:28:21 volumio volumio[4790]: info: Initializing connection to go-librespot Websocket Feb 12 14:28:21 volumio go-librespot[5268]: time="2026-02-12T14:28:21+07:00" level=debug msg="new websocket client" Feb 12 14:28:21 volumio volumio[4790]: info: Connection to go-librespot Websocket established Feb 12 14:28:21 volumio go-librespot[5268]: time="2026-02-12T14:28:21+07:00" level=debug msg="obtained new client token: AAAPjpII7cnUk36N6mHdr+882ckpBGxxZaZ/GNAvpi/FYsfA2JOncSLi3bbovojmmoQkxwhW6vS/1k0hKm868GjsfcDhmZJBrFQS0cHtsIVziSIsqqfvAblJZ1oW5SVbNthv7c1QjmfND1EBHrBwhPt5QVeC8iU1x1TBIr6gK3FXmCe8OuPxewTksaH7RZCXHU3XjQpLnubNcbRKbN7LWa4M6Re2t/ZV8ZXYmZN3hwOcLlaaYaFVhTKaNA==" Feb 12 14:28:21 volumio go-librespot[5268]: time="2026-02-12T14:28:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 14:28:21 volumio go-librespot[5268]: time="2026-02-12T14:28:21+07:00" level=debug msg="completed keyexchange" Feb 12 14:28:21 volumio go-librespot[5268]: time="2026-02-12T14:28:21+07:00" level=debug msg="completed challenge" Feb 12 14:28:21 volumio go-librespot[5268]: time="2026-02-12T14:28:21+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 14:28:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 14:28:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 14:28:21 volumio volumio[4790]: info: Connection to go-librespot Websocket closed Feb 12 14:28:22 volumio volumio[4790]: error: MyVolumio Plugin failed to authenticate in a timely fashion Feb 12 14:28:22 volumio volumio[4790]: info: Completed starting MyVolumio Plugin Feb 12 14:28:22 volumio volumio[4790]: [Metrics] CommandRouter: 57s 147.94ms Feb 12 14:28:22 volumio volumio[4790]: info: CoreCommandRouter::volumiosetStartupVolume Feb 12 14:28:22 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 14:28:22 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 14:28:22 volumio volumio[4790]: info: CoreCommandRouter::Close All Modals sent Feb 12 14:28:22 volumio volumio[4790]: info: CoreCommandRouter::Close All Modals sent Feb 12 14:28:23 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Feb 12 14:28:23 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 12 14:28:23 volumio volumio[4790]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Feb 12 14:28:24 volumio volumio[4790]: info: Getting Spotify volume Feb 12 14:28:24 volumio volumio[4790]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 14:28:24 volumio volumio[4790]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 14:28:24 volumio volumio[4790]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 12 14:28:24 volumio volumio[4790]: errno: -111, Feb 12 14:28:24 volumio volumio[4790]: code: 'ECONNREFUSED', Feb 12 14:28:24 volumio volumio[4790]: syscall: 'connect', Feb 12 14:28:24 volumio volumio[4790]: address: '127.0.0.1', Feb 12 14:28:24 volumio volumio[4790]: port: 9879, Feb 12 14:28:24 volumio volumio[4790]: response: undefined Feb 12 14:28:24 volumio volumio[4790]: } Feb 12 14:28:24 volumio volumio[4790]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 14:28:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 12 14:28:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:28:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 14:28:24 volumio go-librespot[5289]: go-librespot daemon starting... Feb 12 14:28:24 volumio go-librespot[5290]: time="2026-02-12T14:28:24+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 14:28:24 volumio go-librespot[5290]: time="2026-02-12T14:28:24+07:00" level=debug msg="app state loaded" Feb 12 14:28:24 volumio go-librespot[5290]: time="2026-02-12T14:28:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 14:28:25 volumio go-librespot[5290]: time="2026-02-12T14:28:25+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 12 14:28:25 volumio go-librespot[5290]: time="2026-02-12T14:28:25+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 12 14:28:25 volumio go-librespot[5290]: time="2026-02-12T14:28:25+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 12 14:28:25 volumio go-librespot[5290]: time="2026-02-12T14:28:25+07:00" level=info msg="zeroconf server listening on port 42511" Feb 12 14:28:25 volumio go-librespot[5290]: time="2026-02-12T14:28:25+07:00" level=debug msg="obtained new client token: AADvNQfynTqt/3NSAvw8xSo43TuzsuTs71BHHxeJgomxPAyBnAJwqjqQhmST5FBlKpKPUY5bTN9ZEPecNyMCnxtYE5sgFKx2nX5rrvTNP7LpUbJP6Zsqf0PB0BCjD8oMZNY90ata3HFSN9GJsWiz3VbujkKtq2rk2ZESPHz0Hi9tzGUkrFwUUpBaGpDyIzzn0WHquHfqfEGl2e9XV3MgYWy/ZUZgOQ0ltt5Rba5fI5x9ZnxmqCNMUNonHQ==" Feb 12 14:28:25 volumio sudo[5300]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-12 14:27' Feb 12 14:28:25 volumio sudo[5300]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 14:28:25 volumio go-librespot[5290]: time="2026-02-12T14:28:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 14:28:25 volumio go-librespot[5290]: time="2026-02-12T14:28:25+07:00" level=debug msg="completed keyexchange" Feb 12 14:28:25 volumio go-librespot[5290]: time="2026-02-12T14:28:25+07:00" level=debug msg="completed challenge" 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"