Dec 08 06:06:00 volumio volumio[23613]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true
Dec 08 06:06:00 volumio sudo[24020]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite
Dec 08 06:06:00 volumio sudo[24020]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 08 06:06:00 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator...
Dec 08 06:06:00 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator.
Dec 08 06:06:00 volumio sudo[24020]: pam_unix(sudo:session): session closed for user root
Dec 08 06:06:00 volumio mpd[23963]: 2025-12-08T06:06:00 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Dec 08 06:06:00 volumio volumio[23613]: info: [squeezelite_mc] 'client' notification received from BigBoss (192.168.1.180); type is 'connect'
Dec 08 06:06:00 volumio volumio[23613]: info: [squeezelite_mc] Getting players connected to BigBoss (192.168.1.180)
Dec 08 06:06:00 volumio volumio[23613]: info: [squeezelite_mc] Players connected to BigBoss (192.168.1.180): [{"id":"00:04:20:27:50:e8","uuid":"01ef6d9b3e5a11e37681969e3bc3ac56","ip":"192.168.1.148","name":"Squeezebox Radio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}},{"id":"b8:27:eb:bb:d5:b0","uuid":null,"ip":"192.168.1.221","name":"volumio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}}]
Dec 08 06:06:00 volumio volumio[23613]: info: [squeezelite_mc] Player found: {"id":"b8:27:eb:bb:d5:b0","uuid":null,"ip":"192.168.1.221","name":"volumio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}}
Dec 08 06:06:00 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Dec 08 06:06:00 volumio sudo[23830]: pam_unix(sudo:session): session closed for user root
Dec 08 06:06:00 volumio sudo[23918]: pam_unix(sudo:session): session closed for user root
Dec 08 06:06:00 volumio sudo[23820]: pam_unix(sudo:session): session closed for user root
Dec 08 06:06:00 volumio volumio[23613]: error: MPD error: The expression evaluated to a falsy value:
Dec 08 06:06:00 volumio volumio[23613]: assert.ok(self.idling)
Dec 08 06:06:00 volumio volumio[23613]: error: The expression evaluated to a falsy value:
Dec 08 06:06:00 volumio volumio[23613]: assert.ok(self.idling)
Dec 08 06:06:00 volumio volumio[23613]: error: MPD error: The expression evaluated to a falsy value:
Dec 08 06:06:00 volumio volumio[23613]: assert.ok(self.idling)
Dec 08 06:06:00 volumio volumio[23613]: error: The expression evaluated to a falsy value:
Dec 08 06:06:00 volumio volumio[23613]: assert.ok(self.idling)
Dec 08 06:06:00 volumio volumio[23613]: info: MPD running with PID23963
Dec 08 06:06:00 volumio volumio[23613]: ,establishing connection
Dec 08 06:06:00 volumio volumio[23613]: error: updateQueue error: null
Dec 08 06:06:00 volumio volumio[23613]: error: updateQueue error: null
Dec 08 06:06:00 volumio volumio[23613]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Dec 08 06:06:00 volumio sudo[24032]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Dec 08 06:06:00 volumio sudo[24032]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 08 06:06:00 volumio sudo[24032]: pam_unix(sudo:session): session closed for user root
Dec 08 06:06:01 volumio volumio[23613]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Dec 08 06:06:01 volumio sudo[24035]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Dec 08 06:06:01 volumio sudo[24035]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 08 06:06:01 volumio sudo[24035]: pam_unix(sudo:session): session closed for user root
Dec 08 06:06:01 volumio volumio[23613]: info: CoreCommandRouter::volumioGetState
Dec 08 06:06:01 volumio volumio[23613]: info: CorePlayQueue::getTrack 0
Dec 08 06:06:01 volumio volumio[23613]: info: Initializing connection to go-librespot Websocket
Dec 08 06:06:01 volumio volumio[23613]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 08 06:06:01 volumio volumio[23613]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Dec 08 06:06:01 volumio sudo[24052]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Dec 08 06:06:01 volumio sudo[24052]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 08 06:06:01 volumio sudo[24052]: pam_unix(sudo:session): session closed for user root
Dec 08 06:06:02 volumio volumio[23613]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Dec 08 06:06:02 volumio sudo[24055]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Dec 08 06:06:02 volumio sudo[24055]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 08 06:06:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2.
Dec 08 06:06:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:06:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:06:02 volumio go-librespot[24057]: go-librespot daemon starting...
Dec 08 06:06:02 volumio sudo[24055]: pam_unix(sudo:session): session closed for user root
Dec 08 06:06:02 volumio go-librespot[24058]: time="2025-12-08T06:06:02-06:00" level=info msg="running go-librespot 0.4.0"
Dec 08 06:06:02 volumio go-librespot[24058]: time="2025-12-08T06:06:02-06:00" level=debug msg="app state loaded"
Dec 08 06:06:02 volumio go-librespot[24058]: time="2025-12-08T06:06:02-06:00" level=debug msg="stored credentials not found"
Dec 08 06:06:02 volumio go-librespot[24058]: time="2025-12-08T06:06:02-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 08 06:06:02 volumio go-librespot[24058]: time="2025-12-08T06:06:02-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]"
Dec 08 06:06:02 volumio go-librespot[24058]: time="2025-12-08T06:06:02-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]"
Dec 08 06:06:02 volumio go-librespot[24058]: time="2025-12-08T06:06:02-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]"
Dec 08 06:06:02 volumio go-librespot[24058]: time="2025-12-08T06:06:02-06:00" level=info msg="zeroconf server listening on port 35721"
Dec 08 06:06:03 volumio go-librespot[24058]: time="2025-12-08T06:06:02-06:00" level=debug msg="obtained new client token: AAAHNdRpea4OoRY+6/Qn4nP54sxUW/+OF3ft0YAq5pZPqfuUp3AkIHLosU0Ntp6v3zxtJ0P4LRL4XhMtzrLaCgSiW3dCKDY73hizCkkmE55A8QHRpqOC5LNoZmKUn1tSwmKevCTYLZjudW43u4Z5WCVWmf5YnRZbg0R0y3OC4hTB5TJSqqh+LQ0YGC0RrKZzgYBD0fo+IBwNNfiNvULT1i60IRBCTqtk8f04XbciAtnqgUJ5ud/B0PyIlg=="
Dec 08 06:06:03 volumio go-librespot[24058]: time="2025-12-08T06:06:03-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 08 06:06:03 volumio go-librespot[24058]: time="2025-12-08T06:06:03-06:00" level=debug msg="completed keyexchange"
Dec 08 06:06:03 volumio go-librespot[24058]: time="2025-12-08T06:06:03-06:00" level=debug msg="completed challenge"
Dec 08 06:06:03 volumio go-librespot[24058]: time="2025-12-08T06:06: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 "
Dec 08 06:06:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 08 06:06:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 08 06:06:03 volumio volumio[23613]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Dec 08 06:06:03 volumio sudo[24066]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Dec 08 06:06:03 volumio sudo[24066]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 08 06:06:03 volumio sudo[24066]: pam_unix(sudo:session): session closed for user root
Dec 08 06:06:03 volumio volumio[23613]: info: Completed starting Core Plugins
Dec 08 06:06:03 volumio volumio[23613]: info: -------------------------------------------
Dec 08 06:06:03 volumio volumio[23613]: info: ----- MyVolumio plugins startup ----
Dec 08 06:06:03 volumio volumio[23613]: info: -------------------------------------------
Dec 08 06:06:03 volumio volumio[23613]: info: [MyVolumio PluginManager] Fetching plans data....
Dec 08 06:06:03 volumio sudo[24069]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Dec 08 06:06:03 volumio sudo[24069]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 08 06:06:03 volumio sudo[24071]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Dec 08 06:06:03 volumio sudo[24071]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 08 06:06:03 volumio sudo[24074]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Dec 08 06:06:03 volumio sudo[24074]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 08 06:06:03 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service...
Dec 08 06:06:03 volumio systemd[1]: mpd_monitor.service: Deactivated successfully.
Dec 08 06:06:03 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service.
Dec 08 06:06:03 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service.
Dec 08 06:06:03 volumio sudo[24071]: pam_unix(sudo:session): session closed for user root
Dec 08 06:06:03 volumio sudo[24069]: pam_unix(sudo:session): session closed for user root
Dec 08 06:06:03 volumio mpd_monitor.sh[24077]: MPD Monitor Service: Starting MPD Monitor Service
Dec 08 06:06:03 volumio sudo[24074]: pam_unix(sudo:session): session closed for user root
Dec 08 06:06:03 volumio volumio[23613]: info: Successfully started MPD Monitor
Dec 08 06:06:03 volumio volumio[23613]: info: Successfully started MPD Monitor
Dec 08 06:06:03 volumio volumio[23613]: info: Successfully started MPD Monitor
Dec 08 06:06:04 volumio volumio[23613]: info: Initializing connection to go-librespot Websocket
Dec 08 06:06:04 volumio volumio[23613]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 08 06:06:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3.
Dec 08 06:06:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:06:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:06:06 volumio go-librespot[24081]: go-librespot daemon starting...
Dec 08 06:06:06 volumio go-librespot[24082]: time="2025-12-08T06:06:06-06:00" level=info msg="running go-librespot 0.4.0"
Dec 08 06:06:06 volumio go-librespot[24082]: time="2025-12-08T06:06:06-06:00" level=debug msg="app state loaded"
Dec 08 06:06:06 volumio go-librespot[24082]: time="2025-12-08T06:06:06-06:00" level=debug msg="stored credentials not found"
Dec 08 06:06:06 volumio go-librespot[24082]: time="2025-12-08T06:06:06-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 08 06:06:06 volumio go-librespot[24082]: time="2025-12-08T06:06: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]"
Dec 08 06:06:06 volumio go-librespot[24082]: time="2025-12-08T06:06: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]"
Dec 08 06:06:06 volumio go-librespot[24082]: time="2025-12-08T06:06: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]"
Dec 08 06:06:06 volumio go-librespot[24082]: time="2025-12-08T06:06:06-06:00" level=info msg="zeroconf server listening on port 46763"
Dec 08 06:06:06 volumio go-librespot[24082]: time="2025-12-08T06:06:06-06:00" level=debug msg="obtained new client token: AABQdjK57b8RtuNeaNNmKNSNU3547kABhUaU//TlKLqWHJK0K1sKtPVnh2YDlVeZio5ZD5kAOwBDOpB9YS+YpjPEcNAEVp9VwDHSHRw9AbzgBZa9fxJnMR91h8oTwH2gyIUSrmeBZPSxDio02BwjdDNeqVLukzgj9oycOu1glcbKrfixEpIlVwnUmLcaao36LS11hDYeNra7+FCZ8KlHXLu7qDLNcWuc/kglNC98LD10xTuZVCZCpSDUvA=="
Dec 08 06:06:06 volumio go-librespot[24082]: time="2025-12-08T06:06:06-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 08 06:06:06 volumio go-librespot[24082]: time="2025-12-08T06:06:06-06:00" level=debug msg="completed keyexchange"
Dec 08 06:06:06 volumio go-librespot[24082]: time="2025-12-08T06:06:06-06:00" level=debug msg="completed challenge"
Dec 08 06:06:06 volumio go-librespot[24082]: time="2025-12-08T06:06:06-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 "
Dec 08 06:06:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 08 06:06:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 08 06:06:08 volumio volumio[23613]: info: Initializing connection to go-librespot Websocket
Dec 08 06:06:08 volumio volumio[23613]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 08 06:06:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4.
Dec 08 06:06:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:06:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:06:09 volumio go-librespot[24089]: go-librespot daemon starting...
Dec 08 06:06:10 volumio go-librespot[24090]: time="2025-12-08T06:06:10-06:00" level=info msg="running go-librespot 0.4.0"
Dec 08 06:06:10 volumio go-librespot[24090]: time="2025-12-08T06:06:10-06:00" level=debug msg="app state loaded"
Dec 08 06:06:10 volumio go-librespot[24090]: time="2025-12-08T06:06:10-06:00" level=debug msg="stored credentials not found"
Dec 08 06:06:10 volumio go-librespot[24090]: time="2025-12-08T06:06:10-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 08 06:06:10 volumio go-librespot[24090]: time="2025-12-08T06:06: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-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Dec 08 06:06:10 volumio go-librespot[24090]: time="2025-12-08T06:06:10-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]"
Dec 08 06:06:10 volumio go-librespot[24090]: time="2025-12-08T06:06:10-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]"
Dec 08 06:06:10 volumio go-librespot[24090]: time="2025-12-08T06:06:10-06:00" level=info msg="zeroconf server listening on port 43445"
Dec 08 06:06:10 volumio go-librespot[24090]: time="2025-12-08T06:06:10-06:00" level=debug msg="obtained new client token: AAAdVd+hxsuhWt8UWq3Rw/5TJc2+Cuvmgg7ZwjNSy/qIGRl3868XJcf7Lh5p1EgyXTByDbRvMqutbu5A73+e0sw8M5HVRspljc6L0MbF9v2Dogb5q2Tljez7xWeIMOhpCgtmaOatYkd5+12I7gvzJ8I303yhFrDwqi2z/3PMR7oocyRkc9uKkMBlq2UrMIcDZ88NUbZa1h4PmQTROok4l7IGufpQlm5i0ucXl+SIRc1EivbkL9T4rv3XVA=="
Dec 08 06:06:10 volumio go-librespot[24090]: time="2025-12-08T06:06:10-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 08 06:06:10 volumio go-librespot[24090]: time="2025-12-08T06:06:10-06:00" level=debug msg="completed keyexchange"
Dec 08 06:06:10 volumio go-librespot[24090]: time="2025-12-08T06:06:10-06:00" level=debug msg="completed challenge"
Dec 08 06:06:10 volumio go-librespot[24090]: time="2025-12-08T06:06: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 "
Dec 08 06:06:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 08 06:06:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 08 06:06:11 volumio volumio[23613]: info: Initializing connection to go-librespot Websocket
Dec 08 06:06:11 volumio volumio[23613]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 08 06:06:12 volumio volumio[23613]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Dec 08 06:06:12 volumio volumio[23613]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Dec 08 06:06:12 volumio volumio[23613]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Dec 08 06:06:12 volumio volumio[23613]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Dec 08 06:06:12 volumio volumio[23613]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Dec 08 06:06:12 volumio volumio[23613]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Dec 08 06:06:12 volumio volumio[23613]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Dec 08 06:06:12 volumio volumio[23613]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Dec 08 06:06:12 volumio volumio[23613]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Dec 08 06:06:12 volumio volumio[23613]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Dec 08 06:06:12 volumio volumio[23613]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Dec 08 06:06:12 volumio volumio[23613]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Dec 08 06:06:12 volumio volumio[23613]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Dec 08 06:06:12 volumio volumio[23613]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Dec 08 06:06:12 volumio volumio[23613]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Dec 08 06:06:12 volumio volumio[23613]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Dec 08 06:06:12 volumio volumio[23613]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Dec 08 06:06:12 volumio volumio[23613]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Dec 08 06:06:12 volumio volumio[23613]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Dec 08 06:06:12 volumio volumio[23613]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Dec 08 06:06:12 volumio volumio[23613]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Dec 08 06:06:12 volumio volumio[23613]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Dec 08 06:06:12 volumio volumio[23613]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Dec 08 06:06:12 volumio volumio[23613]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Dec 08 06:06:12 volumio volumio[23613]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Dec 08 06:06:12 volumio volumio[23613]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Dec 08 06:06:12 volumio volumio[23613]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Dec 08 06:06:12 volumio volumio[23613]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Dec 08 06:06:12 volumio volumio[23613]: info: Adding plugin bluetooth to MyMusic Plugins
Dec 08 06:06:12 volumio volumio[23613]: info: Adding plugin multiroom to MyMusic Plugins
Dec 08 06:06:12 volumio volumio[23613]: info: Adding plugin metavolumio to MyMusic Plugins
Dec 08 06:06:12 volumio volumio[23613]: info: Adding plugin cd_controller to MyMusic Plugins
Dec 08 06:06:12 volumio volumio[23613]: info: Adding plugin qobuzconnect to MyMusic Plugins
Dec 08 06:06:12 volumio volumio[23613]: info: Adding plugin smart_inputs to MyMusic Plugins
Dec 08 06:06:12 volumio volumio[23613]: info: Adding plugin tidalconnect to MyMusic Plugins
Dec 08 06:06:12 volumio volumio[23613]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Dec 08 06:06:13 volumio volumio[23613]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Dec 08 06:06:13 volumio volumio[23613]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Dec 08 06:06:13 volumio volumio[23613]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 08 06:06:13 volumio volumio[23613]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 08 06:06:13 volumio volumio[23613]: info: Starting MyVolumio Remote Streaming Endpoints
Dec 08 06:06:13 volumio volumio[23613]: info: MyVolumio login type: Token
Dec 08 06:06:13 volumio volumio[23613]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Dec 08 06:06:13 volumio volumio[23613]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Dec 08 06:06:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5.
Dec 08 06:06:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:06:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:06:13 volumio go-librespot[24111]: go-librespot daemon starting...
Dec 08 06:06:13 volumio go-librespot[24112]: time="2025-12-08T06:06:13-06:00" level=info msg="running go-librespot 0.4.0"
Dec 08 06:06:13 volumio go-librespot[24112]: time="2025-12-08T06:06:13-06:00" level=debug msg="app state loaded"
Dec 08 06:06:13 volumio go-librespot[24112]: time="2025-12-08T06:06:13-06:00" level=debug msg="stored credentials not found"
Dec 08 06:06:13 volumio go-librespot[24112]: time="2025-12-08T06:06:13-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 08 06:06:13 volumio volumio[23613]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Dec 08 06:06:13 volumio volumio[23613]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Dec 08 06:06:13 volumio volumio[23613]: info: Streaming services startup
Dec 08 06:06:13 volumio volumio[23613]: info: Starting Streaming Daemon
Dec 08 06:06:13 volumio sudo[24120]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Dec 08 06:06:13 volumio sudo[24120]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 08 06:06:13 volumio volumio[23613]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Dec 08 06:06:14 volumio sudo[24120]: pam_unix(sudo:session): session closed for user root
Dec 08 06:06:14 volumio volumio[23613]: error: Cannot start Volumio Streaming Daemon
Dec 08 06:06:14 volumio volumio[23613]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Dec 08 06:06:14 volumio volumio[23613]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Dec 08 06:06:14 volumio go-librespot[24112]: time="2025-12-08T06:06: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-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 08 06:06:14 volumio go-librespot[24112]: time="2025-12-08T06:06:14-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]"
Dec 08 06:06:14 volumio go-librespot[24112]: time="2025-12-08T06:06:14-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]"
Dec 08 06:06:14 volumio go-librespot[24112]: time="2025-12-08T06:06:14-06:00" level=info msg="zeroconf server listening on port 42383"
Dec 08 06:06:14 volumio go-librespot[24112]: time="2025-12-08T06:06:14-06:00" level=debug msg="obtained new client token: AAAUMPVqsxuaoEE5DWrgtGmA6RzHgydo88/TWb8E4NE+TcUTuYDvswtjA18mUEJtR/VoTJrcyftbuFPOPCzO9q/raCU43gNbT/GwZhzlHDLppf/Wnh6ypq++KkR5Sz8dDRirnfQAAQ0C2DAy0rW+I0y7JS8wKIuwQ0lAOEQooFB+4TdEfby39czoVVTAOJU1v8hMI4GcowbdhfIn3EreIBRaH9QRqV2J9cILbFh/aZgUaB7jJfXYSRY="
Dec 08 06:06:14 volumio go-librespot[24112]: time="2025-12-08T06:06:14-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 08 06:06:14 volumio go-librespot[24112]: time="2025-12-08T06:06:14-06:00" level=debug msg="completed keyexchange"
Dec 08 06:06:14 volumio go-librespot[24112]: time="2025-12-08T06:06:14-06:00" level=debug msg="completed challenge"
Dec 08 06:06:14 volumio go-librespot[24112]: time="2025-12-08T06:06: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 "
Dec 08 06:06:14 volumio volumio[23613]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN
Dec 08 06:06:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 08 06:06:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 08 06:06:14 volumio volumio[23613]: info: Initializing connection to go-librespot Websocket
Dec 08 06:06:14 volumio volumio[23613]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 08 06:06:14 volumio volumio[23613]: info: MyVolumio token set successfully
Dec 08 06:06:14 volumio volumio[23613]: info: MYVOLUMIO: Adding device
Dec 08 06:06:14 volumio volumio[23613]: info: MYVOLUMIO: Evaluating Server
Dec 08 06:06:14 volumio volumio[23613]: info: MyVolumio status changed
Dec 08 06:06:14 volumio volumio[23613]: info: Streaming services startup
Dec 08 06:06:14 volumio volumio[23613]: info: Starting Streaming Daemon
Dec 08 06:06:14 volumio volumio[23613]: info: Removing browser output: myVolumio user plan is not superstar
Dec 08 06:06:14 volumio volumio[23613]: info: Removing audio output:
Dec 08 06:06:14 volumio volumio[23613]: info: Stoppping Tunnel 1
Dec 08 06:06:14 volumio sudo[24148]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Dec 08 06:06:14 volumio sudo[24148]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 08 06:06:15 volumio sudo[24150]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service
Dec 08 06:06:15 volumio sudo[24150]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 08 06:06:15 volumio sudo[24148]: pam_unix(sudo:session): session closed for user root
Dec 08 06:06:15 volumio volumio[23613]: error: Cannot start Volumio Streaming Daemon
Dec 08 06:06:15 volumio volumio[23613]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Dec 08 06:06:15 volumio volumio[23613]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Dec 08 06:06:15 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Dec 08 06:06:15 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Dec 08 06:06:15 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Dec 08 06:06:15 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Dec 08 06:06:15 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Dec 08 06:06:15 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Dec 08 06:06:15 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Dec 08 06:06:15 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Dec 08 06:06:15 volumio sudo[24150]: pam_unix(sudo:session): session closed for user root
Dec 08 06:06:15 volumio volumio[23613]: info: Remote SSH Stopped
Dec 08 06:06:15 volumio volumio[23613]: info: Setting Geolocation for MyVolumio to us1
Dec 08 06:06:15 volumio volumio[23613]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 08 06:06:15 volumio volumio[23613]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 08 06:06:15 volumio volumio[23613]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 08 06:06:15 volumio volumio[23613]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Dec 08 06:06:16 volumio volumio[23613]: info: Updating MyVolumio device info
Dec 08 06:06:16 volumio volumio[23613]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 08 06:06:16 volumio volumio[23613]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 08 06:06:16 volumio volumio[23613]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 08 06:06:17 volumio volumio[23613]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Dec 08 06:06:17 volumio volumio[23613]: info: Initializing connection to go-librespot Websocket
Dec 08 06:06:17 volumio volumio[23613]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 08 06:06:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6.
Dec 08 06:06:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:06:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:06:17 volumio go-librespot[24154]: go-librespot daemon starting...
Dec 08 06:06:17 volumio go-librespot[24155]: time="2025-12-08T06:06:17-06:00" level=info msg="running go-librespot 0.4.0"
Dec 08 06:06:17 volumio go-librespot[24155]: time="2025-12-08T06:06:17-06:00" level=debug msg="app state loaded"
Dec 08 06:06:17 volumio go-librespot[24155]: time="2025-12-08T06:06:17-06:00" level=debug msg="stored credentials not found"
Dec 08 06:06:17 volumio go-librespot[24155]: time="2025-12-08T06:06:17-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 08 06:06:17 volumio go-librespot[24155]: time="2025-12-08T06:06:17-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]"
Dec 08 06:06:17 volumio go-librespot[24155]: time="2025-12-08T06:06:17-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]"
Dec 08 06:06:17 volumio go-librespot[24155]: time="2025-12-08T06:06:17-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]"
Dec 08 06:06:17 volumio go-librespot[24155]: time="2025-12-08T06:06:17-06:00" level=info msg="zeroconf server listening on port 33231"
Dec 08 06:06:17 volumio go-librespot[24155]: time="2025-12-08T06:06:17-06:00" level=debug msg="obtained new client token: AACgVe/+Yd0cjZzPXgCnphJXnoN1CecYLjFRPX5sgxGmeuCPqnvPU5Y4if8BxBE6SIYwUL5Up5d8nUFbPRon9HM/Bire3DJSmXFF59mH12xiufETeRJpG8c910vuKUlRXF16nU9MYw1w/azJz9G/F9rMFqVJktPJFv0aN4cRYJn/n2Ngp09FwlviD8+WQdVxKCcxBGV8bc4Le0HsPvhKuYJSPa9wnN+jXBOzIDEG08UuNy9YUuV2vroU5A=="
Dec 08 06:06:17 volumio go-librespot[24155]: time="2025-12-08T06:06:17-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 08 06:06:17 volumio go-librespot[24155]: time="2025-12-08T06:06:17-06:00" level=debug msg="completed keyexchange"
Dec 08 06:06:17 volumio go-librespot[24155]: time="2025-12-08T06:06:17-06:00" level=debug msg="completed challenge"
Dec 08 06:06:17 volumio go-librespot[24155]: time="2025-12-08T06:06:17-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 "
Dec 08 06:06:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 08 06:06:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 08 06:06:19 volumio volumio[23613]: info: MYVOLUMIO: Adding device
Dec 08 06:06:19 volumio volumio[23613]: info: MYVOLUMIO: Evaluating Server
Dec 08 06:06:19 volumio volumio[23613]: info: Setting Geolocation for MyVolumio to us4
Dec 08 06:06:19 volumio volumio[23613]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 08 06:06:19 volumio volumio[23613]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 08 06:06:19 volumio volumio[23613]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 08 06:06:20 volumio volumio[23613]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Dec 08 06:06:20 volumio volumio[23613]: info: Initializing connection to go-librespot Websocket
Dec 08 06:06:20 volumio volumio[23613]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 08 06:06:20 volumio volumio[23613]: info: Updating MyVolumio device info
Dec 08 06:06:20 volumio volumio[23613]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 08 06:06:20 volumio volumio[23613]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 08 06:06:20 volumio volumio[23613]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 08 06:06:21 volumio volumio[23613]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Dec 08 06:06:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7.
Dec 08 06:06:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:06:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:06:21 volumio go-librespot[24181]: go-librespot daemon starting...
Dec 08 06:06:21 volumio go-librespot[24182]: time="2025-12-08T06:06:21-06:00" level=info msg="running go-librespot 0.4.0"
Dec 08 06:06:21 volumio go-librespot[24182]: time="2025-12-08T06:06:21-06:00" level=debug msg="app state loaded"
Dec 08 06:06:21 volumio go-librespot[24182]: time="2025-12-08T06:06:21-06:00" level=debug msg="stored credentials not found"
Dec 08 06:06:21 volumio go-librespot[24182]: time="2025-12-08T06:06:21-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 08 06:06:21 volumio go-librespot[24182]: time="2025-12-08T06:06: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 08 06:06:21 volumio go-librespot[24182]: time="2025-12-08T06:06:21-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]"
Dec 08 06:06:21 volumio go-librespot[24182]: time="2025-12-08T06:06:21-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]"
Dec 08 06:06:21 volumio go-librespot[24182]: time="2025-12-08T06:06:21-06:00" level=info msg="zeroconf server listening on port 44035"
Dec 08 06:06:21 volumio go-librespot[24182]: time="2025-12-08T06:06:21-06:00" level=debug msg="obtained new client token: AAAFM93M/mne7KL6kyyBKuO4uB6S+PZEZ9esKnHCqUU88Sfn1XkSHoffzNcARUsFc1NJp3ssMU4SI37DLAYT7nWBO9Erv0syFfrmZrlSZlcOEVm0dZ345RoEFpVDNH1iR4M7qYXyeco2aPi9RwP5+tGlPlNdEucwo3j2l/INNnXnWCGSCNiLLWrvwJzANxpKBhP1XXUvFxELTdVa3qb6CUmJudjqj+/4RRdJ46hEYe3pn6VlaqQrH05Pnw=="
Dec 08 06:06:21 volumio go-librespot[24182]: time="2025-12-08T06:06:21-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 08 06:06:21 volumio go-librespot[24182]: time="2025-12-08T06:06:21-06:00" level=debug msg="completed keyexchange"
Dec 08 06:06:21 volumio go-librespot[24182]: time="2025-12-08T06:06:21-06:00" level=debug msg="completed challenge"
Dec 08 06:06:21 volumio go-librespot[24182]: time="2025-12-08T06:06:21-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 "
Dec 08 06:06:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 08 06:06:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 08 06:06:23 volumio volumio[23613]: info: Initializing connection to go-librespot Websocket
Dec 08 06:06:23 volumio volumio[23613]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 08 06:06:24 volumio volumio[23613]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 08 06:06:24 volumio volumio[23613]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 08 06:06:24 volumio volumio[23613]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Dec 08 06:06:24 volumio volumio[23613]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Dec 08 06:06:24 volumio volumio-remote-updater[9752]: Test mode disabled
Dec 08 06:06:24 volumio volumio-remote-updater[9752]: Alpha mode disabled
Dec 08 06:06:24 volumio volumio-remote-updater[9752]: Alpha legacy test mode disabled
Dec 08 06:06:24 volumio volumio[23613]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"ANNOUNCEMENT
\n\n- Production line
\n
\nFIX
\n\n- Nodejs 20.5.1 version pinning with static package fallback
\n
\n","title":"Update v4.073","updateavailable":true}
Dec 08 06:06:24 volumio volumio[23613]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Dec 08 06:06:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8.
Dec 08 06:06:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:06:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:06:25 volumio go-librespot[24210]: go-librespot daemon starting...
Dec 08 06:06:25 volumio go-librespot[24211]: time="2025-12-08T06:06:25-06:00" level=info msg="running go-librespot 0.4.0"
Dec 08 06:06:25 volumio go-librespot[24211]: time="2025-12-08T06:06:25-06:00" level=debug msg="app state loaded"
Dec 08 06:06:25 volumio go-librespot[24211]: time="2025-12-08T06:06:25-06:00" level=debug msg="stored credentials not found"
Dec 08 06:06:25 volumio go-librespot[24211]: time="2025-12-08T06:06:25-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 08 06:06:25 volumio go-librespot[24211]: time="2025-12-08T06:06: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 08 06:06:25 volumio go-librespot[24211]: time="2025-12-08T06:06:25-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]"
Dec 08 06:06:25 volumio go-librespot[24211]: time="2025-12-08T06:06:25-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]"
Dec 08 06:06:25 volumio go-librespot[24211]: time="2025-12-08T06:06:25-06:00" level=info msg="zeroconf server listening on port 43041"
Dec 08 06:06:25 volumio go-librespot[24211]: time="2025-12-08T06:06:25-06:00" level=debug msg="obtained new client token: AACc9dj/eWHeQivIeT0rI4zPiz5+K0IxnYqa/1tizbeeS0zvevXkIWhmrGqqyNSWS9KU9VRtUB8DPtmVSGN/oInO6S05z3XecpOnfoGaYUm1AtKT/4l9VG/H9pfjMghs+srHZOMuO9rcqyz0lSOvRndcZ061xz2OYW6aeReHUlrURvMm8EeNDvtgy5joMbzaYANPtck6TvLVOGb6ksUNzZ+dnxSpriikEUNHondT48nCxAKkDckGt3eGCA=="
Dec 08 06:06:25 volumio go-librespot[24211]: time="2025-12-08T06:06:25-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 08 06:06:25 volumio go-librespot[24211]: time="2025-12-08T06:06:25-06:00" level=debug msg="completed keyexchange"
Dec 08 06:06:25 volumio go-librespot[24211]: time="2025-12-08T06:06:25-06:00" level=debug msg="completed challenge"
Dec 08 06:06:25 volumio go-librespot[24211]: time="2025-12-08T06:06: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 "
Dec 08 06:06:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 08 06:06:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 08 06:06:26 volumio volumio[23613]: info: Initializing connection to go-librespot Websocket
Dec 08 06:06:26 volumio volumio[23613]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 08 06:06:28 volumio volumio[23613]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Dec 08 06:06:28 volumio volumio[23613]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4
Dec 08 06:06:28 volumio volumio[23613]: info: CoreCommandRouter::volumioGetState
Dec 08 06:06:28 volumio volumio[23613]: info: CorePlayQueue::getTrack 0
Dec 08 06:06:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9.
Dec 08 06:06:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:06:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:06:28 volumio go-librespot[24218]: go-librespot daemon starting...
Dec 08 06:06:28 volumio go-librespot[24219]: time="2025-12-08T06:06:28-06:00" level=info msg="running go-librespot 0.4.0"
Dec 08 06:06:28 volumio go-librespot[24219]: time="2025-12-08T06:06:28-06:00" level=debug msg="app state loaded"
Dec 08 06:06:28 volumio go-librespot[24219]: time="2025-12-08T06:06:28-06:00" level=debug msg="stored credentials not found"
Dec 08 06:06:28 volumio go-librespot[24219]: time="2025-12-08T06:06:28-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 08 06:06:28 volumio go-librespot[24219]: time="2025-12-08T06:06:28-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]"
Dec 08 06:06:28 volumio go-librespot[24219]: time="2025-12-08T06:06:28-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]"
Dec 08 06:06:28 volumio go-librespot[24219]: time="2025-12-08T06:06:28-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]"
Dec 08 06:06:29 volumio go-librespot[24219]: time="2025-12-08T06:06:29-06:00" level=info msg="zeroconf server listening on port 46235"
Dec 08 06:06:29 volumio go-librespot[24219]: time="2025-12-08T06:06:29-06:00" level=debug msg="obtained new client token: AABaL42hR5ymwK2IDt4pNVY2sYM1hTFHbc2GDr4fm/BFwpDrAx3Ylxd1f8Efm03TfxOVRD7sL8gNLShqvIDNF3qfVbANW3kTRnXwA3bFbhBCjsnduyU5QVlCBWP/usdRzwy8Fp+oExCUYVb7hELRDrBiKNFX0Yal/80G0MB2Qfu41VwkLgt2J47G8W5w0+duwU046yNfNz0CVsOsbsU81dL+0csuZmsGjU9zklkCcnyO74NzC0H8+Wc="
Dec 08 06:06:29 volumio go-librespot[24219]: time="2025-12-08T06:06:29-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused"
Dec 08 06:06:29 volumio go-librespot[24219]: time="2025-12-08T06:06:29-06:00" level=debug msg="connected to ap-guc3.spotify.com:443"
Dec 08 06:06:29 volumio go-librespot[24219]: time="2025-12-08T06:06:29-06:00" level=debug msg="completed keyexchange"
Dec 08 06:06:29 volumio go-librespot[24219]: time="2025-12-08T06:06:29-06:00" level=debug msg="completed challenge"
Dec 08 06:06:29 volumio go-librespot[24219]: time="2025-12-08T06:06: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 "
Dec 08 06:06:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 08 06:06:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 08 06:06:29 volumio volumio[23613]: info: Initializing connection to go-librespot Websocket
Dec 08 06:06:29 volumio volumio[23613]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 08 06:06:32 volumio volumio[23613]: info: Initializing connection to go-librespot Websocket
Dec 08 06:06:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10.
Dec 08 06:06:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:06:32 volumio volumio[23613]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 08 06:06:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:06:32 volumio go-librespot[24240]: go-librespot daemon starting...
Dec 08 06:06:32 volumio go-librespot[24241]: time="2025-12-08T06:06:32-06:00" level=info msg="running go-librespot 0.4.0"
Dec 08 06:06:32 volumio go-librespot[24241]: time="2025-12-08T06:06:32-06:00" level=debug msg="app state loaded"
Dec 08 06:06:32 volumio go-librespot[24241]: time="2025-12-08T06:06:32-06:00" level=debug msg="stored credentials not found"
Dec 08 06:06:32 volumio go-librespot[24241]: time="2025-12-08T06:06:32-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 08 06:06:32 volumio go-librespot[24241]: time="2025-12-08T06:06:32-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]"
Dec 08 06:06:32 volumio go-librespot[24241]: time="2025-12-08T06:06:32-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]"
Dec 08 06:06:32 volumio go-librespot[24241]: time="2025-12-08T06:06:32-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]"
Dec 08 06:06:32 volumio go-librespot[24241]: time="2025-12-08T06:06:32-06:00" level=info msg="zeroconf server listening on port 41777"
Dec 08 06:06:32 volumio go-librespot[24241]: time="2025-12-08T06:06:32-06:00" level=debug msg="obtained new client token: AACuLq8zMK4UDBmJKs9rpu4i7yVpIyCCfaMvqbQYi5ZOyyaC+XCIHoi88fEoW5qLnioRFqrMchVaomNAIMKZCceQZQ4a2MHvazZJPNDyoqhMtYosUzcHhExnNASBodf3BJi8xQ9c1qO5/Btg0tqq4Ew8fYuAb05V5ZtUwrvx8+vBb8fQ5WAmI65AHk7C2ME2CW07ipTkqzQFLvbAW+QkV8OKTnAKnRxbPRPzJ60AH16kDkxwz4EjH2vwww=="
Dec 08 06:06:32 volumio go-librespot[24241]: time="2025-12-08T06:06:32-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 08 06:06:32 volumio go-librespot[24241]: time="2025-12-08T06:06:32-06:00" level=debug msg="completed keyexchange"
Dec 08 06:06:32 volumio go-librespot[24241]: time="2025-12-08T06:06:32-06:00" level=debug msg="completed challenge"
Dec 08 06:06:33 volumio go-librespot[24241]: time="2025-12-08T06:06: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 "
Dec 08 06:06:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 08 06:06:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 08 06:06:33 volumio volumio[23613]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 08 06:06:33 volumio volumio[23613]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 08 06:06:33 volumio volumio[23613]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam
Dec 08 06:06:33 volumio volumio[23613]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
Dec 08 06:06:33 volumio volumio[23613]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Dec 08 06:06:33 volumio volumio[23613]: info: CoreCommandRouter::volumioGetBrowseSources
Dec 08 06:06:33 volumio volumio[23613]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 08 06:06:33 volumio volumio[23613]: error: MyVolumio Plugin failed to authenticate in a timely fashion
Dec 08 06:06:33 volumio volumio[23613]: info: Completed starting MyVolumio Plugin
Dec 08 06:06:33 volumio volumio[23613]: [Metrics] CommandRouter: 54s 773.61ms
Dec 08 06:06:33 volumio volumio[23613]: info: CoreCommandRouter::volumiosetStartupVolume
Dec 08 06:06:33 volumio volumio[23613]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 08 06:06:33 volumio volumio[23613]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 08 06:06:34 volumio volumio[23613]: info: CoreCommandRouter::Close All Modals sent
Dec 08 06:06:34 volumio volumio[23613]: info: CoreCommandRouter::Close All Modals sent
Dec 08 06:06:35 volumio volumio[23613]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable
Dec 08 06:06:35 volumio volumio[23613]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
Dec 08 06:06:35 volumio volumio[23613]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect
Dec 08 06:06:35 volumio volumio[23613]: info: Initializing connection to go-librespot Websocket
Dec 08 06:06:35 volumio volumio[23613]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 08 06:06:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11.
Dec 08 06:06:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:06:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:06:36 volumio go-librespot[24255]: go-librespot daemon starting...
Dec 08 06:06:36 volumio go-librespot[24257]: time="2025-12-08T06:06:36-06:00" level=info msg="running go-librespot 0.4.0"
Dec 08 06:06:36 volumio go-librespot[24257]: time="2025-12-08T06:06:36-06:00" level=debug msg="app state loaded"
Dec 08 06:06:36 volumio go-librespot[24257]: time="2025-12-08T06:06:36-06:00" level=debug msg="stored credentials not found"
Dec 08 06:06:36 volumio go-librespot[24257]: time="2025-12-08T06:06:36-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 08 06:06:36 volumio go-librespot[24257]: time="2025-12-08T06:06: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 08 06:06:36 volumio go-librespot[24257]: time="2025-12-08T06:06:36-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]"
Dec 08 06:06:36 volumio go-librespot[24257]: time="2025-12-08T06:06:36-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]"
Dec 08 06:06:36 volumio go-librespot[24257]: time="2025-12-08T06:06:36-06:00" level=info msg="zeroconf server listening on port 45727"
Dec 08 06:06:36 volumio go-librespot[24257]: time="2025-12-08T06:06:36-06:00" level=debug msg="obtained new client token: AAChqeF1ErGK9DRNn0myTIk5lzzVUArLGkUJfG0+30ZNFItKreCMOqf+ioOamu9fNtTgN/t8RP+O5PL/+HZ7bl7eVKXPlwupmP3wEjemXnWZvZ3g/r8VhRG/5kruHRI+fomLsIRIAFOb7pbyx1RxKlxmrh3NMY1BtbOS5xdwe2zzPPEtaMFeZhq+Brkx58fPFj9oWUyyEjCy6K24Np/pRNu2Wt+nLAkMXzdKHCpyOfMfRvmd6rktpgN/Iw=="
Dec 08 06:06:36 volumio go-librespot[24257]: time="2025-12-08T06:06:36-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 08 06:06:36 volumio go-librespot[24257]: time="2025-12-08T06:06:36-06:00" level=debug msg="completed keyexchange"
Dec 08 06:06:36 volumio go-librespot[24257]: time="2025-12-08T06:06:36-06:00" level=debug msg="completed challenge"
Dec 08 06:06:36 volumio go-librespot[24257]: time="2025-12-08T06:06:36-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 "
Dec 08 06:06:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 08 06:06:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 08 06:06:38 volumio volumio[23613]: info: Initializing connection to go-librespot Websocket
Dec 08 06:06:38 volumio volumio[23613]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 08 06:06:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12.
Dec 08 06:06:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:06:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:06:39 volumio go-librespot[24265]: go-librespot daemon starting...
Dec 08 06:06:40 volumio go-librespot[24266]: time="2025-12-08T06:06:40-06:00" level=info msg="running go-librespot 0.4.0"
Dec 08 06:06:40 volumio go-librespot[24266]: time="2025-12-08T06:06:40-06:00" level=debug msg="app state loaded"
Dec 08 06:06:40 volumio go-librespot[24266]: time="2025-12-08T06:06:40-06:00" level=debug msg="stored credentials not found"
Dec 08 06:06:40 volumio go-librespot[24266]: time="2025-12-08T06:06:40-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 08 06:06:40 volumio go-librespot[24266]: time="2025-12-08T06:06: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]"
Dec 08 06:06:40 volumio go-librespot[24266]: time="2025-12-08T06:06: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]"
Dec 08 06:06:40 volumio go-librespot[24266]: time="2025-12-08T06:06: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]"
Dec 08 06:06:40 volumio go-librespot[24266]: time="2025-12-08T06:06:40-06:00" level=info msg="zeroconf server listening on port 45599"
Dec 08 06:06:40 volumio go-librespot[24266]: time="2025-12-08T06:06:40-06:00" level=debug msg="obtained new client token: AACYE1aE2w58fI8G6Ll2BvK+yCBhUJ5+iwigLpGveZ+XTAVI8QuRYHvGQSwgTjAJsyD8SG4dS6gKM0RH71egZ16vl3MRbjD0eufD1xp6h+MrfqaAYQFtImUZ77hbQpU7CGtY8TM3nKMgTTuFDKk+B7FAqcMJeZieLUAlfWG34rhO5Pj+2hLrOcHWhzhcwnZU+1cKJRUBeJ6RNHT3aSpnl7lyPtBeg628K9REVvp7FZO6Vhn62mAYKxMS+Q=="
Dec 08 06:06:40 volumio go-librespot[24266]: time="2025-12-08T06:06:40-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 08 06:06:40 volumio go-librespot[24266]: time="2025-12-08T06:06:40-06:00" level=debug msg="completed keyexchange"
Dec 08 06:06:40 volumio go-librespot[24266]: time="2025-12-08T06:06:40-06:00" level=debug msg="completed challenge"
Dec 08 06:06:40 volumio go-librespot[24266]: time="2025-12-08T06:06: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 "
Dec 08 06:06:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 08 06:06:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 08 06:06:41 volumio volumio[23613]: info: BOOT COMPLETED
Dec 08 06:06:41 volumio volumio[23613]: info: Initializing connection to go-librespot Websocket
Dec 08 06:06:41 volumio volumio[23613]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 08 06:06:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13.
Dec 08 06:06:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:06:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:06:43 volumio go-librespot[24287]: go-librespot daemon starting...
Dec 08 06:06:43 volumio go-librespot[24291]: time="2025-12-08T06:06:43-06:00" level=info msg="running go-librespot 0.4.0"
Dec 08 06:06:43 volumio go-librespot[24291]: time="2025-12-08T06:06:43-06:00" level=debug msg="app state loaded"
Dec 08 06:06:43 volumio go-librespot[24291]: time="2025-12-08T06:06:43-06:00" level=debug msg="stored credentials not found"
Dec 08 06:06:43 volumio go-librespot[24291]: time="2025-12-08T06:06:43-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 08 06:06:44 volumio go-librespot[24291]: time="2025-12-08T06:06: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 08 06:06:44 volumio go-librespot[24291]: time="2025-12-08T06:06:44-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]"
Dec 08 06:06:44 volumio go-librespot[24291]: time="2025-12-08T06:06:44-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]"
Dec 08 06:06:44 volumio go-librespot[24291]: time="2025-12-08T06:06:44-06:00" level=info msg="zeroconf server listening on port 44359"
Dec 08 06:06:44 volumio go-librespot[24291]: time="2025-12-08T06:06:44-06:00" level=debug msg="obtained new client token: AAB8gWDvYFNKNyt2UNw0NCEaXHHKp0pqNev0a85o6yccvV8/JY90C2ggp/X94lO1MNLxksj0ILDDO233QiE73wBkf9y7/FCro+GV7hjNOpTkd8W9rtDd+zdEP2eZVuGJbW5pzOU0SBkCD8IWRPP96TCfwTcJ3geuIY8Bg81RUO0WnzN2OCPB8mNmpkfWGTN3NPSDTrcHMbiXSGCcbDht/6jGY3YLdQsYbNTV8My74qzzzhFBbdxKqo4="
Dec 08 06:06:44 volumio go-librespot[24291]: time="2025-12-08T06:06:44-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 08 06:06:44 volumio go-librespot[24291]: time="2025-12-08T06:06:44-06:00" level=debug msg="completed keyexchange"
Dec 08 06:06:44 volumio go-librespot[24291]: time="2025-12-08T06:06:44-06:00" level=debug msg="completed challenge"
Dec 08 06:06:44 volumio go-librespot[24291]: time="2025-12-08T06:06: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 "
Dec 08 06:06:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 08 06:06:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 08 06:06:44 volumio volumio[23613]: info: Initializing connection to go-librespot Websocket
Dec 08 06:06:44 volumio volumio[23613]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 08 06:06:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14.
Dec 08 06:06:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:06:47 volumio volumio[23613]: info: Initializing connection to go-librespot Websocket
Dec 08 06:06:47 volumio volumio[23613]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 08 06:06:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:06:47 volumio go-librespot[24298]: go-librespot daemon starting...
Dec 08 06:06:47 volumio go-librespot[24299]: time="2025-12-08T06:06:47-06:00" level=info msg="running go-librespot 0.4.0"
Dec 08 06:06:47 volumio go-librespot[24299]: time="2025-12-08T06:06:47-06:00" level=debug msg="app state loaded"
Dec 08 06:06:47 volumio go-librespot[24299]: time="2025-12-08T06:06:47-06:00" level=debug msg="stored credentials not found"
Dec 08 06:06:47 volumio go-librespot[24299]: time="2025-12-08T06:06:47-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 08 06:06:47 volumio go-librespot[24299]: time="2025-12-08T06:06:47-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]"
Dec 08 06:06:47 volumio go-librespot[24299]: time="2025-12-08T06:06:47-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]"
Dec 08 06:06:47 volumio go-librespot[24299]: time="2025-12-08T06:06:47-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]"
Dec 08 06:06:47 volumio go-librespot[24299]: time="2025-12-08T06:06:47-06:00" level=info msg="zeroconf server listening on port 44123"
Dec 08 06:06:47 volumio go-librespot[24299]: time="2025-12-08T06:06:47-06:00" level=debug msg="obtained new client token: AABnNqlN/8hgD8e+XcEY34GScVWFVxBc/dbxLelkBSDOZF5hAl4ulAD9z092yH+r/tjMXjcUxMnU4kE1GkjR65FahqVsMqpVWlTXBCLE5q3HSkBVcVe7M4geRIoP1Ia2U3RIQ1QX/uD43ClO1eg3w0zwcwzeI+xVBmd0rv35tCkxpSjPjuO4fuVzmzgRyh4TGA/j7K+duAvOYBebPZ4V3r6cE4LspMS+q9ZRpQSPcqQLXDSRCfa2CVra5A=="
Dec 08 06:06:47 volumio go-librespot[24299]: time="2025-12-08T06:06:47-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 08 06:06:47 volumio go-librespot[24299]: time="2025-12-08T06:06:47-06:00" level=debug msg="completed keyexchange"
Dec 08 06:06:47 volumio go-librespot[24299]: time="2025-12-08T06:06:47-06:00" level=debug msg="completed challenge"
Dec 08 06:06:47 volumio go-librespot[24299]: time="2025-12-08T06:06:47-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 "
Dec 08 06:06:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 08 06:06:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 08 06:06:50 volumio volumio[23613]: info: Initializing connection to go-librespot Websocket
Dec 08 06:06:50 volumio volumio[23613]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 08 06:06:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15.
Dec 08 06:06:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:06:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:06:51 volumio go-librespot[24306]: go-librespot daemon starting...
Dec 08 06:06:51 volumio go-librespot[24307]: time="2025-12-08T06:06:51-06:00" level=info msg="running go-librespot 0.4.0"
Dec 08 06:06:51 volumio go-librespot[24307]: time="2025-12-08T06:06:51-06:00" level=debug msg="app state loaded"
Dec 08 06:06:51 volumio go-librespot[24307]: time="2025-12-08T06:06:51-06:00" level=debug msg="stored credentials not found"
Dec 08 06:06:51 volumio go-librespot[24307]: time="2025-12-08T06:06:51-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 08 06:06:51 volumio go-librespot[24307]: time="2025-12-08T06:06: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 08 06:06:51 volumio go-librespot[24307]: time="2025-12-08T06:06:51-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]"
Dec 08 06:06:51 volumio go-librespot[24307]: time="2025-12-08T06:06:51-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]"
Dec 08 06:06:51 volumio go-librespot[24307]: time="2025-12-08T06:06:51-06:00" level=info msg="zeroconf server listening on port 43817"
Dec 08 06:06:51 volumio go-librespot[24307]: time="2025-12-08T06:06:51-06:00" level=debug msg="obtained new client token: AAAed45oizRUM+MuN68dMwP5TWs2WnUti2ZLBt2BXrCsS2uYsXSpinxWbupmPLQomQnEIGc/ij/VklBttmhuxiU/p++j7M/nuSuBbD+Sn9vflYfKrrfGtBUw8a8tTIIBtQmeodGZREkRIdHe64JF6YPO9MrqrTtXyG0/+sMKkE+Pb//pO8V6wk/Y93XdcIZXtrzWRdHYnz4+D8iCe2HnCha1RIe6Y+YKpU5T/IEjKD0U20BjZGuE+4H/SQ=="
Dec 08 06:06:51 volumio go-librespot[24307]: time="2025-12-08T06:06:51-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 08 06:06:51 volumio go-librespot[24307]: time="2025-12-08T06:06:51-06:00" level=debug msg="completed keyexchange"
Dec 08 06:06:51 volumio go-librespot[24307]: time="2025-12-08T06:06:51-06:00" level=debug msg="completed challenge"
Dec 08 06:06:51 volumio go-librespot[24307]: time="2025-12-08T06:06:51-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 "
Dec 08 06:06:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 08 06:06:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 08 06:06:53 volumio volumio[23613]: info: Initializing connection to go-librespot Websocket
Dec 08 06:06:53 volumio volumio[23613]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 08 06:06:54 volumio volumio[23613]: info: UPDATER: Scheduling automatic update
Dec 08 06:06:54 volumio volumio[23613]: info: CoreCommandRouter::executeOnPlugin: system , getAutoUpdateWindowStartTime
Dec 08 06:06:54 volumio volumio[23613]: info: CoreCommandRouter::executeOnPlugin: system , getAutoUpdateWindowStopTime
Dec 08 06:06:54 volumio volumio[23613]: info: UPDATER: Auto update will take place at: Tue Dec 09 2025 04:27:07 GMT-0600 (Central Standard Time)
Dec 08 06:06:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16.
Dec 08 06:06:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:06:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:06:54 volumio go-librespot[24328]: go-librespot daemon starting...
Dec 08 06:06:55 volumio go-librespot[24329]: time="2025-12-08T06:06:55-06:00" level=info msg="running go-librespot 0.4.0"
Dec 08 06:06:55 volumio go-librespot[24329]: time="2025-12-08T06:06:55-06:00" level=debug msg="app state loaded"
Dec 08 06:06:55 volumio go-librespot[24329]: time="2025-12-08T06:06:55-06:00" level=debug msg="stored credentials not found"
Dec 08 06:06:55 volumio go-librespot[24329]: time="2025-12-08T06:06:55-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 08 06:06:55 volumio go-librespot[24329]: time="2025-12-08T06:06: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-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Dec 08 06:06:55 volumio go-librespot[24329]: time="2025-12-08T06:06:55-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]"
Dec 08 06:06:55 volumio go-librespot[24329]: time="2025-12-08T06:06:55-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]"
Dec 08 06:06:55 volumio go-librespot[24329]: time="2025-12-08T06:06:55-06:00" level=info msg="zeroconf server listening on port 38899"
Dec 08 06:06:55 volumio go-librespot[24329]: time="2025-12-08T06:06:55-06:00" level=debug msg="obtained new client token: AAAKBpo61+P/Xr2UfpwAK5jpRb76Nfbv0cQRa16srna+f5RwandCg2GrpHCTQOi4gh8WuAwQ20KKfjG9o61v221qnCs4BVXrLccI2kz6K5bwjF2uRr9R+FVuFAOlsrjmq4GbIdbeyAQLeRaWhxlvoqMMF35rTOaXqauue/bZ7XjdjMYgpQ7UVcWUD6nyoxQOJEA2qKRAMuw8IniOUFjXcpBXIirbfsZfBlJHIv+WXG8LV78PZq7Qk2NdEQ=="
Dec 08 06:06:55 volumio go-librespot[24329]: time="2025-12-08T06:06:55-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 08 06:06:55 volumio go-librespot[24329]: time="2025-12-08T06:06:55-06:00" level=debug msg="completed keyexchange"
Dec 08 06:06:55 volumio go-librespot[24329]: time="2025-12-08T06:06:55-06:00" level=debug msg="completed challenge"
Dec 08 06:06:55 volumio go-librespot[24329]: time="2025-12-08T06:06: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 "
Dec 08 06:06:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 08 06:06:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 08 06:06:56 volumio volumio[23613]: info: Initializing connection to go-librespot Websocket
Dec 08 06:06:56 volumio volumio[23613]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 08 06:06:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17.
Dec 08 06:06:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:06:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:06:58 volumio go-librespot[24337]: go-librespot daemon starting...
Dec 08 06:06:58 volumio go-librespot[24338]: time="2025-12-08T06:06:58-06:00" level=info msg="running go-librespot 0.4.0"
Dec 08 06:06:58 volumio go-librespot[24338]: time="2025-12-08T06:06:58-06:00" level=debug msg="app state loaded"
Dec 08 06:06:58 volumio go-librespot[24338]: time="2025-12-08T06:06:58-06:00" level=debug msg="stored credentials not found"
Dec 08 06:06:58 volumio go-librespot[24338]: time="2025-12-08T06:06:58-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 08 06:06:58 volumio go-librespot[24338]: time="2025-12-08T06:06:58-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]"
Dec 08 06:06:58 volumio go-librespot[24338]: time="2025-12-08T06:06:58-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]"
Dec 08 06:06:58 volumio go-librespot[24338]: time="2025-12-08T06:06:58-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]"
Dec 08 06:06:58 volumio go-librespot[24338]: time="2025-12-08T06:06:58-06:00" level=info msg="zeroconf server listening on port 37563"
Dec 08 06:06:59 volumio go-librespot[24338]: time="2025-12-08T06:06:59-06:00" level=debug msg="obtained new client token: AAAEvcVw0sYvry8jfTkPqjWcXIig3AravK5o4XcDjhohfBdi9Cn1CiyY/iPRomadB3xZPKFqUnLx9IEklLAhRuZoFTCYfrhBFjRObY66Gl3WW63LgUUpnSjm/dznTAZzKZ6QelNHNEXOzkSMQa9/ePghL9qM4CN7/2IJZ4VmHA76umnAsw503OZYG2ZeGLM8vvbmEI1zKbnVCHNNqYkfzJ0bd9lLbZpkar/ScZ8yMuvDwyxynT1VKdE="
Dec 08 06:06:59 volumio go-librespot[24338]: time="2025-12-08T06:06:59-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 08 06:06:59 volumio go-librespot[24338]: time="2025-12-08T06:06:59-06:00" level=debug msg="completed keyexchange"
Dec 08 06:06:59 volumio go-librespot[24338]: time="2025-12-08T06:06:59-06:00" level=debug msg="completed challenge"
Dec 08 06:06:59 volumio go-librespot[24338]: time="2025-12-08T06:06: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 "
Dec 08 06:06:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 08 06:06:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 08 06:06:59 volumio volumio[23613]: info: Initializing connection to go-librespot Websocket
Dec 08 06:06:59 volumio volumio[23613]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 08 06:07:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18.
Dec 08 06:07:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:07:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:07:02 volumio go-librespot[24359]: go-librespot daemon starting...
Dec 08 06:07:02 volumio volumio[23613]: info: Initializing connection to go-librespot Websocket
Dec 08 06:07:02 volumio volumio[23613]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 08 06:07:02 volumio go-librespot[24360]: time="2025-12-08T06:07:02-06:00" level=info msg="running go-librespot 0.4.0"
Dec 08 06:07:02 volumio go-librespot[24360]: time="2025-12-08T06:07:02-06:00" level=debug msg="app state loaded"
Dec 08 06:07:02 volumio go-librespot[24360]: time="2025-12-08T06:07:02-06:00" level=debug msg="stored credentials not found"
Dec 08 06:07:02 volumio go-librespot[24360]: time="2025-12-08T06:07:02-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 08 06:07:02 volumio go-librespot[24360]: time="2025-12-08T06:07:02-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]"
Dec 08 06:07:02 volumio go-librespot[24360]: time="2025-12-08T06:07:02-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]"
Dec 08 06:07:02 volumio go-librespot[24360]: time="2025-12-08T06:07:02-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]"
Dec 08 06:07:02 volumio go-librespot[24360]: time="2025-12-08T06:07:02-06:00" level=info msg="zeroconf server listening on port 35513"
Dec 08 06:07:02 volumio go-librespot[24360]: time="2025-12-08T06:07:02-06:00" level=debug msg="obtained new client token: AAA1d0eNHNkaGL7y/HxZRtBty2f1HJeNrQOxTYqQkYgxKSy5YHkTRsl/cGh4iQKtET8fx4MY6BiuBMalZ/BfTNWh5tLnHz8n3V9qi3YNp8dSNXBb2pX1vIZNaCFc7nDtCL3sicONJDr5se8tMGipqZ9l+KRWyoaLrYL2LtVAskIKHz5lUvUaIRfkRSvIWAkxsGsTmR5HNJOcL6BoUzd4BXLRMVe6qZ3hz6ce8lbyStApUqahwaDR+b6nwA=="
Dec 08 06:07:02 volumio go-librespot[24360]: time="2025-12-08T06:07:02-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 08 06:07:02 volumio go-librespot[24360]: time="2025-12-08T06:07:02-06:00" level=debug msg="completed keyexchange"
Dec 08 06:07:02 volumio go-librespot[24360]: time="2025-12-08T06:07:02-06:00" level=debug msg="completed challenge"
Dec 08 06:07:02 volumio go-librespot[24360]: time="2025-12-08T06:07:02-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 "
Dec 08 06:07:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 08 06:07:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 08 06:07:05 volumio volumio[23613]: info: Initializing connection to go-librespot Websocket
Dec 08 06:07:05 volumio volumio[23613]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 08 06:07:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19.
Dec 08 06:07:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:07:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:07:06 volumio go-librespot[24370]: go-librespot daemon starting...
Dec 08 06:07:06 volumio go-librespot[24371]: time="2025-12-08T06:07:06-06:00" level=info msg="running go-librespot 0.4.0"
Dec 08 06:07:06 volumio go-librespot[24371]: time="2025-12-08T06:07:06-06:00" level=debug msg="app state loaded"
Dec 08 06:07:06 volumio go-librespot[24371]: time="2025-12-08T06:07:06-06:00" level=debug msg="stored credentials not found"
Dec 08 06:07:06 volumio go-librespot[24371]: time="2025-12-08T06:07:06-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 08 06:07:06 volumio go-librespot[24371]: time="2025-12-08T06:07: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]"
Dec 08 06:07:06 volumio go-librespot[24371]: time="2025-12-08T06:07: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]"
Dec 08 06:07:06 volumio go-librespot[24371]: time="2025-12-08T06:07: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]"
Dec 08 06:07:06 volumio go-librespot[24371]: time="2025-12-08T06:07:06-06:00" level=info msg="zeroconf server listening on port 44087"
Dec 08 06:07:06 volumio go-librespot[24371]: time="2025-12-08T06:07:06-06:00" level=debug msg="obtained new client token: AAAQ5z2gpj6LR5r6fzaPuESawh0xZ4I7gnyJrPRTzbvG/t+Pq0mhY4D9DDb373C9geOW1Q3I1ZNy5RJ14Q96S1kX8hYNxt14qkWkP9nEVVjfWTEUhEQ+lZR2s6v5rp4GgS1B4VMv/Cb1dRYuczTQjCspEVADoqXd78YdG5BOoGlbf5VPjvZrvT0DzM9E+gFwpbseVnL6cTd5sE/sHIX3mD/syyRRMIudYIdGSsCGN1Jt7QDqR1gZH+2O4Q=="
Dec 08 06:07:06 volumio go-librespot[24371]: time="2025-12-08T06:07:06-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 08 06:07:06 volumio go-librespot[24371]: time="2025-12-08T06:07:06-06:00" level=debug msg="completed keyexchange"
Dec 08 06:07:06 volumio go-librespot[24371]: time="2025-12-08T06:07:06-06:00" level=debug msg="completed challenge"
Dec 08 06:07:06 volumio go-librespot[24371]: time="2025-12-08T06:07:06-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 "
Dec 08 06:07:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 08 06:07:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 08 06:07:08 volumio volumio[23613]: info: Initializing connection to go-librespot Websocket
Dec 08 06:07:08 volumio volumio[23613]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 08 06:07:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20.
Dec 08 06:07:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:07:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:07:10 volumio go-librespot[24378]: go-librespot daemon starting...
Dec 08 06:07:10 volumio go-librespot[24379]: time="2025-12-08T06:07:10-06:00" level=info msg="running go-librespot 0.4.0"
Dec 08 06:07:10 volumio go-librespot[24379]: time="2025-12-08T06:07:10-06:00" level=debug msg="app state loaded"
Dec 08 06:07:10 volumio go-librespot[24379]: time="2025-12-08T06:07:10-06:00" level=debug msg="stored credentials not found"
Dec 08 06:07:10 volumio go-librespot[24379]: time="2025-12-08T06:07:10-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 08 06:07:10 volumio go-librespot[24379]: time="2025-12-08T06:07: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-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 08 06:07:10 volumio go-librespot[24379]: time="2025-12-08T06:07:10-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]"
Dec 08 06:07:10 volumio go-librespot[24379]: time="2025-12-08T06:07:10-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]"
Dec 08 06:07:10 volumio go-librespot[24379]: time="2025-12-08T06:07:10-06:00" level=info msg="zeroconf server listening on port 35367"
Dec 08 06:07:10 volumio go-librespot[24379]: time="2025-12-08T06:07:10-06:00" level=debug msg="obtained new client token: AABJy+4d6lwMZz5TCrOUxBaEwypFMsz8fABuKOArNKfFo/yZxfxVsvmQDY5dPH2a/OTSLjnDh5NlQ06vvc3dR5et8zmaLleMr+1pISq++If/3kZHQfe5UJwHSHDfGqsK78afgF/nUSV25+mTnVE/WJT6rmVXwlNq1QXKxi7Yvezxk4ZF1v3ZZcUfas3MHLBC/Rm5kXmlWqV8wEKbdxqlLzEVrNpl+Wy/LnvvP8TCDMQGqaffNUPVVhSBVA=="
Dec 08 06:07:10 volumio go-librespot[24379]: time="2025-12-08T06:07:10-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused"
Dec 08 06:07:10 volumio go-librespot[24379]: time="2025-12-08T06:07:10-06:00" level=debug msg="connected to ap-guc3.spotify.com:443"
Dec 08 06:07:10 volumio go-librespot[24379]: time="2025-12-08T06:07:10-06:00" level=debug msg="completed keyexchange"
Dec 08 06:07:10 volumio go-librespot[24379]: time="2025-12-08T06:07:10-06:00" level=debug msg="completed challenge"
Dec 08 06:07:10 volumio go-librespot[24379]: time="2025-12-08T06:07: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 "
Dec 08 06:07:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 08 06:07:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 08 06:07:11 volumio volumio[23613]: info: Initializing connection to go-librespot Websocket
Dec 08 06:07:11 volumio volumio[23613]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 08 06:07:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21.
Dec 08 06:07:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:07:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:07:13 volumio go-librespot[24400]: go-librespot daemon starting...
Dec 08 06:07:13 volumio go-librespot[24401]: time="2025-12-08T06:07:13-06:00" level=info msg="running go-librespot 0.4.0"
Dec 08 06:07:13 volumio go-librespot[24401]: time="2025-12-08T06:07:13-06:00" level=debug msg="app state loaded"
Dec 08 06:07:13 volumio go-librespot[24401]: time="2025-12-08T06:07:13-06:00" level=debug msg="stored credentials not found"
Dec 08 06:07:13 volumio go-librespot[24401]: time="2025-12-08T06:07:13-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 08 06:07:13 volumio go-librespot[24401]: time="2025-12-08T06:07:13-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]"
Dec 08 06:07:13 volumio go-librespot[24401]: time="2025-12-08T06:07:13-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]"
Dec 08 06:07:13 volumio go-librespot[24401]: time="2025-12-08T06:07:13-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]"
Dec 08 06:07:13 volumio go-librespot[24401]: time="2025-12-08T06:07:13-06:00" level=info msg="zeroconf server listening on port 42233"
Dec 08 06:07:14 volumio go-librespot[24401]: time="2025-12-08T06:07:14-06:00" level=debug msg="obtained new client token: AADmD4THMH69EY1HjsUeV1sjrtw1fwGdlTZUYeN3pYOwo+u9DU8AICq6M2REUkqUh/JJXtzqb7S+q8N12q5VZe05ubCSgSFRai9XUIKl4ud/dv95fHmGRfvkDVTBrpwVbJhJvLsFE2aDxOeocoFrMA72XzETJi0avm1cR2NKX4X9emmtysPvhO3ZQv2QDEGmA8EQUjcRFmtV5qsa8/vNgafdpKRLmxdPZqjQxI6z/9Mlt0W6G7Uex6k="
Dec 08 06:07:14 volumio go-librespot[24401]: time="2025-12-08T06:07:14-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 08 06:07:14 volumio go-librespot[24401]: time="2025-12-08T06:07:14-06:00" level=debug msg="completed keyexchange"
Dec 08 06:07:14 volumio go-librespot[24401]: time="2025-12-08T06:07:14-06:00" level=debug msg="completed challenge"
Dec 08 06:07:14 volumio go-librespot[24401]: time="2025-12-08T06:07: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 "
Dec 08 06:07:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 08 06:07:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 08 06:07:14 volumio volumio[23613]: info: Initializing connection to go-librespot Websocket
Dec 08 06:07:14 volumio volumio[23613]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 08 06:07:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22.
Dec 08 06:07:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:07:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:07:17 volumio go-librespot[24409]: go-librespot daemon starting...
Dec 08 06:07:17 volumio go-librespot[24410]: time="2025-12-08T06:07:17-06:00" level=info msg="running go-librespot 0.4.0"
Dec 08 06:07:17 volumio go-librespot[24410]: time="2025-12-08T06:07:17-06:00" level=debug msg="app state loaded"
Dec 08 06:07:17 volumio go-librespot[24410]: time="2025-12-08T06:07:17-06:00" level=debug msg="stored credentials not found"
Dec 08 06:07:17 volumio go-librespot[24410]: time="2025-12-08T06:07:17-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 08 06:07:17 volumio volumio[23613]: info: Initializing connection to go-librespot Websocket
Dec 08 06:07:17 volumio go-librespot[24410]: time="2025-12-08T06:07:17-06:00" level=debug msg="new websocket client"
Dec 08 06:07:17 volumio volumio[23613]: info: Connection to go-librespot Websocket established
Dec 08 06:07:17 volumio go-librespot[24410]: time="2025-12-08T06:07:17-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]"
Dec 08 06:07:17 volumio go-librespot[24410]: time="2025-12-08T06:07:17-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]"
Dec 08 06:07:17 volumio go-librespot[24410]: time="2025-12-08T06:07:17-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]"
Dec 08 06:07:17 volumio go-librespot[24410]: time="2025-12-08T06:07:17-06:00" level=info msg="zeroconf server listening on port 45745"
Dec 08 06:07:17 volumio go-librespot[24410]: time="2025-12-08T06:07:17-06:00" level=debug msg="obtained new client token: AADvIt3dIxfjUDsUE2STTMvNijXC88y6T31Z2+AAxEdmHMptPcGFHJ3cMmm/pnNeQzdW668I+4lDbwiBMO+g29HCjav4NogMT2ht6crgGw8nfBmb1yiL7w56YWJh/nKkh/D9/Z70B9ANPl+sWzy+681ZFYmUikkH2USL7pduhkqCfNdHWvE7NzKnAlX1eSgEl1Jpcy5W5/24xCMlMiycLnSmGY0thPnM0PXybDEQmx3KIWTNDTAIBaVLnA=="
Dec 08 06:07:17 volumio go-librespot[24410]: time="2025-12-08T06:07:17-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 08 06:07:17 volumio go-librespot[24410]: time="2025-12-08T06:07:17-06:00" level=debug msg="completed keyexchange"
Dec 08 06:07:17 volumio go-librespot[24410]: time="2025-12-08T06:07:17-06:00" level=debug msg="completed challenge"
Dec 08 06:07:17 volumio go-librespot[24410]: time="2025-12-08T06:07:17-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 "
Dec 08 06:07:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 08 06:07:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 08 06:07:17 volumio volumio[23613]: info: Connection to go-librespot Websocket closed
Dec 08 06:07:20 volumio volumio[23613]: info: Getting Spotify volume
Dec 08 06:07:20 volumio volumio[23613]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 08 06:07:20 volumio volumio[23613]: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 08 06:07:20 volumio volumio[23613]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Dec 08 06:07:20 volumio volumio[23613]: errno: -111,
Dec 08 06:07:20 volumio volumio[23613]: code: 'ECONNREFUSED',
Dec 08 06:07:20 volumio volumio[23613]: syscall: 'connect',
Dec 08 06:07:20 volumio volumio[23613]: address: '127.0.0.1',
Dec 08 06:07:20 volumio volumio[23613]: port: 9879,
Dec 08 06:07:20 volumio volumio[23613]: response: undefined
Dec 08 06:07:20 volumio volumio[23613]: }
Dec 08 06:07:20 volumio volumio[23613]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 08 06:07:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23.
Dec 08 06:07:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:07:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 08 06:07:21 volumio go-librespot[24429]: go-librespot daemon starting...
Dec 08 06:07:21 volumio go-librespot[24430]: time="2025-12-08T06:07:21-06:00" level=info msg="running go-librespot 0.4.0"
Dec 08 06:07:21 volumio go-librespot[24430]: time="2025-12-08T06:07:21-06:00" level=debug msg="app state loaded"
Dec 08 06:07:21 volumio go-librespot[24430]: time="2025-12-08T06:07:21-06:00" level=debug msg="stored credentials not found"
Dec 08 06:07:21 volumio go-librespot[24430]: time="2025-12-08T06:07:21-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 08 06:07:21 volumio sudo[24439]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-08 06:06'
Dec 08 06:07:21 volumio sudo[24439]: 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"