-- Logs begin at Thu 2019-02-14 10:11:58 GMT, end at Mon 2025-06-16 20:41:02 BST. -- Jun 16 20:40:01 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 20:40:01 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 48. Jun 16 20:40:01 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 20:40:01 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 20:40:01 richdacvolumio go-librespot[11408]: Librespot-go daemon starting... Jun 16 20:40:01 richdacvolumio go-librespot[11408]: time="2025-06-16T20:40:01+01:00" level=info msg="generated new device id: e75d89b76093b4a6971e69368694862b4afdbfa7" Jun 16 20:40:01 richdacvolumio go-librespot[11408]: time="2025-06-16T20:40:01+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 20:40:01 richdacvolumio go-librespot[11408]: time="2025-06-16T20:40:01+01:00" level=debug msg="obtained new client token: AACUNSh3CaqGxHMLSrZjWuStt2nyBdiD3Xj9Z/qMCCDBtP9z6ZMChWNy9XiiApHcrnPAbr3/PU5Sc2eIaaiNhBHc1Mi4Y5Cicjt6KSYYS5C4zu7RVWwvZjPOIACqNSmhjEvFM02psKq5ColJQIWhXH+rU5vEt1xMJc10A3Vyd1FfFHb1b2buA2vEcRp5F0H0QXxBItUhdsGt5y93dPpG3nU27W0tchsdSJpdUODgJSnCHDX2lfrNBIg/9MUhig==" Jun 16 20:40:01 richdacvolumio go-librespot[11408]: time="2025-06-16T20:40:01+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jun 16 20:40:02 richdacvolumio go-librespot[11408]: time="2025-06-16T20:40:02+01:00" level=debug msg="completed keyexchange" Jun 16 20:40:02 richdacvolumio go-librespot[11408]: time="2025-06-16T20:40:02+01:00" level=debug msg="completed challenge" Jun 16 20:40:02 richdacvolumio go-librespot[11408]: time="2025-06-16T20:40:02+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jun 16 20:40:02 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 20:40:02 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 20:40:05 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 20:40:05 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 49. Jun 16 20:40:05 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 20:40:05 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 20:40:05 richdacvolumio go-librespot[11417]: Librespot-go daemon starting... Jun 16 20:40:05 richdacvolumio go-librespot[11417]: time="2025-06-16T20:40:05+01:00" level=info msg="generated new device id: 2afb529ce693352697deaacb1fec529195e782c9" Jun 16 20:40:05 richdacvolumio go-librespot[11417]: time="2025-06-16T20:40:05+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 20:40:06 richdacvolumio go-librespot[11417]: time="2025-06-16T20:40:06+01:00" level=debug msg="obtained new client token: AAAcb4aIfm0yCmkSzDsl0ym09zRxZKZr2VLnzTSOPWC+SEOJu2nWxtkBzF2bKxzn+nqDDvMBWJXgE9zgXbAXfhTgN2XyyHkEg0mrs3M7hEzN1RvpGz6Mag8Ckk3jR5RE7cHsO/0N7/9TKbNTvXpBVkoGkeiZ2NTeQTy0thf2gADnt5rb95SQlyxtRLluEJ+9yF3IXW4TeGLOxE9QQfeTQ8TTeoYtRVylUZJ8/RszrXoifxYDT5hssjlS+2E=" Jun 16 20:40:06 richdacvolumio go-librespot[11417]: time="2025-06-16T20:40:06+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jun 16 20:40:06 richdacvolumio go-librespot[11417]: time="2025-06-16T20:40:06+01:00" level=debug msg="completed keyexchange" Jun 16 20:40:06 richdacvolumio go-librespot[11417]: time="2025-06-16T20:40:06+01:00" level=debug msg="completed challenge" Jun 16 20:40:06 richdacvolumio go-librespot[11417]: time="2025-06-16T20:40:06+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jun 16 20:40:06 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 20:40:06 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 20:40:07 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:07 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:07 richdacvolumio volumio[9938]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 16 20:40:07 richdacvolumio volumio[9938]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 16 20:40:07 richdacvolumio volumio[9938]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 16 20:40:07 richdacvolumio volumio[9938]: info: Initializing connection to go-librespot Websocket Jun 16 20:40:07 richdacvolumio volumio[9938]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 20:40:07 richdacvolumio volumio[9938]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 20:40:07 richdacvolumio volumio[9938]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Jun 16 20:40:07 richdacvolumio volumio[9938]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Jun 16 20:40:07 richdacvolumio volumio[9938]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jun 16 20:40:07 richdacvolumio volumio[9938]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jun 16 20:40:07 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetBrowseSources Jun 16 20:40:07 richdacvolumio volumio[9938]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 16 20:40:07 richdacvolumio volumio[9938]: error: MyVolumio Plugin failed to authenticate in a timely fashion Jun 16 20:40:07 richdacvolumio volumio[9938]: info: Completed starting MyVolumio Plugin Jun 16 20:40:07 richdacvolumio volumio[9938]: [Metrics] CommandRouter: 77s 345.55ms Jun 16 20:40:07 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumiosetStartupVolume Jun 16 20:40:07 richdacvolumio volumio[9938]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 20:40:07 richdacvolumio volumio[9938]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 16 20:40:07 richdacvolumio volumio[9938]: info: CoreCommandRouter::Close All Modals sent Jun 16 20:40:07 richdacvolumio volumio[9938]: info: CoreCommandRouter::Close All Modals sent Jun 16 20:40:09 richdacvolumio volumio-remote-updater[645]: No test mode Jun 16 20:40:09 richdacvolumio volumio-remote-updater[645]: No alpha test mode Jun 16 20:40:09 richdacvolumio volumio[9938]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Jun 16 20:40:09 richdacvolumio volumio[9938]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jun 16 20:40:09 richdacvolumio volumio[9938]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 16 20:40:09 richdacvolumio volumio[9938]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jun 16 20:40:09 richdacvolumio volumio[9938]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jun 16 20:40:09 richdacvolumio volumio[9938]: info: FusionDsp - ---- read samplerate from file: 44100 Jun 16 20:40:09 richdacvolumio volumio[9938]: info: camilladsp stopping service pid 10749... Jun 16 20:40:09 richdacvolumio volumio[9938]: grep: /proc/10749/cmdline: No such file or directory Jun 16 20:40:09 richdacvolumio volumio[9938]: info: camilladsp service terminated, instance 1 Jun 16 20:40:09 richdacvolumio volumio[9938]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 16 20:40:09 richdacvolumio volumio[9938]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 20:40:09 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:09 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:09 richdacvolumio volumio[9938]: info: camilladsp spawned new process with pid 11439, instance 1, run: true Jun 16 20:40:09 richdacvolumio volumio[9938]: info: camilladsp service started and running in background, instance 1 Jun 16 20:40:10 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 20:40:10 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50. Jun 16 20:40:10 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 20:40:10 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 20:40:10 richdacvolumio go-librespot[11446]: Librespot-go daemon starting... Jun 16 20:40:10 richdacvolumio go-librespot[11446]: time="2025-06-16T20:40:10+01:00" level=info msg="generated new device id: 7b47fd206e86fb4a68602e251d2e4b55e340d349" Jun 16 20:40:10 richdacvolumio go-librespot[11446]: time="2025-06-16T20:40:10+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 20:40:10 richdacvolumio go-librespot[11446]: time="2025-06-16T20:40:10+01:00" level=debug msg="obtained new client token: AACo3kDziPx2dbm2Jdfj2RmPib4Nw09N+5mulz+oKP6XPzs2cYbZ1ViUs/cEsse1VpXXGdv3LxcKg/pOGuS3HLkZJWsBtdGrYXp8MBmwcX47t4woeiyY8ZYf8y3pCFZXkLDmPzgOQfntLfQCbFBSlVcEcwsPV4q5yTu5KuTt2kkNFjrw8ylX53i1PdESDwXwih35U45kZ31MH/9GauW8WgcAxlTsXD7Nqy3r4WLnNGdOJk1DPomh1R2R9xfn0g==" Jun 16 20:40:10 richdacvolumio go-librespot[11446]: time="2025-06-16T20:40:10+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jun 16 20:40:10 richdacvolumio go-librespot[11446]: time="2025-06-16T20:40:10+01:00" level=debug msg="completed keyexchange" Jun 16 20:40:10 richdacvolumio volumio[9938]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Jun 16 20:40:10 richdacvolumio volumio[9938]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Jun 16 20:40:10 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:10 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:10 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:10 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:11 richdacvolumio go-librespot[11446]: time="2025-06-16T20:40:11+01:00" level=debug msg="completed challenge" Jun 16 20:40:11 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:11 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:11 richdacvolumio go-librespot[11446]: time="2025-06-16T20:40:11+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jun 16 20:40:11 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:11 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:11 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 20:40:11 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 20:40:11 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:11 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:11 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:11 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:11 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:11 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:11 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:11 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:12 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:12 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:12 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:12 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:12 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:12 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:12 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:12 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:12 richdacvolumio volumio[9938]: info: Initializing connection to go-librespot Websocket Jun 16 20:40:12 richdacvolumio volumio[9938]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 20:40:12 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:12 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:12 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:12 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:13 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:13 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:13 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:13 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:13 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:13 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:13 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:13 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:13 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:13 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:13 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:13 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:14 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:14 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:14 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:14 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:14 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 20:40:14 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 51. Jun 16 20:40:14 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 20:40:14 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 20:40:14 richdacvolumio go-librespot[11534]: Librespot-go daemon starting... Jun 16 20:40:14 richdacvolumio go-librespot[11534]: time="2025-06-16T20:40:14+01:00" level=info msg="generated new device id: 8a8ded597c96b203d6f9f4705d02687b52547270" Jun 16 20:40:14 richdacvolumio go-librespot[11534]: time="2025-06-16T20:40:14+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 20:40:14 richdacvolumio volumio[9938]: info: BOOT COMPLETED Jun 16 20:40:14 richdacvolumio volumio[9938]: info: mpdhttpout ---Boot completed detected! Patching mpd now! Jun 16 20:40:14 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:14 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:14 richdacvolumio volumio[9938]: info: mpdhttpout ---Configuration successfully replaced in mpd.conf. Jun 16 20:40:14 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:14 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:14 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioPause Jun 16 20:40:14 richdacvolumio volumio[9938]: info: CoreStateMachine::pause Jun 16 20:40:14 richdacvolumio volumio[9938]: info: mpdhttpout --- Volumio set on pause Jun 16 20:40:14 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:14 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:14 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:14 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:14 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:14 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:15 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:15 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:15 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:15 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:15 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:15 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:15 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:15 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:15 richdacvolumio volumio[9938]: info: Initializing connection to go-librespot Websocket Jun 16 20:40:15 richdacvolumio go-librespot[11534]: time="2025-06-16T20:40:15+01:00" level=debug msg="new websocket client" Jun 16 20:40:15 richdacvolumio volumio[9938]: info: Connection to go-librespot Websocket established Jun 16 20:40:15 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:15 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:15 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:15 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:16 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:16 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:16 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:16 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:16 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:16 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:16 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:16 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:16 richdacvolumio volumio[9938]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd Jun 16 20:40:16 richdacvolumio sudo[11587]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 16 20:40:16 richdacvolumio sudo[11587]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 20:40:16 richdacvolumio systemd[1]: Stopping MPD OLED Plugin... Jun 16 20:40:16 richdacvolumio systemd[1]: mpd_oled_plugin.service: Main process exited, code=killed, status=15/TERM Jun 16 20:40:16 richdacvolumio systemd[1]: mpd_oled_plugin.service: Succeeded. Jun 16 20:40:16 richdacvolumio systemd[1]: Stopped MPD OLED Plugin. Jun 16 20:40:16 richdacvolumio systemd[1]: Stopping Music Player Daemon... Jun 16 20:40:16 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:16 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:16 richdacvolumio systemd[1]: mpd.service: Succeeded. Jun 16 20:40:16 richdacvolumio systemd[1]: Stopped Music Player Daemon. Jun 16 20:40:16 richdacvolumio systemd[1]: Starting Music Player Daemon... Jun 16 20:40:16 richdacvolumio sudo[11589]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 16 20:40:16 richdacvolumio sudo[11589]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 20:40:16 richdacvolumio sudo[11589]: pam_unix(sudo:session): session closed for user root Jun 16 20:40:17 richdacvolumio mpd[11592]: Jun 16 20:40 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 16 20:40:17 richdacvolumio systemd[1]: Started Music Player Daemon. Jun 16 20:40:17 richdacvolumio sudo[11587]: pam_unix(sudo:session): session closed for user root Jun 16 20:40:17 richdacvolumio volumio[9938]: error: updateQueue error: null Jun 16 20:40:17 richdacvolumio systemd[1]: Started MPD OLED Plugin. Jun 16 20:40:17 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:17 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:17 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:17 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:17 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:17 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:17 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:17 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:18 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:18 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:18 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:18 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:18 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:18 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:18 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:18 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:18 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:18 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:18 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:18 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:18 richdacvolumio volumio[9938]: info: Getting Spotify volume Jun 16 20:40:18 richdacvolumio volumio[9938]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Jun 16 20:40:18 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:18 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:18 richdacvolumio volumio[9938]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 16 20:40:19 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:19 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:19 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:19 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:19 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:19 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:19 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:19 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:19 richdacvolumio go-librespot[11534]: time="2025-06-16T20:40:19+01:00" level=debug msg="obtained new client token: AACd2FZqknq1H/LnR4yIfmWttKgy184IumxtJmkhindLtZ28Z9//aOUWxcWL7gIVReaGKOmtTmIEgPvBRLf/mPskPruQTA1E2dpPuIZR1YmHVVv0XCPFnUOwtKs6AzqPU1FTpUPJU1Xmww2vkVXLuKTzkO4psbuRJOZyOVNj2XAdpG1wZXAdfKqMtS1UW2Qqx54Xz6BKRD9ql/DYZZXIprZp/ftZtQq3Mrnz6t9ochmbvMtZKJt4mciZCuXI0w==" Jun 16 20:40:19 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:19 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:19 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:19 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:19 richdacvolumio go-librespot[11534]: time="2025-06-16T20:40:19+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jun 16 20:40:20 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:20 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:20 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:20 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:20 richdacvolumio go-librespot[11534]: time="2025-06-16T20:40:20+01:00" level=debug msg="completed keyexchange" Jun 16 20:40:20 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:20 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:20 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:20 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:20 richdacvolumio go-librespot[11534]: time="2025-06-16T20:40:20+01:00" level=debug msg="completed challenge" Jun 16 20:40:20 richdacvolumio go-librespot[11534]: time="2025-06-16T20:40:20+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jun 16 20:40:20 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 20:40:20 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 20:40:20 richdacvolumio volumio[9938]: (node:9938) UnhandledPromiseRejectionWarning: Error: socket hang up Jun 16 20:40:20 richdacvolumio volumio[9938]: at connResetException (internal/errors.js:607:14) Jun 16 20:40:20 richdacvolumio volumio[9938]: at Socket.socketOnEnd (_http_client.js:493:23) Jun 16 20:40:20 richdacvolumio volumio[9938]: at Socket.emit (events.js:327:22) Jun 16 20:40:20 richdacvolumio volumio[9938]: at endReadableNT (internal/streams/readable.js:1327:12) Jun 16 20:40:20 richdacvolumio volumio[9938]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jun 16 20:40:20 richdacvolumio volumio[9938]: (node:9938) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 4) Jun 16 20:40:20 richdacvolumio volumio[9938]: info: Connection to go-librespot Websocket closed Jun 16 20:40:20 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:20 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:20 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:20 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:21 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:21 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:21 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:21 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:21 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:21 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:21 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:21 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:21 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:21 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:21 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:21 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:22 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:22 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:22 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:22 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:22 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:22 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:22 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:22 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:22 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:22 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:22 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:22 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:23 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:23 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:23 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:23 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:23 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:23 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:23 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:23 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:23 richdacvolumio volumio[9938]: info: Initializing connection to go-librespot Websocket Jun 16 20:40:23 richdacvolumio volumio[9938]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 20:40:23 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:23 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:23 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:23 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:23 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 20:40:23 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 52. Jun 16 20:40:23 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 20:40:23 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 20:40:23 richdacvolumio go-librespot[11728]: Librespot-go daemon starting... Jun 16 20:40:23 richdacvolumio go-librespot[11728]: time="2025-06-16T20:40:23+01:00" level=info msg="generated new device id: 41e693cec44d0c1dbe20972b8b1c847061d9f000" Jun 16 20:40:23 richdacvolumio go-librespot[11728]: time="2025-06-16T20:40:23+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 20:40:24 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:24 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:24 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:24 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:24 richdacvolumio go-librespot[11728]: time="2025-06-16T20:40:24+01:00" level=debug msg="obtained new client token: AAAJGDi24Um1+pcuSSkKPLJjNquTBo3EO2SVZcuKQFkXo1POkYEGNnboJ7/9Y9FVrxYvekjBB7LH7FqD8drH6RxFuLCY4h/v9IevV1MO2lMu6wQPZyFich9cCdj+AMIG3dMk40uzUtGhENo5qR1sICBIbsb29L7RvmlSg5ezw6itnrX3CXE5trabN+lXtMvrJRGjmJgjhFEpabsukc+jkIdYVQ1QaWE8CfZi8PhM0AG44Bw/AU2UeLZxcMf6yg==" Jun 16 20:40:24 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:24 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:24 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:24 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:24 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:24 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:24 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:24 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:24 richdacvolumio go-librespot[11728]: time="2025-06-16T20:40:24+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jun 16 20:40:25 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:25 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:25 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:25 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:25 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:25 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:25 richdacvolumio go-librespot[11728]: time="2025-06-16T20:40:25+01:00" level=debug msg="completed keyexchange" Jun 16 20:40:25 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:25 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:25 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:25 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:25 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:25 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:25 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:25 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:25 richdacvolumio go-librespot[11728]: time="2025-06-16T20:40:25+01:00" level=debug msg="completed challenge" Jun 16 20:40:26 richdacvolumio go-librespot[11728]: time="2025-06-16T20:40:26+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jun 16 20:40:26 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:26 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:26 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 20:40:26 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 20:40:26 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:26 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:26 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:26 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:26 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:26 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:26 richdacvolumio volumio[9938]: info: Initializing connection to go-librespot Websocket Jun 16 20:40:26 richdacvolumio volumio[9938]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 20:40:26 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:26 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:26 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:26 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:27 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:27 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:27 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:27 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:27 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:27 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:27 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:27 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:27 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:27 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:27 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:27 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:28 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:28 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:28 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:28 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:28 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:28 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:28 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:28 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:28 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:28 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:28 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:28 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:29 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:29 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:29 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:29 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:29 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 20:40:29 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 53. Jun 16 20:40:29 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 20:40:29 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 20:40:29 richdacvolumio go-librespot[11835]: Librespot-go daemon starting... Jun 16 20:40:29 richdacvolumio go-librespot[11835]: time="2025-06-16T20:40:29+01:00" level=info msg="generated new device id: ea780193f0ce81533e5cd6eaae85b1053330fb8c" Jun 16 20:40:29 richdacvolumio go-librespot[11835]: time="2025-06-16T20:40:29+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 20:40:29 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:29 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:29 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:29 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:29 richdacvolumio volumio[9938]: info: Initializing connection to go-librespot Websocket Jun 16 20:40:29 richdacvolumio go-librespot[11835]: time="2025-06-16T20:40:29+01:00" level=debug msg="new websocket client" Jun 16 20:40:29 richdacvolumio volumio[9938]: info: Connection to go-librespot Websocket established Jun 16 20:40:29 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:29 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:29 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:29 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:29 richdacvolumio go-librespot[11835]: time="2025-06-16T20:40:29+01:00" level=debug msg="obtained new client token: AACGfoHwTQBZsEOqfYbPwagw7h+3GPBBApTl6+F0cE0d5WbEYFvriDpg2764/0Dw+Yl6L20SPvGIvjYvYg61Oj5BEYos8gbEXMOFL0xPdEe3Zos7VFoWP+Vv5U69vkraEKgi34nzzKPG8QdkIPfHOkE2aAuDQQImMnNxHHtQr8WsX0o0k6Q5XFIuYsON/aMzHKyy93tf95t9J+2M3Z5+kCxfmW0OGu2bkh71oSJf/0plWif2D5SP7jk6nfkOpg==" Jun 16 20:40:30 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:30 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:30 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:30 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:30 richdacvolumio go-librespot[11835]: time="2025-06-16T20:40:30+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jun 16 20:40:30 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:30 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:30 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:30 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:30 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:30 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:30 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:30 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:31 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:31 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:31 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:31 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:31 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:31 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:31 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:31 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:31 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:31 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:31 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:31 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:32 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:32 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:32 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:32 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:32 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:32 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:32 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:32 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:32 richdacvolumio volumio[9938]: info: Getting Spotify volume Jun 16 20:40:32 richdacvolumio volumio[9938]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Jun 16 20:40:32 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:32 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:32 richdacvolumio volumio[9938]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 16 20:40:32 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:32 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:32 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:32 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:33 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:33 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:33 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:33 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:33 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:33 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:33 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:33 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:33 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:33 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:33 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:33 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:34 richdacvolumio volumio[9938]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 16 20:40:34 richdacvolumio volumio[9938]: info: Preload queue cleared Jun 16 20:40:34 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:34 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:34 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:34 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:34 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:34 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:34 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:34 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:34 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:34 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:34 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:34 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:35 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:35 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:35 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:35 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:35 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:35 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:35 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:35 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:35 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:35 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:35 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:35 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:36 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:36 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:36 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:36 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:36 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:36 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:36 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:36 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:36 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:36 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:36 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:36 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:37 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:37 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:37 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:37 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:37 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:37 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:37 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:37 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:37 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:38 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:38 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:38 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:38 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:38 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:38 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:38 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:38 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:38 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:38 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:38 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:38 richdacvolumio go-librespot[11835]: time="2025-06-16T20:40:38+01:00" level=debug msg="completed keyexchange" Jun 16 20:40:39 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:39 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:39 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:39 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:39 richdacvolumio go-librespot[11835]: time="2025-06-16T20:40:39+01:00" level=debug msg="completed challenge" Jun 16 20:40:39 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:39 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:39 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:39 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:39 richdacvolumio go-librespot[11835]: time="2025-06-16T20:40:39+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jun 16 20:40:39 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 20:40:39 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 20:40:39 richdacvolumio volumio[9938]: (node:9938) UnhandledPromiseRejectionWarning: Error: socket hang up Jun 16 20:40:39 richdacvolumio volumio[9938]: at connResetException (internal/errors.js:607:14) Jun 16 20:40:39 richdacvolumio volumio[9938]: at Socket.socketOnEnd (_http_client.js:493:23) Jun 16 20:40:39 richdacvolumio volumio[9938]: at Socket.emit (events.js:327:22) Jun 16 20:40:39 richdacvolumio volumio[9938]: at endReadableNT (internal/streams/readable.js:1327:12) Jun 16 20:40:39 richdacvolumio volumio[9938]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jun 16 20:40:39 richdacvolumio volumio[9938]: (node:9938) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 5) Jun 16 20:40:39 richdacvolumio volumio[9938]: info: Connection to go-librespot Websocket closed Jun 16 20:40:39 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:39 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:39 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:39 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:40 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:40 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:40 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:40 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:40 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:40 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:40 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:40 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:40 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:40 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:40 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:40 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:41 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:41 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:41 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:41 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:41 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:41 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:41 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:41 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:41 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:41 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:41 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:41 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:42 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:42 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:42 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:42 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:42 richdacvolumio volumio[9938]: info: Initializing connection to go-librespot Websocket Jun 16 20:40:42 richdacvolumio volumio[9938]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 20:40:42 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 20:40:42 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 54. Jun 16 20:40:42 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 20:40:42 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:42 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:42 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:42 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:42 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 20:40:42 richdacvolumio go-librespot[12152]: Librespot-go daemon starting... Jun 16 20:40:42 richdacvolumio go-librespot[12152]: time="2025-06-16T20:40:42+01:00" level=info msg="generated new device id: eebebb9c4fb483bbf7506fd6067c81e98bcd6368" Jun 16 20:40:42 richdacvolumio go-librespot[12152]: time="2025-06-16T20:40:42+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 20:40:42 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:42 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:42 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:42 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:43 richdacvolumio go-librespot[12152]: time="2025-06-16T20:40:43+01:00" level=debug msg="obtained new client token: AABUs82pQDhshUStSgs3OaPXJ8gxKn3jN+psK2fcDZDkXxg28T/lVVt/ey/sqtcy5wZmSvDp93vmilmvg081Z3AhjPcEU5sVWgasNN6tK7GFUdU9zeXxI0mD7jouh/VH4W8hTtT+acqBlpHnb8LcGTjleImaD54OoxNVfP3a8Arsl7pd5lbv+NMJ0PjjkcBVGAugHg47fx50uWs8e9Q6mdlJ15JzeOe53Vv/jGHJOJPQ8XZHzVtV9KGpA6g=" Jun 16 20:40:43 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:43 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:43 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:43 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:43 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:43 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:43 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:43 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:43 richdacvolumio go-librespot[12152]: time="2025-06-16T20:40:43+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jun 16 20:40:43 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:43 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:43 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:43 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:44 richdacvolumio go-librespot[12152]: time="2025-06-16T20:40:44+01:00" level=debug msg="completed keyexchange" Jun 16 20:40:44 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:44 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:44 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:44 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:44 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:44 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:44 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:44 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:44 richdacvolumio go-librespot[12152]: time="2025-06-16T20:40:44+01:00" level=debug msg="completed challenge" Jun 16 20:40:44 richdacvolumio go-librespot[12152]: time="2025-06-16T20:40:44+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jun 16 20:40:44 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 20:40:44 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 20:40:44 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:44 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:44 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:44 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:45 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:45 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:45 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:45 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:45 richdacvolumio volumio[9938]: info: Initializing connection to go-librespot Websocket Jun 16 20:40:45 richdacvolumio volumio[9938]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 20:40:45 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:45 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:45 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:45 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:45 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:45 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:45 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:45 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:46 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:46 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:46 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:46 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:46 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:46 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:46 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:46 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:46 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:46 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:46 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:46 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:47 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:47 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:47 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:47 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:47 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:47 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:47 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:47 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:47 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:47 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:47 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:47 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:48 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 20:40:48 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 55. Jun 16 20:40:48 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 20:40:48 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 20:40:48 richdacvolumio go-librespot[12262]: Librespot-go daemon starting... Jun 16 20:40:48 richdacvolumio go-librespot[12262]: time="2025-06-16T20:40:48+01:00" level=info msg="generated new device id: f87f998b22696ba43f64bf3152aa795d9040e920" Jun 16 20:40:48 richdacvolumio go-librespot[12262]: time="2025-06-16T20:40:48+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 20:40:48 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:48 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:48 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:48 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:48 richdacvolumio volumio[9938]: info: Initializing connection to go-librespot Websocket Jun 16 20:40:48 richdacvolumio go-librespot[12262]: time="2025-06-16T20:40:48+01:00" level=debug msg="new websocket client" Jun 16 20:40:48 richdacvolumio volumio[9938]: info: Connection to go-librespot Websocket established Jun 16 20:40:48 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:48 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:48 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:48 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:48 richdacvolumio go-librespot[12262]: time="2025-06-16T20:40:48+01:00" level=debug msg="obtained new client token: AADWgpc8j+UgxV8xOm46TqTwn9iBV9BncPCtdgxWZv4MPeWqAGJQvVnfGo1lawrx3M1BmyYL9Lqmc35t9C9hoGZRoMw0R7/AxtnyCroVjpNhKdhjkV3LFeF2pamkl7UzZTsiP5L1qtbReq8obVPKqLzFledwW1YVhkHEXPp2yZ8zEVejusDudJk1JI0D3osgZH7b7HiRQfmFDXn2OW8izBY+g1k1sizxPYnFa/ZLvqMisHfB1E+xmp4F098eMw==" Jun 16 20:40:48 richdacvolumio go-librespot[12262]: time="2025-06-16T20:40:48+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 16 20:40:49 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:49 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:49 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:49 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:49 richdacvolumio go-librespot[12262]: time="2025-06-16T20:40:49+01:00" level=debug msg="completed keyexchange" Jun 16 20:40:49 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:49 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:49 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:49 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:49 richdacvolumio go-librespot[12262]: time="2025-06-16T20:40:49+01:00" level=debug msg="completed challenge" Jun 16 20:40:49 richdacvolumio go-librespot[12262]: time="2025-06-16T20:40:49+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jun 16 20:40:49 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 20:40:49 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 20:40:49 richdacvolumio volumio[9938]: info: Connection to go-librespot Websocket closed Jun 16 20:40:49 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:49 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:49 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:49 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:50 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:50 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:50 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:50 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:50 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:50 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:50 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:50 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:50 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:50 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:50 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:50 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:51 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:51 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:51 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:51 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:51 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:51 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:51 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:51 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:51 richdacvolumio volumio[9938]: info: Getting Spotify volume Jun 16 20:40:51 richdacvolumio volumio[9938]: (node:9938) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 20:40:51 richdacvolumio volumio[9938]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jun 16 20:40:51 richdacvolumio volumio[9938]: (node:9938) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 6) Jun 16 20:40:51 richdacvolumio volumio[9938]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Jun 16 20:40:51 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:51 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:51 richdacvolumio volumio[9938]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 16 20:40:51 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:51 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:51 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:51 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:52 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:52 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:52 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:52 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:52 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:52 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:52 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:52 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:52 richdacvolumio volumio[9938]: info: Initializing connection to go-librespot Websocket Jun 16 20:40:52 richdacvolumio volumio[9938]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 20:40:52 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:52 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:52 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:52 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:52 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 20:40:52 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 56. Jun 16 20:40:52 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 20:40:52 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 20:40:52 richdacvolumio go-librespot[12369]: Librespot-go daemon starting... Jun 16 20:40:52 richdacvolumio go-librespot[12369]: time="2025-06-16T20:40:52+01:00" level=info msg="generated new device id: d3e66f34b0bf33c5e82cf1a26076db4d44c51286" Jun 16 20:40:52 richdacvolumio go-librespot[12369]: time="2025-06-16T20:40:52+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 20:40:53 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:53 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:53 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:53 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:53 richdacvolumio go-librespot[12369]: time="2025-06-16T20:40:53+01:00" level=debug msg="obtained new client token: AACrpAFqi3pH78LrNXSS0BlXV7jzSVMf4QmYGf4Fz9TBGYaQFetnDXP5qSajPijRRHgwMMG0tzFe9glY1D8o1Gz8INq0aDHKHE76OyxIdt0bJ6lHBh6q5Q5DYilgqOcxjQaSrFTLT16pXxJ/TJiDj1KOYDocmVmimOkEvoOpI2aK/dFSAeVnQo2tZEAx0RtdiHCVODodQJ0cKYHZSuYjW/j+pkI9mUTNaVSHL2p/cXtmnG9iiH+2u4nUWw4=" Jun 16 20:40:53 richdacvolumio go-librespot[12369]: time="2025-06-16T20:40:53+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 16 20:40:53 richdacvolumio go-librespot[12369]: time="2025-06-16T20:40:53+01:00" level=debug msg="completed keyexchange" Jun 16 20:40:53 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:53 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:53 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:53 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:53 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:53 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:53 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:53 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:53 richdacvolumio go-librespot[12369]: time="2025-06-16T20:40:53+01:00" level=debug msg="completed challenge" Jun 16 20:40:53 richdacvolumio go-librespot[12369]: time="2025-06-16T20:40:53+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jun 16 20:40:53 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 20:40:53 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 20:40:53 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:53 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:54 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:54 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:54 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:54 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:54 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:54 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:54 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:54 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:54 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:54 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:54 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:54 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:55 richdacvolumio volumio[9938]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 16 20:40:55 richdacvolumio volumio[9938]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 16 20:40:55 richdacvolumio volumio[9938]: info: Retrieving Cloud Streaming UI Jun 16 20:40:55 richdacvolumio volumio[9938]: info: Getting Tidal Cloud Configuration Jun 16 20:40:55 richdacvolumio volumio[9938]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 16 20:40:55 richdacvolumio volumio[9938]: info: Getting Qobuz Cloud Configuration Jun 16 20:40:55 richdacvolumio volumio[9938]: info: Asking plugin for UI Config Jun 16 20:40:55 richdacvolumio volumio[9938]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 16 20:40:55 richdacvolumio volumio[9938]: info: Getting Spotify Cloud Configuration Jun 16 20:40:55 richdacvolumio volumio[9938]: info: Asking plugin for UI Config Jun 16 20:40:55 richdacvolumio volumio[9938]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 16 20:40:55 richdacvolumio volumio[9938]: info: Saving Spotify Acccount Jun 16 20:40:55 richdacvolumio volumio[9938]: info: Got Tidal Cloud Configuration Jun 16 20:40:55 richdacvolumio volumio[9938]: info: Got it Jun 16 20:40:55 richdacvolumio volumio[9938]: info: Got it Jun 16 20:40:55 richdacvolumio volumio[9938]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Jun 16 20:40:55 richdacvolumio volumio[9938]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 16 20:40:55 richdacvolumio volumio[9938]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Jun 16 20:40:55 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:55 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:55 richdacvolumio volumio[9938]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jun 16 20:40:55 richdacvolumio volumio[9938]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jun 16 20:40:55 richdacvolumio volumio[9938]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jun 16 20:40:55 richdacvolumio volumio[9938]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jun 16 20:40:55 richdacvolumio volumio[9938]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 16 20:40:55 richdacvolumio volumio[9938]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 16 20:40:55 richdacvolumio volumio[9938]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 16 20:40:55 richdacvolumio volumio[9938]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 16 20:40:55 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetBrowseSources Jun 16 20:40:55 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetBrowseSources Jun 16 20:40:55 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetBrowseSources Jun 16 20:40:55 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:55 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:55 richdacvolumio volumio[9938]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 16 20:40:55 richdacvolumio volumio[9938]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Jun 16 20:40:55 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:55 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:55 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:55 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:55 richdacvolumio volumio[9938]: info: Initializing connection to go-librespot Websocket Jun 16 20:40:55 richdacvolumio volumio[9938]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 20:40:55 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:55 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:55 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:55 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:56 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:56 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:56 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:56 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:56 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:56 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:56 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:56 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:56 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:56 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:56 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:56 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:57 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 20:40:57 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 57. Jun 16 20:40:57 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 20:40:57 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 20:40:57 richdacvolumio go-librespot[12453]: Librespot-go daemon starting... Jun 16 20:40:57 richdacvolumio volumio[9938]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jun 16 20:40:57 richdacvolumio volumio[9938]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jun 16 20:40:57 richdacvolumio go-librespot[12453]: time="2025-06-16T20:40:57+01:00" level=info msg="generated new device id: dcf836d2a3a8ddb3c935ea8beb7a00251922d997" Jun 16 20:40:57 richdacvolumio go-librespot[12453]: time="2025-06-16T20:40:57+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 20:40:57 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:57 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:57 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:57 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:57 richdacvolumio go-librespot[12453]: time="2025-06-16T20:40:57+01:00" level=debug msg="obtained new client token: AABXoAr+84lAF+FMJ/ly81OcbOyOmUkKTGVnisuG/YvA9g9TrPu2OLdfKVgvHAvZ8XbqaS2/1PIyHyZq0HSgyiX40iHdfDSKWtj8pwv8T3PtXv1f2WMRSjfRUA21L4HZSmIClf89weGOpkOsuxyHPI/IueU1XS27qhALbTVlEbAaslrEzuaZ/8wjck0LH4HetI4Ao7lX9uxaNwMKaYmp7Qazdx4aKnHo61iHS3Ez7wCxbxImt6UjbHLy5WQiig==" Jun 16 20:40:57 richdacvolumio go-librespot[12453]: time="2025-06-16T20:40:57+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 16 20:40:57 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:57 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:57 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:57 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:57 richdacvolumio go-librespot[12453]: time="2025-06-16T20:40:57+01:00" level=debug msg="completed keyexchange" Jun 16 20:40:57 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:57 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:57 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:57 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:58 richdacvolumio go-librespot[12453]: time="2025-06-16T20:40:58+01:00" level=debug msg="completed challenge" Jun 16 20:40:58 richdacvolumio go-librespot[12453]: time="2025-06-16T20:40:58+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jun 16 20:40:58 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 20:40:58 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 20:40:58 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:58 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:58 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:58 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:58 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:58 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:58 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:58 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:58 richdacvolumio volumio[9938]: info: Initializing connection to go-librespot Websocket Jun 16 20:40:58 richdacvolumio volumio[9938]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 20:40:58 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:58 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:58 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:58 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:59 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:59 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:59 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:59 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:59 richdacvolumio volumio[9938]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 16 20:40:59 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:59 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:59 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:59 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:59 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:59 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:59 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:40:59 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:40:59 richdacvolumio volumio[9938]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jun 16 20:40:59 richdacvolumio volumio[9938]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jun 16 20:41:00 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:41:00 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:41:00 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:41:00 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:41:00 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:41:00 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:41:00 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:41:00 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:41:00 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:41:00 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:41:00 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:41:00 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:41:01 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:41:01 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:41:01 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:41:01 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:41:01 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 20:41:01 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 58. Jun 16 20:41:01 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 20:41:01 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 20:41:01 richdacvolumio go-librespot[12548]: Librespot-go daemon starting... Jun 16 20:41:01 richdacvolumio go-librespot[12548]: time="2025-06-16T20:41:01+01:00" level=info msg="generated new device id: 0d9af868300eaa178eb0c89856120165dd09acbd" Jun 16 20:41:01 richdacvolumio go-librespot[12548]: time="2025-06-16T20:41:01+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 20:41:01 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:41:01 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:41:01 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:41:01 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:41:01 richdacvolumio go-librespot[12548]: time="2025-06-16T20:41:01+01:00" level=debug msg="obtained new client token: AADw9azoZtPiJmBZuRoz3cqG/JtOZgEYjEQ5/ihXDvfFm91so6e5JfrHLiRdPvjFxaLTX5ehAnbhe+PznP58MPMX6puNEbAbeMEtIb72pNYX9WIEMw8Cu6Lv6YewocEtyCzZsWcUNhr0t7IBBdRA8iafAS94KN7fWvJpUnqGtsM1RSj9HoTuyU9QSqZP88eHAqs6jKZdZ8jadmGmkB0ojeXGEYxDmr1HRrZtqJuI0ykdCMsDBx7tb2yg4bffHg==" Jun 16 20:41:01 richdacvolumio volumio[9938]: info: Initializing connection to go-librespot Websocket Jun 16 20:41:01 richdacvolumio go-librespot[12548]: time="2025-06-16T20:41:01+01:00" level=debug msg="new websocket client" Jun 16 20:41:01 richdacvolumio volumio[9938]: info: Connection to go-librespot Websocket established Jun 16 20:41:01 richdacvolumio go-librespot[12548]: time="2025-06-16T20:41:01+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jun 16 20:41:01 richdacvolumio go-librespot[12548]: time="2025-06-16T20:41:01+01:00" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 104.199.65.9:4070: connect: connection refused" Jun 16 20:41:01 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 20:41:01 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 20:41:01 richdacvolumio volumio[9938]: info: Connection to go-librespot Websocket closed Jun 16 20:41:01 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:41:01 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:41:01 richdacvolumio volumio[9938]: info: CoreCommandRouter::volumioGetState Jun 16 20:41:01 richdacvolumio volumio[9938]: info: CorePlayQueue::getTrack 0 Jun 16 20:41:02 richdacvolumio volumio[9938]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 16 20:41:02 richdacvolumio volumio[9938]: Error: dns service error: unknown Jun 16 20:41:02 richdacvolumio volumio[9938]: at MDNSService.on_resolver_done (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:19:30) Jun 16 20:41:02 richdacvolumio volumio[9938]: at SocketWatcher.MDNSService.self.watcher.callback (/volumio/node_modules/mdns/lib/mdns_service.js:18:40) { Jun 16 20:41:02 richdacvolumio volumio[9938]: errorCode: -65537 Jun 16 20:41:02 richdacvolumio volumio[9938]: } Jun 16 20:41:02 richdacvolumio volumio[9938]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 16 20:41:02 richdacvolumio sudo[12591]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-16 20:40 Jun 16 20:41:02 richdacvolumio sudo[12591]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="a142ed2648fb91920de0dde3a60cd39b5d0ba4f6" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 10 Jun 2025 04:52:53 PM CEST" VOLUMIO_VERSION="3.816" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="a72866a0de4045751d03a035de6290e1"