Mar 04 02:47:00 volumio volumio[13731]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 02:47:00 volumio volumio[13731]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 02:47:00 volumio volumio[13731]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 02:47:00 volumio volumio[13731]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 02:47:00 volumio volumio[13731]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 02:47:00 volumio volumio[13731]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 02:47:00 volumio volumio[13731]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 02:47:00 volumio volumio[13731]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 02:47:00 volumio volumio[13731]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 04 02:47:00 volumio volumio[13731]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 02:47:00 volumio sudo[14065]:  volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service
Mar 04 02:47:00 volumio sudo[14065]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 02:47:00 volumio volumio[13731]: info: CoreCommandRouter::volumioGetState
Mar 04 02:47:00 volumio volumio[13731]: info: CorePlayQueue::getTrack 0
Mar 04 02:47:00 volumio sudo[14065]: pam_unix(sudo:session): session closed for user root
Mar 04 02:47:00 volumio volumio[13731]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload  || true
Mar 04 02:47:00 volumio sudo[14061]:     root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Mar 04 02:47:00 volumio sudo[14061]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Mar 04 02:47:00 volumio volumio[13731]: info: Starting Shairport Sync
Mar 04 02:47:00 volumio sudo[14061]: pam_unix(sudo:session): session closed for user root
Mar 04 02:47:00 volumio sudo[14074]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload
Mar 04 02:47:00 volumio sudo[14074]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 02:47:00 volumio sudo[14076]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Mar 04 02:47:00 volumio sudo[14076]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 02:47:00 volumio volumio[13731]: SPOTIFY: User informations: {"display_name":"Clint Smith","external_urls":{"spotify":"https://open.spotify.com/user/clintsmith1"},"followers":{"href":null,"total":7},"href":"https://api.spotify.com/v1/users/clintsmith1","id":"clintsmith1","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee856520409d25d9cc210472a0fd","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b826520409d25d9cc210472a0fd","width":64}],"type":"user","uri":"spotify:user:clintsmith1"}
Mar 04 02:47:00 volumio volumio[13731]: info: Spotify Successfully logged in
Mar 04 02:47:00 volumio volumio[13731]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Mar 04 02:47:00 volumio volumio[13731]: info: [1772614020269] CoreMusicLibrary::Adding element Spotify
Mar 04 02:47:00 volumio volumio[13731]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 04 02:47:00 volumio volumio[13731]: Cannot find translation for source Bandcamp Discover
Mar 04 02:47:00 volumio volumio[13731]: Cannot find translation for source SoundCloud
Mar 04 02:47:00 volumio volumio[13731]: Cannot find translation for source YouTube2
Mar 04 02:47:00 volumio volumio[13731]: Cannot find translation for source YouTube Music
Mar 04 02:47:00 volumio volumio[13731]: Cannot find translation for source Podcast
Mar 04 02:47:00 volumio volumio[13731]: Cannot find translation for source Volusonic
Mar 04 02:47:00 volumio volumio[13731]: Cannot find translation for source Spotify
Mar 04 02:47:00 volumio systemd[1]: Reloading.
Mar 04 02:47:01 volumio volumio[13731]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 02:47:01 volumio volumio[13731]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 02:47:01 volumio volumio[13731]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 02:47:01 volumio volumio[13731]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Mar 04 02:47:01 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Mar 04 02:47:01 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Mar 04 02:47:02 volumio sudo[14074]: pam_unix(sudo:session): session closed for user root
Mar 04 02:47:02 volumio volumio[13731]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Mar 04 02:47:02 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Mar 04 02:47:02 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Mar 04 02:47:02 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Mar 04 02:47:02 volumio systemd[1]: shairport-sync.service: Consumed 1.479s CPU time.
Mar 04 02:47:02 volumio sudo[14098]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Mar 04 02:47:02 volumio sudo[14098]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 02:47:02 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Mar 04 02:47:02 volumio sudo[14076]: pam_unix(sudo:session): session closed for user root
Mar 04 02:47:02 volumio volumio[13731]: info: Shairport-Sync Started
Mar 04 02:47:02 volumio volumio[13731]: info: go-librespot daemon successfully initialized
Mar 04 02:47:02 volumio sudo[14098]: pam_unix(sudo:session): session closed for user root
Mar 04 02:47:02 volumio volumio[13731]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true
Mar 04 02:47:02 volumio sudo[14116]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite
Mar 04 02:47:02 volumio sudo[14116]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 02:47:02 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator...
Mar 04 02:47:02 volumio systemd[1]: squeezelite.service: Deactivated successfully.
Mar 04 02:47:02 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator.
Mar 04 02:47:02 volumio sudo[14116]: pam_unix(sudo:session): session closed for user root
Mar 04 02:47:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 221.
Mar 04 02:47:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:47:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:47:02 volumio go-librespot[14119]: go-librespot daemon starting...
Mar 04 02:47:02 volumio go-librespot[14120]: time="2026-03-04T02:47:02-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 02:47:02 volumio go-librespot[14120]: time="2026-03-04T02:47:02-06:00" level=debug msg="app state loaded"
Mar 04 02:47:02 volumio go-librespot[14120]: time="2026-03-04T02:47:02-06:00" level=debug msg="stored credentials not found"
Mar 04 02:47:02 volumio go-librespot[14120]: time="2026-03-04T02:47:02-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 02:47:03 volumio go-librespot[14120]: time="2026-03-04T02:47:03-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Mar 04 02:47:03 volumio go-librespot[14120]: time="2026-03-04T02:47:03-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Mar 04 02:47:03 volumio go-librespot[14120]: time="2026-03-04T02:47:03-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Mar 04 02:47:03 volumio go-librespot[14120]: time="2026-03-04T02:47:03-06:00" level=info msg="zeroconf server listening on port 46637"
Mar 04 02:47:03 volumio go-librespot[14120]: time="2026-03-04T02:47:03-06:00" level=debug msg="obtained new client token: AADVa5gFRW/FYtg45P+mfuwuEtDzhQfO69u6AhLcY1CMvEokDdnIba9xVndoidZOu4+aDILBh5cJxufbZdU6D87a2Fz5rTJnW4gaXdgu9s4XixIxQXARJMHV7KZIf8vjnbGHMxlnBEsQdbST4g+EKzOjdZo4LfaPJCOz+tUB0JnMRTxA9KxUfKM69j2HLfKFcIOMkrNKSYf1y54+oaTwKfrZrejT20JOXDzSzJ7CUcF/E4AjLpbV+/M="
Mar 04 02:47:03 volumio volumio[13731]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Mar 04 02:47:03 volumio sudo[14129]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Mar 04 02:47:03 volumio sudo[14129]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 02:47:03 volumio go-librespot[14120]: time="2026-03-04T02:47:03-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 02:47:03 volumio go-librespot[14120]: time="2026-03-04T02:47:03-06:00" level=debug msg="completed keyexchange"
Mar 04 02:47:03 volumio go-librespot[14120]: time="2026-03-04T02:47:03-06:00" level=debug msg="completed challenge"
Mar 04 02:47:03 volumio sudo[14129]: pam_unix(sudo:session): session closed for user root
Mar 04 02:47:03 volumio volumio[13731]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log
Mar 04 02:47:03 volumio go-librespot[14120]: time="2026-03-04T02:47:03-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 02:47:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 02:47:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 02:47:03 volumio sudo[14133]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log
Mar 04 02:47:03 volumio sudo[14133]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 02:47:03 volumio sudo[14133]: pam_unix(sudo:session): session closed for user root
Mar 04 02:47:03 volumio volumio[13731]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true
Mar 04 02:47:03 volumio sudo[14136]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite
Mar 04 02:47:03 volumio sudo[14136]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 02:47:03 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator...
Mar 04 02:47:03 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator.
Mar 04 02:47:03 volumio sudo[14136]: pam_unix(sudo:session): session closed for user root
Mar 04 02:47:03 volumio mpd[14077]: 2026-03-04T02:47:03 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Mar 04 02:47:04 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Mar 04 02:47:04 volumio sudo[14036]: pam_unix(sudo:session): session closed for user root
Mar 04 02:47:04 volumio sudo[13947]: pam_unix(sudo:session): session closed for user root
Mar 04 02:47:04 volumio sudo[13957]: pam_unix(sudo:session): session closed for user root
Mar 04 02:47:04 volumio volumio[13731]: error: MPD error: The expression evaluated to a falsy value:
Mar 04 02:47:04 volumio volumio[13731]:   assert.ok(self.idling)
Mar 04 02:47:04 volumio volumio[13731]: error: The expression evaluated to a falsy value:
Mar 04 02:47:04 volumio volumio[13731]:   assert.ok(self.idling)
Mar 04 02:47:04 volumio volumio[13731]: error: MPD error: The expression evaluated to a falsy value:
Mar 04 02:47:04 volumio volumio[13731]:   assert.ok(self.idling)
Mar 04 02:47:04 volumio volumio[13731]: error: The expression evaluated to a falsy value:
Mar 04 02:47:04 volumio volumio[13731]:   assert.ok(self.idling)
Mar 04 02:47:04 volumio volumio[13731]: error: updateQueue error: null
Mar 04 02:47:04 volumio volumio[13731]: info: MPD running with PID14077
Mar 04 02:47:04 volumio volumio[13731]:  ,establishing connection
Mar 04 02:47:04 volumio volumio[13731]: error: updateQueue error: null
Mar 04 02:47:04 volumio volumio[13731]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Mar 04 02:47:04 volumio sudo[14161]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Mar 04 02:47:04 volumio sudo[14161]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 02:47:04 volumio sudo[14161]: pam_unix(sudo:session): session closed for user root
Mar 04 02:47:04 volumio volumio[13731]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Mar 04 02:47:04 volumio sudo[14164]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Mar 04 02:47:04 volumio sudo[14164]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 02:47:04 volumio sudo[14164]: pam_unix(sudo:session): session closed for user root
Mar 04 02:47:05 volumio volumio[13731]: info: Initializing connection to go-librespot Websocket
Mar 04 02:47:05 volumio volumio[13731]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 02:47:05 volumio volumio[13731]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Mar 04 02:47:05 volumio sudo[14167]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Mar 04 02:47:05 volumio sudo[14167]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 02:47:05 volumio sudo[14167]: pam_unix(sudo:session): session closed for user root
Mar 04 02:47:05 volumio volumio[13731]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Mar 04 02:47:06 volumio sudo[14170]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Mar 04 02:47:06 volumio sudo[14170]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 02:47:06 volumio sudo[14170]: pam_unix(sudo:session): session closed for user root
Mar 04 02:47:06 volumio volumio[13731]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Mar 04 02:47:06 volumio sudo[14173]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Mar 04 02:47:06 volumio sudo[14173]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 02:47:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 222.
Mar 04 02:47:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:47:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:47:06 volumio go-librespot[14175]: go-librespot daemon starting...
Mar 04 02:47:06 volumio sudo[14173]: pam_unix(sudo:session): session closed for user root
Mar 04 02:47:06 volumio go-librespot[14176]: time="2026-03-04T02:47:06-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 02:47:06 volumio go-librespot[14176]: time="2026-03-04T02:47:06-06:00" level=debug msg="app state loaded"
Mar 04 02:47:06 volumio go-librespot[14176]: time="2026-03-04T02:47:06-06:00" level=debug msg="stored credentials not found"
Mar 04 02:47:06 volumio go-librespot[14176]: time="2026-03-04T02:47:06-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 02:47:06 volumio volumio[13731]: info: Completed starting Core Plugins
Mar 04 02:47:06 volumio volumio[13731]: info: -------------------------------------------
Mar 04 02:47:06 volumio volumio[13731]: info: -----    MyVolumio plugins startup     ----
Mar 04 02:47:06 volumio volumio[13731]: info: -------------------------------------------
Mar 04 02:47:06 volumio volumio[13731]: info: [MyVolumio PluginManager] Fetching plans data....
Mar 04 02:47:06 volumio go-librespot[14176]: time="2026-03-04T02:47:06-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Mar 04 02:47:06 volumio go-librespot[14176]: time="2026-03-04T02:47:06-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Mar 04 02:47:06 volumio go-librespot[14176]: time="2026-03-04T02:47:06-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Mar 04 02:47:06 volumio go-librespot[14176]: time="2026-03-04T02:47:06-06:00" level=info msg="zeroconf server listening on port 45555"
Mar 04 02:47:07 volumio go-librespot[14176]: time="2026-03-04T02:47:07-06:00" level=debug msg="obtained new client token: AAAeqBoHKWcyeTnyujqgrjPpMGZHkcG3cPzH3DkPf5muLH5LRc05o5e6wDEbuYmPqYVCtQzVfeX6WzJPeK2FJv5gTGMCXdUh4gusFC8wd4OUImS3IseXFVHXmMze/bjGsRMw9CkVbai705MJx35HV5rBRoIqvtzZqvAHWyvTy4tTMUFXohmnGzZt2w3W256JMMghTCW9Vk1XIXIwtF03rNwY4O3i0UDpxQo89wv8mECCxuT26fPMqWE="
Mar 04 02:47:07 volumio sudo[14184]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Mar 04 02:47:07 volumio sudo[14184]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 02:47:07 volumio sudo[14186]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Mar 04 02:47:07 volumio sudo[14186]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 02:47:07 volumio sudo[14188]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Mar 04 02:47:07 volumio sudo[14188]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 02:47:07 volumio go-librespot[14176]: time="2026-03-04T02:47:07-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 02:47:07 volumio go-librespot[14176]: time="2026-03-04T02:47:07-06:00" level=debug msg="completed keyexchange"
Mar 04 02:47:07 volumio go-librespot[14176]: time="2026-03-04T02:47:07-06:00" level=debug msg="completed challenge"
Mar 04 02:47:07 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service...
Mar 04 02:47:07 volumio systemd[1]: mpd_monitor.service: Deactivated successfully.
Mar 04 02:47:07 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service.
Mar 04 02:47:07 volumio go-librespot[14176]: time="2026-03-04T02:47:07-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 02:47:07 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service.
Mar 04 02:47:07 volumio sudo[14186]: pam_unix(sudo:session): session closed for user root
Mar 04 02:47:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 02:47:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 02:47:07 volumio mpd_monitor.sh[14192]: MPD Monitor Service: Starting MPD Monitor Service
Mar 04 02:47:07 volumio sudo[14188]: pam_unix(sudo:session): session closed for user root
Mar 04 02:47:07 volumio sudo[14184]: pam_unix(sudo:session): session closed for user root
Mar 04 02:47:07 volumio volumio[13731]: info: Successfully started MPD Monitor
Mar 04 02:47:07 volumio volumio[13731]: info: Successfully started MPD Monitor
Mar 04 02:47:07 volumio volumio[13731]: info: Successfully started MPD Monitor
Mar 04 02:47:08 volumio volumio[13731]: info: Initializing connection to go-librespot Websocket
Mar 04 02:47:08 volumio volumio[13731]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 02:47:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 223.
Mar 04 02:47:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:47:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:47:10 volumio go-librespot[14198]: go-librespot daemon starting...
Mar 04 02:47:10 volumio go-librespot[14199]: time="2026-03-04T02:47:10-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 02:47:10 volumio go-librespot[14199]: time="2026-03-04T02:47:10-06:00" level=debug msg="app state loaded"
Mar 04 02:47:10 volumio go-librespot[14199]: time="2026-03-04T02:47:10-06:00" level=debug msg="stored credentials not found"
Mar 04 02:47:10 volumio go-librespot[14199]: time="2026-03-04T02:47:10-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 02:47:10 volumio go-librespot[14199]: time="2026-03-04T02:47:10-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 02:47:10 volumio go-librespot[14199]: time="2026-03-04T02:47:10-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 02:47:10 volumio go-librespot[14199]: time="2026-03-04T02:47:10-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 02:47:10 volumio go-librespot[14199]: time="2026-03-04T02:47:10-06:00" level=info msg="zeroconf server listening on port 38859"
Mar 04 02:47:10 volumio go-librespot[14199]: time="2026-03-04T02:47:10-06:00" level=debug msg="obtained new client token: AADBuztDP1uXUUQKYEb5DaevBCSjuWeZHDQderKCbQMeJ2/1HxuZpkSub1PamyLSqgXJRnFCmK919qCU9MnTUFkm2e373Xq8bmR9T3WAh4zYiYNpm9XM7N3otoketlwbshtVEhO6fglIhPkQlSmg/IjhEeh5fyQ0N1UCmbUr/p/o07O0BshBOLrFAIyUwIlwmc5NSPSkdsK7fo5Xu1UpmefWxl56bnlv2rpX6VIMz8wD28FIrzpHyLJ5bw=="
Mar 04 02:47:10 volumio go-librespot[14199]: time="2026-03-04T02:47:10-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 02:47:11 volumio go-librespot[14199]: time="2026-03-04T02:47:11-06:00" level=debug msg="completed keyexchange"
Mar 04 02:47:11 volumio go-librespot[14199]: time="2026-03-04T02:47:11-06:00" level=debug msg="completed challenge"
Mar 04 02:47:11 volumio go-librespot[14199]: time="2026-03-04T02:47:11-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 02:47:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 02:47:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 02:47:11 volumio volumio[13731]: info: Initializing connection to go-librespot Websocket
Mar 04 02:47:11 volumio volumio[13731]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 02:47:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 224.
Mar 04 02:47:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:47:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:47:14 volumio go-librespot[14220]: go-librespot daemon starting...
Mar 04 02:47:14 volumio go-librespot[14221]: time="2026-03-04T02:47:14-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 02:47:14 volumio go-librespot[14221]: time="2026-03-04T02:47:14-06:00" level=debug msg="app state loaded"
Mar 04 02:47:14 volumio go-librespot[14221]: time="2026-03-04T02:47:14-06:00" level=debug msg="stored credentials not found"
Mar 04 02:47:14 volumio go-librespot[14221]: time="2026-03-04T02:47:14-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 02:47:14 volumio go-librespot[14221]: time="2026-03-04T02:47:14-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 02:47:14 volumio go-librespot[14221]: time="2026-03-04T02:47:14-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 02:47:14 volumio go-librespot[14221]: time="2026-03-04T02:47:14-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 02:47:14 volumio go-librespot[14221]: time="2026-03-04T02:47:14-06:00" level=info msg="zeroconf server listening on port 33451"
Mar 04 02:47:14 volumio go-librespot[14221]: time="2026-03-04T02:47:14-06:00" level=debug msg="obtained new client token: AAB/FX0Kspif4hRzKdiNHHdOY5Synr+CTUeBn+M3Z7s6bPgcGkkpLXxnspTpEuX4MxeLQH4sfbYuqfcv0LbVRaN/XB8huYOj8Qco5tQSQfLpIZCB93++KCsfu4VZjZC+l8PEwldUMIgY5UNRcF/MtJjkwXOjQqquzYX4ZOkZhNQghkk8VO8pMK30hs3JQfnyVzsKDuOgn58SkXLDXhF+ymCeWRjbgSZrGCO2DUYq/R1p+9WehlSbSczgVQ=="
Mar 04 02:47:14 volumio go-librespot[14221]: time="2026-03-04T02:47:14-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 02:47:14 volumio go-librespot[14221]: time="2026-03-04T02:47:14-06:00" level=debug msg="completed keyexchange"
Mar 04 02:47:14 volumio go-librespot[14221]: time="2026-03-04T02:47:14-06:00" level=debug msg="completed challenge"
Mar 04 02:47:14 volumio go-librespot[14221]: time="2026-03-04T02:47:14-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 02:47:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 02:47:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 02:47:14 volumio volumio[13731]: info: Initializing connection to go-librespot Websocket
Mar 04 02:47:14 volumio volumio[13731]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 02:47:14 volumio volumio[13731]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Mar 04 02:47:14 volumio volumio[13731]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Mar 04 02:47:14 volumio volumio[13731]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Mar 04 02:47:14 volumio volumio[13731]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Mar 04 02:47:14 volumio volumio[13731]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Mar 04 02:47:14 volumio volumio[13731]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Mar 04 02:47:14 volumio volumio[13731]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Mar 04 02:47:14 volumio volumio[13731]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Mar 04 02:47:14 volumio volumio[13731]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Mar 04 02:47:14 volumio volumio[13731]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Mar 04 02:47:14 volumio volumio[13731]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Mar 04 02:47:14 volumio volumio[13731]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Mar 04 02:47:14 volumio volumio[13731]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Mar 04 02:47:14 volumio volumio[13731]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Mar 04 02:47:14 volumio volumio[13731]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Mar 04 02:47:14 volumio volumio[13731]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Mar 04 02:47:14 volumio volumio[13731]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Mar 04 02:47:14 volumio volumio[13731]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Mar 04 02:47:14 volumio volumio[13731]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Mar 04 02:47:14 volumio volumio[13731]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Mar 04 02:47:14 volumio volumio[13731]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Mar 04 02:47:14 volumio volumio[13731]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Mar 04 02:47:14 volumio volumio[13731]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Mar 04 02:47:14 volumio volumio[13731]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Mar 04 02:47:14 volumio volumio[13731]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Mar 04 02:47:14 volumio volumio[13731]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Mar 04 02:47:14 volumio volumio[13731]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Mar 04 02:47:14 volumio volumio[13731]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Mar 04 02:47:14 volumio volumio[13731]: info: Adding plugin bluetooth to MyMusic Plugins
Mar 04 02:47:14 volumio volumio[13731]: info: Adding plugin multiroom to MyMusic Plugins
Mar 04 02:47:14 volumio volumio[13731]: info: Adding plugin metavolumio to MyMusic Plugins
Mar 04 02:47:14 volumio volumio[13731]: info: Adding plugin cd_controller to MyMusic Plugins
Mar 04 02:47:14 volumio volumio[13731]: info: Adding plugin qobuzconnect to MyMusic Plugins
Mar 04 02:47:14 volumio volumio[13731]: info: Adding plugin smart_inputs to MyMusic Plugins
Mar 04 02:47:14 volumio volumio[13731]: info: Adding plugin tidalconnect to MyMusic Plugins
Mar 04 02:47:14 volumio volumio[13731]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Mar 04 02:47:15 volumio volumio[13731]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Mar 04 02:47:15 volumio volumio[13731]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Mar 04 02:47:15 volumio volumio[13731]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 04 02:47:15 volumio volumio[13731]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 04 02:47:15 volumio volumio[13731]: info: Starting MyVolumio Remote Streaming Endpoints
Mar 04 02:47:15 volumio volumio[13731]: info: MyVolumio login type: Token
Mar 04 02:47:15 volumio volumio[13731]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Mar 04 02:47:15 volumio volumio[13731]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Mar 04 02:47:16 volumio volumio[13731]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Mar 04 02:47:16 volumio volumio[13731]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Mar 04 02:47:16 volumio volumio[13731]: info: Streaming services startup
Mar 04 02:47:16 volumio volumio[13731]: info: Starting Streaming Daemon
Mar 04 02:47:16 volumio sudo[14229]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Mar 04 02:47:16 volumio sudo[14229]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 02:47:16 volumio volumio[13731]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Mar 04 02:47:16 volumio sudo[14229]: pam_unix(sudo:session): session closed for user root
Mar 04 02:47:16 volumio volumio[13731]: error: Cannot start Volumio Streaming Daemon
Mar 04 02:47:16 volumio volumio[13731]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Mar 04 02:47:16 volumio volumio[13731]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Mar 04 02:47:17 volumio volumio[13731]: error: MyVolumio FAILED LOGIN: Invalid assertion format. 3 dot separated segments required.
Mar 04 02:47:17 volumio volumio[13731]: info: Initializing connection to go-librespot Websocket
Mar 04 02:47:17 volumio volumio[13731]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 02:47:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 225.
Mar 04 02:47:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:47:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:47:17 volumio go-librespot[14235]: go-librespot daemon starting...
Mar 04 02:47:17 volumio go-librespot[14236]: time="2026-03-04T02:47:17-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 02:47:17 volumio go-librespot[14236]: time="2026-03-04T02:47:17-06:00" level=debug msg="app state loaded"
Mar 04 02:47:17 volumio go-librespot[14236]: time="2026-03-04T02:47:17-06:00" level=debug msg="stored credentials not found"
Mar 04 02:47:17 volumio go-librespot[14236]: time="2026-03-04T02:47:17-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 02:47:18 volumio go-librespot[14236]: time="2026-03-04T02:47:18-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Mar 04 02:47:18 volumio go-librespot[14236]: time="2026-03-04T02:47:18-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Mar 04 02:47:18 volumio go-librespot[14236]: time="2026-03-04T02:47:18-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Mar 04 02:47:18 volumio go-librespot[14236]: time="2026-03-04T02:47:18-06:00" level=info msg="zeroconf server listening on port 44725"
Mar 04 02:47:18 volumio go-librespot[14236]: time="2026-03-04T02:47:18-06:00" level=debug msg="obtained new client token: AAAevnidUmWNdS3fu95AKscUAUyqNmxLfS/OOOW/y68U79kTiOFBGRFSG2dD6MNeeX5ESzWv9TZdetBXuLf0qWHw1FRyfeIIgmY6ONZ5V79+ICmV85j5u0aglfRxoPox2kdo/ScIS7GEZEdcGkHiImpmv2BNZ6X/KTaqW/yyo+lEZkyRgHBiy3YPNhYZatKrQIz//Hr14I362MTtQ21WZ3dsubtCvm3w3rGO3gHunsLw/X8CV3kWrgI="
Mar 04 02:47:18 volumio go-librespot[14236]: time="2026-03-04T02:47:18-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 02:47:18 volumio go-librespot[14236]: time="2026-03-04T02:47:18-06:00" level=debug msg="completed keyexchange"
Mar 04 02:47:18 volumio go-librespot[14236]: time="2026-03-04T02:47:18-06:00" level=debug msg="completed challenge"
Mar 04 02:47:18 volumio go-librespot[14236]: time="2026-03-04T02:47:18-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 02:47:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 02:47:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 02:47:20 volumio volumio[13731]: info: Initializing connection to go-librespot Websocket
Mar 04 02:47:20 volumio volumio[13731]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 02:47:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 226.
Mar 04 02:47:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:47:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:47:21 volumio go-librespot[14243]: go-librespot daemon starting...
Mar 04 02:47:21 volumio go-librespot[14244]: time="2026-03-04T02:47:21-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 02:47:21 volumio go-librespot[14244]: time="2026-03-04T02:47:21-06:00" level=debug msg="app state loaded"
Mar 04 02:47:21 volumio go-librespot[14244]: time="2026-03-04T02:47:21-06:00" level=debug msg="stored credentials not found"
Mar 04 02:47:21 volumio go-librespot[14244]: time="2026-03-04T02:47:21-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 02:47:21 volumio go-librespot[14244]: time="2026-03-04T02:47:21-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 02:47:21 volumio go-librespot[14244]: time="2026-03-04T02:47:21-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 02:47:21 volumio go-librespot[14244]: time="2026-03-04T02:47:21-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 02:47:21 volumio go-librespot[14244]: time="2026-03-04T02:47:21-06:00" level=info msg="zeroconf server listening on port 35367"
Mar 04 02:47:22 volumio go-librespot[14244]: time="2026-03-04T02:47:22-06:00" level=debug msg="obtained new client token: AAA+gjvTW6n+TvmTo88JVWO+q+KL8dQdx71ahSKTfaIqGdQgM8/qdNG5nQfbuYizMu5I01EaqVh6oJhtKJc2jUYf02DD+rAlkYU98sMtmu7eegzI3kE+VFbAC1E0y6ReWB29xZsdU7aNtUD0unDACWeKQDMYl+H3G1jn9DYx6i6re80HkraiDrmn7dGCXq9j6Gc9Wev2eq3NcwL6K7pq+6AaEXcSOW2J22RwsYHSaUqv7d003OkYNNU="
Mar 04 02:47:22 volumio go-librespot[14244]: time="2026-03-04T02:47:22-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 02:47:22 volumio go-librespot[14244]: time="2026-03-04T02:47:22-06:00" level=debug msg="completed keyexchange"
Mar 04 02:47:22 volumio go-librespot[14244]: time="2026-03-04T02:47:22-06:00" level=debug msg="completed challenge"
Mar 04 02:47:22 volumio go-librespot[14244]: time="2026-03-04T02:47:22-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 02:47:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 02:47:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 02:47:23 volumio volumio[13731]: info: Initializing connection to go-librespot Websocket
Mar 04 02:47:23 volumio volumio[13731]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 02:47:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 227.
Mar 04 02:47:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:47:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:47:25 volumio go-librespot[14265]: go-librespot daemon starting...
Mar 04 02:47:25 volumio go-librespot[14266]: time="2026-03-04T02:47:25-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 02:47:25 volumio go-librespot[14266]: time="2026-03-04T02:47:25-06:00" level=debug msg="app state loaded"
Mar 04 02:47:25 volumio go-librespot[14266]: time="2026-03-04T02:47:25-06:00" level=debug msg="stored credentials not found"
Mar 04 02:47:25 volumio go-librespot[14266]: time="2026-03-04T02:47:25-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 02:47:25 volumio go-librespot[14266]: time="2026-03-04T02:47:25-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Mar 04 02:47:25 volumio go-librespot[14266]: time="2026-03-04T02:47:25-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Mar 04 02:47:25 volumio go-librespot[14266]: time="2026-03-04T02:47:25-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Mar 04 02:47:25 volumio go-librespot[14266]: time="2026-03-04T02:47:25-06:00" level=info msg="zeroconf server listening on port 46299"
Mar 04 02:47:25 volumio go-librespot[14266]: time="2026-03-04T02:47:25-06:00" level=debug msg="obtained new client token: AAD74KgkqG9loKsYj/tK+U6ai1i5RfH4e0n5Gb8mxjCGSsi7tfZzBIXQwxUR004S9sbLOWI/rb3HEnuAPiNWCU2W+3Gtka+SU0Q15BeFYQ7Xiqkj+6wwypkikGN7MZozjKnE9ypHqgRBTJQuulc0nzYUh8yBbK9TDmu0/Lg4gDWyopoiDYj6ItXzZvW0kcNkhtP0k/S9Hg1vQnteGqqHmKRIsGNI99fRzmoGBUa5Ty7JP4K3oVPwMRJ98Q=="
Mar 04 02:47:25 volumio go-librespot[14266]: time="2026-03-04T02:47:25-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 02:47:25 volumio go-librespot[14266]: time="2026-03-04T02:47:25-06:00" level=debug msg="completed keyexchange"
Mar 04 02:47:25 volumio go-librespot[14266]: time="2026-03-04T02:47:25-06:00" level=debug msg="completed challenge"
Mar 04 02:47:25 volumio go-librespot[14266]: time="2026-03-04T02:47:25-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 02:47:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 02:47:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 02:47:26 volumio volumio[13731]: info: Initializing connection to go-librespot Websocket
Mar 04 02:47:26 volumio volumio[13731]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 02:47:28 volumio volumio[13731]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Mar 04 02:47:28 volumio volumio[13731]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 04 02:47:28 volumio volumio[13731]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Mar 04 02:47:28 volumio volumio-remote-updater[13697]: Test mode disabled
Mar 04 02:47:28 volumio volumio-remote-updater[13697]: Alpha mode disabled
Mar 04 02:47:28 volumio volumio-remote-updater[13697]: Alpha legacy test mode disabled
Mar 04 02:47:28 volumio volumio[13731]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Mar 04 02:47:28 volumio volumio[13731]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"FIXES
\n\nFix for CPU utilization spike
\nFix for triggerhappy input permission
\n
\nNEW ADDITIONS
\n\nAdd BLE onboarding plugin
\nEnable vc4-kms-v3d for all compatible RPi models
\nUpdate Tidal SDK
\n\n","title":"Update v4.096","updateavailable":true}
Mar 04 02:47:28 volumio volumio[13731]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Mar 04 02:47:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 228.
Mar 04 02:47:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:47:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:47:29 volumio go-librespot[14280]: go-librespot daemon starting...
Mar 04 02:47:29 volumio go-librespot[14281]: time="2026-03-04T02:47:29-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 02:47:29 volumio go-librespot[14281]: time="2026-03-04T02:47:29-06:00" level=debug msg="app state loaded"
Mar 04 02:47:29 volumio go-librespot[14281]: time="2026-03-04T02:47:29-06:00" level=debug msg="stored credentials not found"
Mar 04 02:47:29 volumio go-librespot[14281]: time="2026-03-04T02:47:29-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 02:47:29 volumio go-librespot[14281]: time="2026-03-04T02:47:29-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 02:47:29 volumio go-librespot[14281]: time="2026-03-04T02:47:29-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 02:47:29 volumio go-librespot[14281]: time="2026-03-04T02:47:29-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 02:47:29 volumio go-librespot[14281]: time="2026-03-04T02:47:29-06:00" level=info msg="zeroconf server listening on port 41121"
Mar 04 02:47:29 volumio go-librespot[14281]: time="2026-03-04T02:47:29-06:00" level=debug msg="obtained new client token: AABgHPiA5j46gcuNqqU32v/wHLSbwttP/31uTa04wxHghxk4L6IL1oyD7GWPkwFYz0QE2P3dtfThM2x4seh7JGTiU7QTxT7Az5VLrsuIZgoVnKZuav3Pbl6t+3J/XXpXmM2DcRagmjgYxpb/1sgV/kYWuo0M7sJl2s0oPV2OwAZNW3SywFVQvAwqI7nKhQU79U7SHnkX4gN06qT3J4sajBge8vVSXJ2YZwISyRgg2IYAVOevoLdHQ3LgPQ=="
Mar 04 02:47:29 volumio go-librespot[14281]: time="2026-03-04T02:47:29-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 02:47:29 volumio go-librespot[14281]: time="2026-03-04T02:47:29-06:00" level=debug msg="completed keyexchange"
Mar 04 02:47:29 volumio go-librespot[14281]: time="2026-03-04T02:47:29-06:00" level=debug msg="completed challenge"
Mar 04 02:47:29 volumio go-librespot[14281]: time="2026-03-04T02:47:29-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 02:47:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 02:47:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 02:47:29 volumio volumio[13731]: info: Initializing connection to go-librespot Websocket
Mar 04 02:47:29 volumio volumio[13731]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 02:47:30 volumio volumio[13731]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Mar 04 02:47:30 volumio volumio[13731]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4
Mar 04 02:47:30 volumio volumio[13731]: info: CoreCommandRouter::volumioGetState
Mar 04 02:47:30 volumio volumio[13731]: info: CorePlayQueue::getTrack 0
Mar 04 02:47:32 volumio volumio[13731]: info: Initializing connection to go-librespot Websocket
Mar 04 02:47:32 volumio volumio[13731]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 02:47:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 229.
Mar 04 02:47:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:47:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:47:32 volumio go-librespot[14289]: go-librespot daemon starting...
Mar 04 02:47:32 volumio go-librespot[14290]: time="2026-03-04T02:47:32-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 02:47:32 volumio go-librespot[14290]: time="2026-03-04T02:47:32-06:00" level=debug msg="app state loaded"
Mar 04 02:47:32 volumio go-librespot[14290]: time="2026-03-04T02:47:32-06:00" level=debug msg="stored credentials not found"
Mar 04 02:47:32 volumio go-librespot[14290]: time="2026-03-04T02:47:32-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 02:47:33 volumio go-librespot[14290]: time="2026-03-04T02:47:33-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 02:47:33 volumio go-librespot[14290]: time="2026-03-04T02:47:33-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 02:47:33 volumio go-librespot[14290]: time="2026-03-04T02:47:33-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 02:47:33 volumio go-librespot[14290]: time="2026-03-04T02:47:33-06:00" level=info msg="zeroconf server listening on port 43225"
Mar 04 02:47:33 volumio go-librespot[14290]: time="2026-03-04T02:47:33-06:00" level=debug msg="obtained new client token: AACH594Hbs//WmO6K2pto3BoSx0vGVHThUZ8s5MKN+K8JVfM6ir6WmWwPrSRpaS9o6avIdQWOhR10M5W9LGQBivihPONY9WacIpXz4Vzj6tee5lcVLhtK0QSg0lGHnY+7SEZqh7fe2K4Thbq7OE4dZy8l82moxCVr3gcbHxu/uUDQltsW7qO9fNtwcBgjaCUkUWQvklbYGuTn/lL1uj5fhMaw0fwygwgxJy5i/T78qjm5xTsrOyUSMY="
Mar 04 02:47:33 volumio go-librespot[14290]: time="2026-03-04T02:47:33-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 02:47:33 volumio go-librespot[14290]: time="2026-03-04T02:47:33-06:00" level=debug msg="completed keyexchange"
Mar 04 02:47:33 volumio go-librespot[14290]: time="2026-03-04T02:47:33-06:00" level=debug msg="completed challenge"
Mar 04 02:47:33 volumio go-librespot[14290]: time="2026-03-04T02:47:33-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 02:47:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 02:47:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 02:47:35 volumio volumio[13731]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 02:47:35 volumio volumio[13731]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 02:47:35 volumio volumio[13731]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam
Mar 04 02:47:35 volumio volumio[13731]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
Mar 04 02:47:35 volumio volumio[13731]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Mar 04 02:47:35 volumio volumio[13731]: info: CoreCommandRouter::volumioGetBrowseSources
Mar 04 02:47:35 volumio volumio[13731]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Mar 04 02:47:35 volumio volumio[13731]: info: Initializing connection to go-librespot Websocket
Mar 04 02:47:35 volumio volumio[13731]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 02:47:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 230.
Mar 04 02:47:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:47:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:47:36 volumio go-librespot[14311]: go-librespot daemon starting...
Mar 04 02:47:36 volumio go-librespot[14312]: time="2026-03-04T02:47:36-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 02:47:36 volumio go-librespot[14312]: time="2026-03-04T02:47:36-06:00" level=debug msg="app state loaded"
Mar 04 02:47:36 volumio go-librespot[14312]: time="2026-03-04T02:47:36-06:00" level=debug msg="stored credentials not found"
Mar 04 02:47:36 volumio go-librespot[14312]: time="2026-03-04T02:47:36-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 02:47:36 volumio volumio[13731]: error: MyVolumio Plugin failed to authenticate in a timely fashion
Mar 04 02:47:36 volumio volumio[13731]: info: Completed starting MyVolumio Plugin
Mar 04 02:47:36 volumio volumio[13731]:  [Metrics]  CommandRouter:  55s 180.34ms 
Mar 04 02:47:36 volumio volumio[13731]: info: CoreCommandRouter::volumiosetStartupVolume
Mar 04 02:47:36 volumio volumio[13731]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 02:47:36 volumio volumio[13731]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 04 02:47:36 volumio volumio[13731]: info: CoreCommandRouter::Close All Modals sent
Mar 04 02:47:36 volumio volumio[13731]: info: CoreCommandRouter::Close All Modals sent
Mar 04 02:47:36 volumio go-librespot[14312]: time="2026-03-04T02:47:36-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 02:47:36 volumio go-librespot[14312]: time="2026-03-04T02:47:36-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 02:47:36 volumio go-librespot[14312]: time="2026-03-04T02:47:36-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 02:47:36 volumio go-librespot[14312]: time="2026-03-04T02:47:36-06:00" level=info msg="zeroconf server listening on port 34471"
Mar 04 02:47:37 volumio go-librespot[14312]: time="2026-03-04T02:47:37-06:00" level=debug msg="obtained new client token: AAC9pFEqCPlMIiMDV8aySJcBfdiMa/LE0+Uwc2RjhbI6nb14tJFEcW8NrJf9pOEGDma59hP5IW+4VYxw95GGMyK5O/rmZIjmnbRRtZvXYkOYK4gCJkhhC0+af/wEJLMXIFgEuW4Dj8Y9wt0yt2e+MO1j34HtDquXWDQOWub4VOQoEDOLvm6vcqZ9JwHZYsuE9fY7yW2X4ZY99WvscNuQgyjSBET7oIiOzSpPaZTGjfb8kzaNfOKJjog="
Mar 04 02:47:37 volumio go-librespot[14312]: time="2026-03-04T02:47:37-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 02:47:37 volumio go-librespot[14312]: time="2026-03-04T02:47:37-06:00" level=debug msg="completed keyexchange"
Mar 04 02:47:37 volumio go-librespot[14312]: time="2026-03-04T02:47:37-06:00" level=debug msg="completed challenge"
Mar 04 02:47:37 volumio go-librespot[14312]: time="2026-03-04T02:47:37-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 02:47:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 02:47:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 02:47:37 volumio volumio[13731]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable
Mar 04 02:47:37 volumio volumio[13731]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
Mar 04 02:47:37 volumio volumio[13731]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect
Mar 04 02:47:38 volumio volumio[13731]: info: Initializing connection to go-librespot Websocket
Mar 04 02:47:38 volumio volumio[13731]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 02:47:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 231.
Mar 04 02:47:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:47:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:47:40 volumio go-librespot[14326]: go-librespot daemon starting...
Mar 04 02:47:40 volumio go-librespot[14327]: time="2026-03-04T02:47:40-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 02:47:40 volumio go-librespot[14327]: time="2026-03-04T02:47:40-06:00" level=debug msg="app state loaded"
Mar 04 02:47:40 volumio go-librespot[14327]: time="2026-03-04T02:47:40-06:00" level=debug msg="stored credentials not found"
Mar 04 02:47:40 volumio go-librespot[14327]: time="2026-03-04T02:47:40-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 02:47:40 volumio go-librespot[14327]: time="2026-03-04T02:47:40-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 02:47:40 volumio go-librespot[14327]: time="2026-03-04T02:47:40-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 02:47:40 volumio go-librespot[14327]: time="2026-03-04T02:47:40-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 02:47:40 volumio go-librespot[14327]: time="2026-03-04T02:47:40-06:00" level=info msg="zeroconf server listening on port 37225"
Mar 04 02:47:40 volumio go-librespot[14327]: time="2026-03-04T02:47:40-06:00" level=debug msg="obtained new client token: AAAyrEI89vdOLYvwY8WYmLQbM3AeghMasqDistqNh1lgO79BBqs6J5jO/cYp2QEsTzQmUSerI9lX73PvqcJwj0xOcfJ9d+W5jc9ic5JIAfWaFogHZnVc/LCQUZcLgenANFJQYhSWcER73NomGj2ptu1/w/JkfQ76VijLKDpnlkZGMYnXvt1Fx7YGpbcWSa6Gg+WKKTkdNQxNDwiTx4oFLSFoYQQqrJZEJLAQTA0MCFm0E6nOwfXareaivA=="
Mar 04 02:47:40 volumio go-librespot[14327]: time="2026-03-04T02:47:40-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 02:47:40 volumio go-librespot[14327]: time="2026-03-04T02:47:40-06:00" level=debug msg="completed keyexchange"
Mar 04 02:47:40 volumio go-librespot[14327]: time="2026-03-04T02:47:40-06:00" level=debug msg="completed challenge"
Mar 04 02:47:40 volumio go-librespot[14327]: time="2026-03-04T02:47:40-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 02:47:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 02:47:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 02:47:41 volumio volumio[13731]: info: Initializing connection to go-librespot Websocket
Mar 04 02:47:41 volumio volumio[13731]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 02:47:43 volumio volumio[13731]: info: BOOT COMPLETED
Mar 04 02:47:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 232.
Mar 04 02:47:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:47:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:47:44 volumio go-librespot[14348]: go-librespot daemon starting...
Mar 04 02:47:44 volumio go-librespot[14349]: time="2026-03-04T02:47:44-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 02:47:44 volumio go-librespot[14349]: time="2026-03-04T02:47:44-06:00" level=debug msg="app state loaded"
Mar 04 02:47:44 volumio go-librespot[14349]: time="2026-03-04T02:47:44-06:00" level=debug msg="stored credentials not found"
Mar 04 02:47:44 volumio go-librespot[14349]: time="2026-03-04T02:47:44-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 02:47:44 volumio go-librespot[14349]: time="2026-03-04T02:47:44-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 02:47:44 volumio go-librespot[14349]: time="2026-03-04T02:47:44-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 02:47:44 volumio go-librespot[14349]: time="2026-03-04T02:47:44-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 02:47:44 volumio go-librespot[14349]: time="2026-03-04T02:47:44-06:00" level=info msg="zeroconf server listening on port 43453"
Mar 04 02:47:44 volumio go-librespot[14349]: time="2026-03-04T02:47:44-06:00" level=debug msg="obtained new client token: AABDKE18zeLUYI3XxE/DoZ/vwJJNRS+mtCdCYbN3SZRlL1w71s5v1aBw9Z+RFgTIujrKF26ta7qYf0a4cNUbgLSneYgVO3/Rz59YLyLOR0wRkKJj+YPlS7nJEGRxH2twUdBG0Su/9I6Q+5n4nyh0s/mA0K0HkujwhOmw2Ti81xinEzfwTQTw/vVfaAyc06Cm34BX+vB9CBodAXHeCYLdMyz3I3jOodFAxnKpwVXs+5nD2OPxuWAUp/U1Rw=="
Mar 04 02:47:44 volumio go-librespot[14349]: time="2026-03-04T02:47:44-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 02:47:44 volumio go-librespot[14349]: time="2026-03-04T02:47:44-06:00" level=debug msg="completed keyexchange"
Mar 04 02:47:44 volumio go-librespot[14349]: time="2026-03-04T02:47:44-06:00" level=debug msg="completed challenge"
Mar 04 02:47:44 volumio go-librespot[14349]: time="2026-03-04T02:47:44-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 02:47:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 02:47:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 02:47:44 volumio volumio[13731]: info: Initializing connection to go-librespot Websocket
Mar 04 02:47:44 volumio volumio[13731]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 02:47:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 233.
Mar 04 02:47:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:47:47 volumio volumio[13731]: info: Initializing connection to go-librespot Websocket
Mar 04 02:47:47 volumio volumio[13731]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 02:47:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:47:47 volumio go-librespot[14360]: go-librespot daemon starting...
Mar 04 02:47:47 volumio go-librespot[14361]: time="2026-03-04T02:47:47-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 02:47:47 volumio go-librespot[14361]: time="2026-03-04T02:47:47-06:00" level=debug msg="app state loaded"
Mar 04 02:47:47 volumio go-librespot[14361]: time="2026-03-04T02:47:47-06:00" level=debug msg="stored credentials not found"
Mar 04 02:47:47 volumio go-librespot[14361]: time="2026-03-04T02:47:47-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 02:47:48 volumio go-librespot[14361]: time="2026-03-04T02:47:48-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 02:47:48 volumio go-librespot[14361]: time="2026-03-04T02:47:48-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 02:47:48 volumio go-librespot[14361]: time="2026-03-04T02:47:48-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 02:47:48 volumio go-librespot[14361]: time="2026-03-04T02:47:48-06:00" level=info msg="zeroconf server listening on port 43043"
Mar 04 02:47:48 volumio go-librespot[14361]: time="2026-03-04T02:47:48-06:00" level=debug msg="obtained new client token: AADfBrCw6wX4+5DFcLh+VscVWG4T579YXx1c5Gc2ufarKtRdXh/YbORSqagD1e5gdyhOmjhUwWHujoM9bJCEPl/xqMeQ2Y5qRysZgAvxqQoEfo/yKz0BjVnwkLATB4gwZxg/zBOynHZmEiXHDiaPvxrwJZltTCPGoUm16iU7eUIAUNCcOey5PBYCwZeZ4hOqy+0KEOKFfKZkPxhwWDZDJqtutAW0rJgfwOCCOnMbHn3LCu4L6LjsY0mrYg=="
Mar 04 02:47:48 volumio go-librespot[14361]: time="2026-03-04T02:47:48-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 02:47:48 volumio go-librespot[14361]: time="2026-03-04T02:47:48-06:00" level=debug msg="completed keyexchange"
Mar 04 02:47:48 volumio go-librespot[14361]: time="2026-03-04T02:47:48-06:00" level=debug msg="completed challenge"
Mar 04 02:47:48 volumio go-librespot[14361]: time="2026-03-04T02:47:48-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 02:47:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 02:47:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 02:47:50 volumio volumio[13731]: info: Initializing connection to go-librespot Websocket
Mar 04 02:47:50 volumio volumio[13731]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 02:47:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 234.
Mar 04 02:47:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:47:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:47:51 volumio go-librespot[14369]: go-librespot daemon starting...
Mar 04 02:47:51 volumio go-librespot[14370]: time="2026-03-04T02:47:51-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 02:47:51 volumio go-librespot[14370]: time="2026-03-04T02:47:51-06:00" level=debug msg="app state loaded"
Mar 04 02:47:51 volumio go-librespot[14370]: time="2026-03-04T02:47:51-06:00" level=debug msg="stored credentials not found"
Mar 04 02:47:51 volumio go-librespot[14370]: time="2026-03-04T02:47:51-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 02:47:51 volumio go-librespot[14370]: time="2026-03-04T02:47:51-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 02:47:51 volumio go-librespot[14370]: time="2026-03-04T02:47:51-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 02:47:51 volumio go-librespot[14370]: time="2026-03-04T02:47:51-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 02:47:51 volumio go-librespot[14370]: time="2026-03-04T02:47:51-06:00" level=info msg="zeroconf server listening on port 43255"
Mar 04 02:47:52 volumio go-librespot[14370]: time="2026-03-04T02:47:52-06:00" level=debug msg="obtained new client token: AAAKmHU6VZxQ7HS/lFN9ysyY0oa2gXUWHZmyl+Q/s0l1K/ozRsX1NNx2xByXQkTSXzE0FHOFNh/CeB7CDN1y0Nc8AHLHGSxU5fU5Z7PDu59Ohj719Pxuc72jZ5oGPxKRWlhATJYak8PkE5Khkq3iLVf0UAXUwwcxYiIxiv0g81M252NkezEuCzErFjxoeWJ1ajNY03ZaYbLCveVKmJiHLPCL5gP8m4zlDHZfw9EitbeiH5o1SMuqCSs="
Mar 04 02:47:52 volumio go-librespot[14370]: time="2026-03-04T02:47:52-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 02:47:52 volumio go-librespot[14370]: time="2026-03-04T02:47:52-06:00" level=debug msg="completed keyexchange"
Mar 04 02:47:52 volumio go-librespot[14370]: time="2026-03-04T02:47:52-06:00" level=debug msg="completed challenge"
Mar 04 02:47:52 volumio go-librespot[14370]: time="2026-03-04T02:47:52-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 02:47:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 02:47:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 02:47:53 volumio volumio[13731]: info: Initializing connection to go-librespot Websocket
Mar 04 02:47:53 volumio volumio[13731]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 02:47:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 235.
Mar 04 02:47:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:47:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:47:55 volumio go-librespot[14392]: go-librespot daemon starting...
Mar 04 02:47:55 volumio go-librespot[14393]: time="2026-03-04T02:47:55-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 02:47:55 volumio go-librespot[14393]: time="2026-03-04T02:47:55-06:00" level=debug msg="app state loaded"
Mar 04 02:47:55 volumio go-librespot[14393]: time="2026-03-04T02:47:55-06:00" level=debug msg="stored credentials not found"
Mar 04 02:47:55 volumio go-librespot[14393]: time="2026-03-04T02:47:55-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 02:47:55 volumio go-librespot[14393]: time="2026-03-04T02:47:55-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 02:47:55 volumio go-librespot[14393]: time="2026-03-04T02:47:55-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 02:47:55 volumio go-librespot[14393]: time="2026-03-04T02:47:55-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 02:47:55 volumio go-librespot[14393]: time="2026-03-04T02:47:55-06:00" level=info msg="zeroconf server listening on port 38153"
Mar 04 02:47:55 volumio go-librespot[14393]: time="2026-03-04T02:47:55-06:00" level=debug msg="obtained new client token: AABNNgvnL/pGsO1JVuMRsliVyEHPorSgbo4rf73TkQ4z/qSXjOaBcQm/SKHRf4mVVi0PX1Q1zrfQYKQ8irw2mhSrCjP0XZ+anDIcgRvp/mO3/K8piKy+GWdgo6eopTOWaFJ1ZE00UZ8Zfrsrm3SPIhm84pZbaWeRE1jiQdCqz+c5TX+N7Dl2PUs+JQ4QfO9lCSqPwWaSNnqv3Xtmk0KaskAj5tvPCivFfg5BV9FT4lzNF1wfOKjF2Ex4Bw=="
Mar 04 02:47:55 volumio go-librespot[14393]: time="2026-03-04T02:47:55-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 02:47:55 volumio go-librespot[14393]: time="2026-03-04T02:47:55-06:00" level=debug msg="completed keyexchange"
Mar 04 02:47:55 volumio go-librespot[14393]: time="2026-03-04T02:47:55-06:00" level=debug msg="completed challenge"
Mar 04 02:47:55 volumio go-librespot[14393]: time="2026-03-04T02:47:55-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 02:47:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 02:47:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 02:47:56 volumio volumio[13731]: info: Initializing connection to go-librespot Websocket
Mar 04 02:47:56 volumio volumio[13731]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 02:47:58 volumio volumio[13731]: info: UPDATER: Scheduling automatic update
Mar 04 02:47:58 volumio volumio[13731]: info: CoreCommandRouter::executeOnPlugin: system , getAutoUpdateWindowStartTime
Mar 04 02:47:58 volumio volumio[13731]: info: CoreCommandRouter::executeOnPlugin: system , getAutoUpdateWindowStopTime
Mar 04 02:47:58 volumio volumio[13731]: info: UPDATER: Auto update will take place at: Thu Mar 05 2026 03:24:50 GMT-0600 (Central Standard Time)
Mar 04 02:47:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 236.
Mar 04 02:47:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:47:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:47:59 volumio go-librespot[14400]: go-librespot daemon starting...
Mar 04 02:47:59 volumio go-librespot[14401]: time="2026-03-04T02:47:59-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 02:47:59 volumio go-librespot[14401]: time="2026-03-04T02:47:59-06:00" level=debug msg="app state loaded"
Mar 04 02:47:59 volumio go-librespot[14401]: time="2026-03-04T02:47:59-06:00" level=debug msg="stored credentials not found"
Mar 04 02:47:59 volumio go-librespot[14401]: time="2026-03-04T02:47:59-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 02:47:59 volumio go-librespot[14401]: time="2026-03-04T02:47:59-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 02:47:59 volumio go-librespot[14401]: time="2026-03-04T02:47:59-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 02:47:59 volumio go-librespot[14401]: time="2026-03-04T02:47:59-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 02:47:59 volumio go-librespot[14401]: time="2026-03-04T02:47:59-06:00" level=info msg="zeroconf server listening on port 34693"
Mar 04 02:47:59 volumio go-librespot[14401]: time="2026-03-04T02:47:59-06:00" level=debug msg="obtained new client token: AADdmI3XI9EZpymVfcWc6jYwb2lZM9FL7QdIg2eqGdT1PaCRJy4pcSW1BYVA8RbpK52a7Sv/YCLceOS1RTxc6o+RvX9/cZgSxGvHT7ohi12DyxP32s70OMhsP263yeLV5cHd+q99vgwk7K2H7kPG8sdks48z5OxPdk+sN2wbwHD/3A2JSap9owb1ZGDgUrTeq1p4r3cTK6qDZbPIT/Tspp/ta+tPCsCAgZWQ+ddaQY1J6Fj+breYW1C8hA=="
Mar 04 02:47:59 volumio go-librespot[14401]: time="2026-03-04T02:47:59-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 02:47:59 volumio go-librespot[14401]: time="2026-03-04T02:47:59-06:00" level=debug msg="completed keyexchange"
Mar 04 02:47:59 volumio go-librespot[14401]: time="2026-03-04T02:47:59-06:00" level=debug msg="completed challenge"
Mar 04 02:47:59 volumio go-librespot[14401]: time="2026-03-04T02:47:59-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 02:47:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 02:47:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 02:47:59 volumio volumio[13731]: info: Initializing connection to go-librespot Websocket
Mar 04 02:47:59 volumio volumio[13731]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 02:48:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 237.
Mar 04 02:48:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:48:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:48:02 volumio go-librespot[14408]: go-librespot daemon starting...
Mar 04 02:48:02 volumio volumio[13731]: info: Initializing connection to go-librespot Websocket
Mar 04 02:48:02 volumio volumio[13731]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 02:48:02 volumio go-librespot[14409]: time="2026-03-04T02:48:02-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 02:48:02 volumio go-librespot[14409]: time="2026-03-04T02:48:02-06:00" level=debug msg="app state loaded"
Mar 04 02:48:02 volumio go-librespot[14409]: time="2026-03-04T02:48:02-06:00" level=debug msg="stored credentials not found"
Mar 04 02:48:02 volumio go-librespot[14409]: time="2026-03-04T02:48:02-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 02:48:03 volumio go-librespot[14409]: time="2026-03-04T02:48:03-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 02:48:03 volumio go-librespot[14409]: time="2026-03-04T02:48:03-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 02:48:03 volumio go-librespot[14409]: time="2026-03-04T02:48:03-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 02:48:03 volumio go-librespot[14409]: time="2026-03-04T02:48:03-06:00" level=info msg="zeroconf server listening on port 41751"
Mar 04 02:48:03 volumio go-librespot[14409]: time="2026-03-04T02:48:03-06:00" level=debug msg="obtained new client token: AABcCRZqp2uX8pCxix5FrBkZRZi3dyog4cSTxCu1w4HBstX1yincHHzUgb/cELVkDRJ98wUlHzAcahMPNFMFViQUHlNHbdIu31bZyOq0W6Sk7G7KAe/P2xCWzQKTsZ7qVjgdpiEJ7axOfIWQ1n8OovOSpHh3S8a1tznYIdp10ubb6ZK95TM9uMt5/LV26PS1zdH16rWSYKXzRoOea3mCdFYopQuPvSHrCSqMfZGygSFP2wFCQPpms1zEpA=="
Mar 04 02:48:03 volumio go-librespot[14409]: time="2026-03-04T02:48:03-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 02:48:03 volumio go-librespot[14409]: time="2026-03-04T02:48:03-06:00" level=debug msg="completed keyexchange"
Mar 04 02:48:03 volumio go-librespot[14409]: time="2026-03-04T02:48:03-06:00" level=debug msg="completed challenge"
Mar 04 02:48:03 volumio go-librespot[14409]: time="2026-03-04T02:48:03-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 02:48:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 02:48:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 02:48:05 volumio volumio[13731]: info: Initializing connection to go-librespot Websocket
Mar 04 02:48:05 volumio volumio[13731]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 02:48:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 238.
Mar 04 02:48:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:48:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:48:06 volumio go-librespot[14430]: go-librespot daemon starting...
Mar 04 02:48:06 volumio go-librespot[14431]: time="2026-03-04T02:48:06-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 02:48:06 volumio go-librespot[14431]: time="2026-03-04T02:48:06-06:00" level=debug msg="app state loaded"
Mar 04 02:48:06 volumio go-librespot[14431]: time="2026-03-04T02:48:06-06:00" level=debug msg="stored credentials not found"
Mar 04 02:48:06 volumio go-librespot[14431]: time="2026-03-04T02:48:06-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 02:48:06 volumio go-librespot[14431]: time="2026-03-04T02:48:06-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 02:48:06 volumio go-librespot[14431]: time="2026-03-04T02:48:06-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 02:48:06 volumio go-librespot[14431]: time="2026-03-04T02:48:06-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 02:48:06 volumio go-librespot[14431]: time="2026-03-04T02:48:06-06:00" level=info msg="zeroconf server listening on port 35789"
Mar 04 02:48:07 volumio go-librespot[14431]: time="2026-03-04T02:48:07-06:00" level=debug msg="obtained new client token: AAAc4Y7qVKTo8YeEseXRd3DhO/9Rh+VbyNfWV593DX+tYGnBgo/VTfYSWuVLoSuudt4zSxkKdbmCtce7xKhEdk6PYB8REsOMSi5CFu0Zq5aB6YHS8iJPq2S3JOOUb5vGnBgqyKsk4p1y5I/CFAoSz+ITgZltE8m6tGyS5usAYws6kLR/XUzw4CYamOh12sLg/A0//sK0yJd6SPWgocUOepZsxru1yH4yNwasZ5SRpn+9YKSPxi8yRvQ="
Mar 04 02:48:07 volumio go-librespot[14431]: time="2026-03-04T02:48:07-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 02:48:07 volumio go-librespot[14431]: time="2026-03-04T02:48:07-06:00" level=debug msg="completed keyexchange"
Mar 04 02:48:07 volumio go-librespot[14431]: time="2026-03-04T02:48:07-06:00" level=debug msg="completed challenge"
Mar 04 02:48:07 volumio go-librespot[14431]: time="2026-03-04T02:48:07-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 02:48:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 02:48:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 02:48:08 volumio volumio[13731]: info: Initializing connection to go-librespot Websocket
Mar 04 02:48:08 volumio volumio[13731]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 02:48:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 239.
Mar 04 02:48:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:48:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:48:10 volumio go-librespot[14442]: go-librespot daemon starting...
Mar 04 02:48:10 volumio go-librespot[14443]: time="2026-03-04T02:48:10-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 02:48:10 volumio go-librespot[14443]: time="2026-03-04T02:48:10-06:00" level=debug msg="app state loaded"
Mar 04 02:48:10 volumio go-librespot[14443]: time="2026-03-04T02:48:10-06:00" level=debug msg="stored credentials not found"
Mar 04 02:48:10 volumio go-librespot[14443]: time="2026-03-04T02:48:10-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 02:48:10 volumio go-librespot[14443]: time="2026-03-04T02:48:10-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 02:48:10 volumio go-librespot[14443]: time="2026-03-04T02:48:10-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 02:48:10 volumio go-librespot[14443]: time="2026-03-04T02:48:10-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 02:48:10 volumio go-librespot[14443]: time="2026-03-04T02:48:10-06:00" level=info msg="zeroconf server listening on port 37803"
Mar 04 02:48:10 volumio go-librespot[14443]: time="2026-03-04T02:48:10-06:00" level=debug msg="obtained new client token: AABx6cVMNaOzcWBs81GrH+WPgc4/zSrfifVrc2Vcqp6NcK1tKZl36sqzjvqMTIBHUGvYC+C/ishujUhom04BjV49l6hPc1+u5uTjl5lC6edg+VS8hUIEYYjl8IrXvtmbr3IMk/P7l3K307uikzBSJjZp3/byt5iPCUnyOk6MsktKD4tm/3oiTXxRqcjvRNv1q6EcslIKjx79A+erLFF1fg5BALwin+JHM/27jDZlmRHLcGth9ZHVAg3B5Q=="
Mar 04 02:48:10 volumio go-librespot[14443]: time="2026-03-04T02:48:10-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 02:48:10 volumio go-librespot[14443]: time="2026-03-04T02:48:10-06:00" level=debug msg="completed keyexchange"
Mar 04 02:48:10 volumio go-librespot[14443]: time="2026-03-04T02:48:10-06:00" level=debug msg="completed challenge"
Mar 04 02:48:10 volumio go-librespot[14443]: time="2026-03-04T02:48:10-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 02:48:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 02:48:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 02:48:11 volumio volumio[13731]: info: Initializing connection to go-librespot Websocket
Mar 04 02:48:11 volumio volumio[13731]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 02:48:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 240.
Mar 04 02:48:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:48:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:48:14 volumio go-librespot[14464]: go-librespot daemon starting...
Mar 04 02:48:14 volumio go-librespot[14465]: time="2026-03-04T02:48:14-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 02:48:14 volumio go-librespot[14465]: time="2026-03-04T02:48:14-06:00" level=debug msg="app state loaded"
Mar 04 02:48:14 volumio go-librespot[14465]: time="2026-03-04T02:48:14-06:00" level=debug msg="stored credentials not found"
Mar 04 02:48:14 volumio go-librespot[14465]: time="2026-03-04T02:48:14-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 02:48:14 volumio go-librespot[14465]: time="2026-03-04T02:48:14-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 02:48:14 volumio go-librespot[14465]: time="2026-03-04T02:48:14-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 02:48:14 volumio go-librespot[14465]: time="2026-03-04T02:48:14-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 02:48:14 volumio go-librespot[14465]: time="2026-03-04T02:48:14-06:00" level=info msg="zeroconf server listening on port 37717"
Mar 04 02:48:14 volumio go-librespot[14465]: time="2026-03-04T02:48:14-06:00" level=debug msg="obtained new client token: AABtJHf3kzn/OeirKkqvxA0yg9GOgdrp0uw5tTLIIQDatBKrVGJCDA9foCPIWk/NR572xmRgm5j2cKDjPszcFzwHJSRwnNfueZ+tolVCtk+5ejj4h/KbQSFv3I+ww5arsJjLTyeFUlgUdlSjyzmqntYyLJiFgc3iT5rbllyLmskbFsfBSzG6DtYiN9nsd4XbPrqwOr0LHX5bMLP4HUvNbCVa+ajXEMb3Q1iywElhMMMmhZa+9GQXR3DoYA=="
Mar 04 02:48:14 volumio go-librespot[14465]: time="2026-03-04T02:48:14-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 02:48:14 volumio go-librespot[14465]: time="2026-03-04T02:48:14-06:00" level=debug msg="completed keyexchange"
Mar 04 02:48:14 volumio go-librespot[14465]: time="2026-03-04T02:48:14-06:00" level=debug msg="completed challenge"
Mar 04 02:48:14 volumio go-librespot[14465]: time="2026-03-04T02:48:14-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 02:48:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 02:48:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 02:48:14 volumio volumio[13731]: info: Initializing connection to go-librespot Websocket
Mar 04 02:48:14 volumio volumio[13731]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 02:48:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 241.
Mar 04 02:48:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:48:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:48:17 volumio go-librespot[14472]: go-librespot daemon starting...
Mar 04 02:48:17 volumio go-librespot[14473]: time="2026-03-04T02:48:17-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 02:48:17 volumio go-librespot[14473]: time="2026-03-04T02:48:17-06:00" level=debug msg="app state loaded"
Mar 04 02:48:17 volumio go-librespot[14473]: time="2026-03-04T02:48:17-06:00" level=debug msg="stored credentials not found"
Mar 04 02:48:17 volumio go-librespot[14473]: time="2026-03-04T02:48:17-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 02:48:17 volumio volumio[13731]: info: Initializing connection to go-librespot Websocket
Mar 04 02:48:17 volumio go-librespot[14473]: time="2026-03-04T02:48:17-06:00" level=debug msg="new websocket client"
Mar 04 02:48:18 volumio volumio[13731]: info: Connection to go-librespot Websocket established
Mar 04 02:48:18 volumio go-librespot[14473]: time="2026-03-04T02:48:18-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 02:48:18 volumio go-librespot[14473]: time="2026-03-04T02:48:18-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 02:48:18 volumio go-librespot[14473]: time="2026-03-04T02:48:18-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 02:48:18 volumio go-librespot[14473]: time="2026-03-04T02:48:18-06:00" level=info msg="zeroconf server listening on port 43439"
Mar 04 02:48:18 volumio go-librespot[14473]: time="2026-03-04T02:48:18-06:00" level=debug msg="obtained new client token: AAAsOpS7kTd3OQROG/7MY0Jm9pel5QHVQpN3lVI0Z5s61pqqvL3KMuZHIjiIojr3Mq0d+Akt5ZWZgZliDxPh8blSb1RF/gRSNmm3ohOAmeiEPMfiMZGWVDcIIg4TVzAQYr7BVBNnROWESBR7x0KthrBtxmKRILjAUBzlyc4EGYoHYH62NprKEU2EXgLLBtN82d8jG8oNrPZAJZhThGSUJ2VWO0yTQ/o8DhSBKHCABdGmZqC9KOLSPRLA3Q=="
Mar 04 02:48:18 volumio go-librespot[14473]: time="2026-03-04T02:48:18-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 02:48:18 volumio go-librespot[14473]: time="2026-03-04T02:48:18-06:00" level=debug msg="completed keyexchange"
Mar 04 02:48:18 volumio go-librespot[14473]: time="2026-03-04T02:48:18-06:00" level=debug msg="completed challenge"
Mar 04 02:48:18 volumio go-librespot[14473]: time="2026-03-04T02:48:18-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 02:48:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 02:48:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 02:48:18 volumio volumio[13731]: info: Connection to go-librespot Websocket closed
Mar 04 02:48:21 volumio volumio[13731]: info: Getting Spotify volume
Mar 04 02:48:21 volumio volumio[13731]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Mar 04 02:48:21 volumio volumio[13731]: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 02:48:21 volumio volumio[13731]:     at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Mar 04 02:48:21 volumio volumio[13731]:   errno: -111,
Mar 04 02:48:21 volumio volumio[13731]:   code: 'ECONNREFUSED',
Mar 04 02:48:21 volumio volumio[13731]:   syscall: 'connect',
Mar 04 02:48:21 volumio volumio[13731]:   address: '127.0.0.1',
Mar 04 02:48:21 volumio volumio[13731]:   port: 9879,
Mar 04 02:48:21 volumio volumio[13731]:   response: undefined
Mar 04 02:48:21 volumio volumio[13731]: }
Mar 04 02:48:21 volumio volumio[13731]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Mar 04 02:48:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 242.
Mar 04 02:48:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:48:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 02:48:21 volumio go-librespot[14492]: go-librespot daemon starting...
Mar 04 02:48:21 volumio go-librespot[14493]: time="2026-03-04T02:48:21-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 02:48:21 volumio go-librespot[14493]: time="2026-03-04T02:48:21-06:00" level=debug msg="app state loaded"
Mar 04 02:48:21 volumio go-librespot[14493]: time="2026-03-04T02:48:21-06:00" level=debug msg="stored credentials not found"
Mar 04 02:48:21 volumio go-librespot[14493]: time="2026-03-04T02:48:21-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 02:48:21 volumio sudo[14502]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-04 02:47'
Mar 04 02:48:21 volumio sudo[14502]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)"
NAME="Raspbian GNU/Linux"
VERSION_ID="12"
VERSION="12 (bookworm)"
VERSION_CODENAME=bookworm
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"
VOLUMIO_BUILD_VERSION="ac7dd5922ede329d1459d48b226ddc71f5209a2c"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="3441cddd43405c36fe444484553f10f2f5bc830b"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Thu Nov 13 11:04:27 UTC 2025"
VOLUMIO_VERSION="4.069"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="7da8d6d9f8baf8621af4ec2af5a00f00"