-- Logs begin at Sun 2024-07-28 19:29:44 BST, end at Mon 2025-06-16 19:43:53 BST. -- Jun 16 19:42:00 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:00 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:00 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:00 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:00 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:00 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:00 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:00 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:00 richdacvolumio go-librespot[21565]: time="2025-06-16T19:42:00+01:00" level=debug msg="completed keyexchange" Jun 16 19:42:00 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:00 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:00 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:00 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:00 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 16 19:42:01 richdacvolumio go-librespot[21565]: time="2025-06-16T19:42:01+01:00" level=debug msg="completed challenge" Jun 16 19:42:01 richdacvolumio go-librespot[21565]: time="2025-06-16T19:42:01+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 19:42:01 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:01 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:01 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 19:42:01 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 19:42:01 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:01 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:01 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:01 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:01 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:01 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:01 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:01 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:01 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:01 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:02 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:02 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:02 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:02 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:02 richdacvolumio volumio[1007]: info: Initializing connection to go-librespot Websocket Jun 16 19:42:02 richdacvolumio volumio[1007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 19:42:02 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:02 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:02 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:02 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:02 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:02 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:02 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:02 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:03 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:03 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:03 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:03 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:03 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:03 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:03 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:03 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:03 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:03 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:03 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:03 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:04 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:04 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:04 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:04 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:04 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 19:42:04 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 177. Jun 16 19:42:04 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 19:42:04 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 19:42:04 richdacvolumio go-librespot[21701]: Librespot-go daemon starting... Jun 16 19:42:04 richdacvolumio go-librespot[21701]: time="2025-06-16T19:42:04+01:00" level=info msg="generated new device id: f442fcf4e320971db535ebf666e938ed81489e9b" Jun 16 19:42:04 richdacvolumio go-librespot[21701]: time="2025-06-16T19:42:04+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 19:42:04 richdacvolumio go-librespot[21701]: time="2025-06-16T19:42:04+01:00" level=debug msg="obtained new client token: AADWfpMV4U7GoL/Ax+zudWZ2dr4eJH0FdClm37qBry4XJnySqZJ16nRxf5cdcB4PUrOz+UWwNuvzNC3xbklsQDmEejiOJHfKBFgF2bIPGSV2GG1y2go5xrha03K3MGC6FK+mFg8E0xJ6lBV0pfZ2A96Khqo0wucPgbSUyMfPaaBskAAXNpm4GP8XslUM39oyhw8rHD7pY0K6MO74WWg0/Mh3H85KkTk0mmYHoTHWc7gpuSQdqMdqJHuiipUc0w==" Jun 16 19:42:04 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:04 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:04 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:04 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:04 richdacvolumio go-librespot[21701]: time="2025-06-16T19:42:04+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 19:42:04 richdacvolumio go-librespot[21701]: time="2025-06-16T19:42:04+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 19:42:04 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 19:42:04 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 19:42:04 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 16 19:42:04 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:04 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:04 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:04 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:04 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: networkfs , editShare Jun 16 19:42:04 richdacvolumio volumio[1007]: info: Share richserver successfully unmounted Jun 16 19:42:04 richdacvolumio sudo[21722]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.0.89/\\\\DESKTOP-I6U92AB/music /mnt/NAS/richserver Jun 16 19:42:04 richdacvolumio sudo[21722]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 19:42:04 richdacvolumio kernel: CIFS: Attempting to mount \\192.168.0.89\ Jun 16 19:42:04 richdacvolumio sudo[21722]: pam_unix(sudo:session): session closed for user root Jun 16 19:42:04 richdacvolumio volumio[1007]: info: An error occurred mounting the new share. Rolling back configuration Jun 16 19:42:04 richdacvolumio kernel: CIFS: Status code returned 0xc0000022 STATUS_ACCESS_DENIED Jun 16 19:42:04 richdacvolumio kernel: CIFS: VFS: \\192.168.0.89 Send error in SessSetup = -13 Jun 16 19:42:04 richdacvolumio kernel: CIFS: VFS: cifs_mount failed w/return code = -13 Jun 16 19:42:05 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:05 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:05 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:05 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:05 richdacvolumio volumio[1007]: info: Initializing connection to go-librespot Websocket Jun 16 19:42:05 richdacvolumio volumio[1007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 19:42:05 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:05 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:05 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:05 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:05 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:05 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:05 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:05 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:06 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:06 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:06 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:06 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:06 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:06 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:06 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:06 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:06 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:06 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:06 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:06 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:07 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:07 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:07 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:07 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:07 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:07 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:07 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:07 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:07 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 19:42:07 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 178. Jun 16 19:42:07 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 19:42:07 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 19:42:07 richdacvolumio go-librespot[21775]: Librespot-go daemon starting... Jun 16 19:42:07 richdacvolumio go-librespot[21775]: time="2025-06-16T19:42:07+01:00" level=info msg="generated new device id: 4ee8071ccadcd27e8cf8338321973fad3d55766c" Jun 16 19:42:07 richdacvolumio go-librespot[21775]: time="2025-06-16T19:42:07+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 19:42:07 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:07 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:07 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:07 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:07 richdacvolumio go-librespot[21775]: time="2025-06-16T19:42:07+01:00" level=debug msg="obtained new client token: AACf2qu66tMRL6uLP/seD/wydNeLhBwGPtfsZgWieBWeikBtni8QA31YGRXMMrjj+vQ7JDEp1QTwiExUef+LtRFACmO/B8eJG5Vtl5XLbi2hnrqP/qDsCuNNrfejXICrukEbSykpvHHofZSwshVFZRhUHsFs4Kgv6wJrZ4lFEZeytKGmQzyyzksh7AIMXWcq7yha5DVk6MFDIjmLYM9xVDZy8ykwBkmjobUUr8J7gD1+vwA96YfLZFdPB2nizg==" Jun 16 19:42:08 richdacvolumio go-librespot[21775]: time="2025-06-16T19:42:08+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 19:42:08 richdacvolumio go-librespot[21775]: time="2025-06-16T19:42:08+01:00" level=debug msg="completed keyexchange" Jun 16 19:42:08 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:08 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:08 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:08 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:08 richdacvolumio volumio[1007]: info: Initializing connection to go-librespot Websocket Jun 16 19:42:08 richdacvolumio go-librespot[21775]: time="2025-06-16T19:42:08+01:00" level=debug msg="new websocket client" Jun 16 19:42:08 richdacvolumio volumio[1007]: info: Connection to go-librespot Websocket established Jun 16 19:42:08 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:08 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:08 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:08 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:08 richdacvolumio go-librespot[21775]: time="2025-06-16T19:42:08+01:00" level=debug msg="completed challenge" Jun 16 19:42:08 richdacvolumio go-librespot[21775]: time="2025-06-16T19:42:08+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 19:42:08 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 19:42:08 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 19:42:08 richdacvolumio volumio[1007]: info: Connection to go-librespot Websocket closed Jun 16 19:42:08 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 16 19:42:08 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:08 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:08 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:08 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:09 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:09 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:09 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:09 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:09 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:09 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:09 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:09 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:09 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:09 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:09 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:09 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:10 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:10 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:10 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:10 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:10 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:10 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:10 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:10 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:10 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:10 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:10 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:10 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:11 richdacvolumio volumio[1007]: info: Getting Spotify volume Jun 16 19:42:11 richdacvolumio volumio[1007]: (node:1007) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 19:42:11 richdacvolumio volumio[1007]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jun 16 19:42:11 richdacvolumio volumio[1007]: (node:1007) 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: 3094) Jun 16 19:42:11 richdacvolumio volumio[1007]: 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 19:42:11 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:11 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:11 richdacvolumio volumio[1007]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 16 19:42:11 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:11 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:11 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:11 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:11 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:11 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:11 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:11 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:11 richdacvolumio volumio[1007]: info: Initializing connection to go-librespot Websocket Jun 16 19:42:11 richdacvolumio volumio[1007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 19:42:11 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 19:42:11 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 179. Jun 16 19:42:11 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 19:42:12 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:12 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:12 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:12 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:12 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 19:42:12 richdacvolumio go-librespot[21856]: Librespot-go daemon starting... Jun 16 19:42:12 richdacvolumio go-librespot[21856]: time="2025-06-16T19:42:12+01:00" level=info msg="generated new device id: ba0789effa8d166634fb75066e4d78008fba3f1f" Jun 16 19:42:12 richdacvolumio go-librespot[21856]: time="2025-06-16T19:42:12+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 19:42:12 richdacvolumio go-librespot[21856]: time="2025-06-16T19:42:12+01:00" level=debug msg="obtained new client token: AAC0fIi54zVX4NVv7dERziQ6VyaZHe3XqLzFGtXFB+uiFEnEZvqMgkcAyF0wn95r6gKQgzFe/5kIeArx8H4cntkTQItUn49So+osjC8NjOi1ksG+BQO9t9X04zOmFrkuwmLYiLWRUHwngupBHqTfPNdmg/LfNGJt9Xh9x2+27S3fJUZFzEhYWQMyv+S+29lj+GcQMVo3SE8QzZNI8DuwvhSzGgKaAIYzXyJ1obAC2kDw2tVm4XxN6PAJ95A=" Jun 16 19:42:12 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:12 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:12 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:12 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:12 richdacvolumio go-librespot[21856]: time="2025-06-16T19:42:12+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 19:42:12 richdacvolumio go-librespot[21856]: time="2025-06-16T19:42:12+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 19:42:12 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 19:42:12 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 19:42:12 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:12 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:12 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:12 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:13 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:13 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:13 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:13 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:13 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:13 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:13 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:13 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:13 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:13 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:13 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:13 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:13 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:13 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:14 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:14 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:14 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:14 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:14 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:14 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:14 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:14 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:14 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:14 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:14 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:14 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:14 richdacvolumio volumio[1007]: info: Initializing connection to go-librespot Websocket Jun 16 19:42:14 richdacvolumio volumio[1007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 19:42:15 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:15 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:15 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:15 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:15 richdacvolumio volumio[1007]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 16 19:42:15 richdacvolumio volumio[1007]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 16 19:42:15 richdacvolumio volumio[1007]: info: Retrieving Cloud Streaming UI Jun 16 19:42:15 richdacvolumio volumio[1007]: info: Getting Tidal Cloud Configuration Jun 16 19:42:15 richdacvolumio volumio[1007]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 16 19:42:15 richdacvolumio volumio[1007]: info: Getting Qobuz Cloud Configuration Jun 16 19:42:15 richdacvolumio volumio[1007]: info: Asking plugin for UI Config Jun 16 19:42:15 richdacvolumio volumio[1007]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 16 19:42:15 richdacvolumio volumio[1007]: info: Getting Spotify Cloud Configuration Jun 16 19:42:15 richdacvolumio volumio[1007]: info: Asking plugin for UI Config Jun 16 19:42:15 richdacvolumio volumio[1007]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 16 19:42:15 richdacvolumio volumio[1007]: info: Saving Spotify Acccount Jun 16 19:42:15 richdacvolumio volumio[1007]: info: Got Tidal Cloud Configuration Jun 16 19:42:15 richdacvolumio volumio[1007]: info: Got it Jun 16 19:42:15 richdacvolumio volumio[1007]: info: Got it Jun 16 19:42:15 richdacvolumio volumio[1007]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Jun 16 19:42:15 richdacvolumio volumio[1007]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 16 19:42:15 richdacvolumio volumio[1007]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Jun 16 19:42:15 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jun 16 19:42:15 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jun 16 19:42:15 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jun 16 19:42:15 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jun 16 19:42:15 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 16 19:42:15 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 16 19:42:15 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 16 19:42:15 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 16 19:42:15 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetBrowseSources Jun 16 19:42:15 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetBrowseSources Jun 16 19:42:15 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetBrowseSources Jun 16 19:42:15 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 16 19:42:15 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Jun 16 19:42:15 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 19:42:15 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 180. Jun 16 19:42:15 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 19:42:15 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:15 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:15 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:15 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:15 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 19:42:15 richdacvolumio go-librespot[21927]: Librespot-go daemon starting... Jun 16 19:42:15 richdacvolumio go-librespot[21927]: time="2025-06-16T19:42:15+01:00" level=info msg="generated new device id: 7598e18f2862ed922c3c5da3ebd09b428a46aaeb" Jun 16 19:42:15 richdacvolumio go-librespot[21927]: time="2025-06-16T19:42:15+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 19:42:15 richdacvolumio go-librespot[21927]: time="2025-06-16T19:42:15+01:00" level=debug msg="obtained new client token: AAAmD8OVgfqXwCZlzZxtMllh0++5EZSYLOs2qGvFDPzL+thFWpcmrVCa1sWvndg1Xguo0JsNE4OMoEAOEVQabSnTYbRzbC3pD5UQSfRhpxO4r8oN1Tmv5R8iNO1e4EYOaALlBWj2CJK5BleVNF3Wfxj2e4W9c6uj1Hw7MYvqQcM1iWER66sVkCwcJ5lNoO0eQj+ZS1QIC2zM+e4fkNeywz4rv0PjSUdBlhrfjrkseCHQbVhA6LdOuYTN1tLrKQ==" Jun 16 19:42:15 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:15 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:15 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:15 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:15 richdacvolumio go-librespot[21927]: time="2025-06-16T19:42:15+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 19:42:15 richdacvolumio go-librespot[21927]: time="2025-06-16T19:42:15+01:00" level=debug msg="completed keyexchange" Jun 16 19:42:16 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:16 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:16 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:16 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:16 richdacvolumio go-librespot[21927]: time="2025-06-16T19:42:16+01:00" level=debug msg="completed challenge" Jun 16 19:42:16 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:16 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:16 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:16 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:16 richdacvolumio go-librespot[21927]: time="2025-06-16T19:42:16+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 19:42:16 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 19:42:16 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 19:42:16 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:16 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:16 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:16 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:17 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:17 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:17 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:17 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:17 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:17 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:17 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:17 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:17 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jun 16 19:42:17 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jun 16 19:42:17 richdacvolumio volumio[1007]: info: Initializing connection to go-librespot Websocket Jun 16 19:42:17 richdacvolumio volumio[1007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 19:42:17 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:17 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:17 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:17 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:18 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:18 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:18 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:18 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:18 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:18 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:18 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:18 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:18 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:18 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:18 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:18 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:19 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:19 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:19 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:19 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:19 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 16 19:42:19 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:19 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:19 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:19 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:19 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 19:42:19 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 181. Jun 16 19:42:19 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 19:42:19 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 19:42:19 richdacvolumio go-librespot[22016]: Librespot-go daemon starting... Jun 16 19:42:19 richdacvolumio go-librespot[22016]: time="2025-06-16T19:42:19+01:00" level=info msg="generated new device id: 4601ba05edc4d18468373696ba7a2cb7123d71b7" Jun 16 19:42:19 richdacvolumio go-librespot[22016]: time="2025-06-16T19:42:19+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 19:42:19 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:19 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:19 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:19 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:20 richdacvolumio go-librespot[22016]: time="2025-06-16T19:42:20+01:00" level=debug msg="obtained new client token: AACKb5wZ6vjysRi1iDpDrVD/EEiWQi4gcKXozfU0GBK/85o8vsc5bUS66UEPwIk93Y1kx38YAnJ5iAD4KUl4HooV3TvkXD6Q1I8pHO++79uNSUVOCAPZJOHxrWSOzC01pQIJJvydnCr+FsU/8iKTMcf2tkPa4FNclrhipOsfpLdU+OZUixEtuUOFNtiZHFXaIV1P7wqlJlhYXIFKOEDG5XfVLZ+keWorlS6qKMEXgPaLR39u5LsnlpQ1RXE=" Jun 16 19:42:20 richdacvolumio go-librespot[22016]: time="2025-06-16T19:42:20+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 19:42:20 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:20 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:20 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:20 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:20 richdacvolumio go-librespot[22016]: time="2025-06-16T19:42:20+01:00" level=debug msg="completed keyexchange" Jun 16 19:42:20 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jun 16 19:42:20 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jun 16 19:42:20 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:20 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:20 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:20 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:20 richdacvolumio go-librespot[22016]: time="2025-06-16T19:42:20+01:00" level=debug msg="completed challenge" Jun 16 19:42:20 richdacvolumio volumio[1007]: info: Initializing connection to go-librespot Websocket Jun 16 19:42:20 richdacvolumio go-librespot[22016]: time="2025-06-16T19:42:20+01:00" level=debug msg="new websocket client" Jun 16 19:42:20 richdacvolumio volumio[1007]: info: Connection to go-librespot Websocket established Jun 16 19:42:20 richdacvolumio go-librespot[22016]: time="2025-06-16T19:42: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 19:42:20 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 19:42:20 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 19:42:20 richdacvolumio volumio[1007]: info: Connection to go-librespot Websocket closed Jun 16 19:42:20 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:20 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:20 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:20 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:21 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:21 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:21 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:21 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:21 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:21 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:21 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:21 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:21 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:21 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:21 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:21 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:22 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:22 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:22 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:22 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:22 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:22 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:22 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:22 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:23 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:23 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:23 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:23 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:23 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:23 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:23 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:23 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:23 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 16 19:42:23 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:23 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:23 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:23 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:23 richdacvolumio volumio[1007]: info: Getting Spotify volume Jun 16 19:42:23 richdacvolumio volumio[1007]: (node:1007) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 19:42:23 richdacvolumio volumio[1007]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jun 16 19:42:23 richdacvolumio volumio[1007]: (node:1007) 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: 3095) Jun 16 19:42:23 richdacvolumio volumio[1007]: 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 19:42:23 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:23 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:23 richdacvolumio volumio[1007]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 16 19:42:23 richdacvolumio volumio[1007]: info: Initializing connection to go-librespot Websocket Jun 16 19:42:23 richdacvolumio volumio[1007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 19:42:23 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 19:42:23 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 182. Jun 16 19:42:23 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 19:42:24 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 19:42:24 richdacvolumio go-librespot[22103]: Librespot-go daemon starting... Jun 16 19:42:24 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:24 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:24 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:24 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:24 richdacvolumio go-librespot[22103]: time="2025-06-16T19:42:24+01:00" level=info msg="generated new device id: ab516a6319345187379faed6c53c61aec21e3513" Jun 16 19:42:24 richdacvolumio go-librespot[22103]: time="2025-06-16T19:42:24+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 19:42:24 richdacvolumio go-librespot[22103]: time="2025-06-16T19:42:24+01:00" level=debug msg="obtained new client token: AADYcHPbhXuIOOCkiCa5S1TLq7FgeRglRgOmnYtqrj9We717u9QUEBhiWoIW70y8KW4Pp52/jaD2WY2UGp6XKj+pxyAl+Ve1hmcZJU3DgxAqxldPQcGJYPipu5mjS/mXHNkPeIzv6+yVvjT+iF/Yz20mPAfz4b/DT2t3S9WQjhJz8XpHlkqa1iFFmsHOdSBPbys6xC6TsMHd8LQm1o/UIaowEgfZ3PYethODD9RyCltBzgUng22D6zXQKJo=" Jun 16 19:42:24 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:24 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:24 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:24 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:24 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jun 16 19:42:24 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jun 16 19:42:24 richdacvolumio go-librespot[22103]: time="2025-06-16T19:42: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-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jun 16 19:42:24 richdacvolumio go-librespot[22103]: time="2025-06-16T19:42:24+01:00" level=debug msg="completed keyexchange" Jun 16 19:42:24 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:24 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:24 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:24 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:25 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:25 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:25 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:25 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:25 richdacvolumio go-librespot[22103]: time="2025-06-16T19:42:25+01:00" level=debug msg="completed challenge" Jun 16 19:42:25 richdacvolumio go-librespot[22103]: time="2025-06-16T19:42:25+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 19:42:25 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 19:42:25 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 19:42:25 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:25 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:25 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:25 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:25 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jun 16 19:42:25 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jun 16 19:42:25 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:25 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:25 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:25 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:25 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jun 16 19:42:25 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jun 16 19:42:26 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:26 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:26 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:26 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:26 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jun 16 19:42:26 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jun 16 19:42:26 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:26 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:26 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:26 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:26 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:26 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:26 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:26 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:26 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jun 16 19:42:26 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jun 16 19:42:26 richdacvolumio volumio[1007]: info: Initializing connection to go-librespot Websocket Jun 16 19:42:26 richdacvolumio volumio[1007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 19:42:27 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:27 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:27 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:27 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:27 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jun 16 19:42:27 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jun 16 19:42:27 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jun 16 19:42:27 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jun 16 19:42:27 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 16 19:42:27 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:27 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:27 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:27 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:27 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jun 16 19:42:27 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jun 16 19:42:27 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jun 16 19:42:27 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jun 16 19:42:27 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:27 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:27 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:27 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:27 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jun 16 19:42:27 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jun 16 19:42:28 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:28 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:28 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:28 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:28 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 19:42:28 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 183. Jun 16 19:42:28 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 19:42:28 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 19:42:28 richdacvolumio go-librespot[22236]: Librespot-go daemon starting... Jun 16 19:42:28 richdacvolumio go-librespot[22236]: time="2025-06-16T19:42:28+01:00" level=info msg="generated new device id: 33229ee07ef01647708126e1f2661d3bfe7502ca" Jun 16 19:42:28 richdacvolumio go-librespot[22236]: time="2025-06-16T19:42:28+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 19:42:28 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:28 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:28 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:28 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:28 richdacvolumio go-librespot[22236]: time="2025-06-16T19:42:28+01:00" level=debug msg="obtained new client token: AAC7rWKUXUk5gOGu2THSphi0FdTmg7eszbV4Lnqu54cop30r+ADSVtYm1WPvQOYx/reFlalOtkFoRLah8ESJLlcUtP3OTjKpgBGffi8clQjusF6IEZdWuNfGEaPZaodLAskELDQHlLjYm54QG3HoQFSftuVnOUJZvl4yNTip1/RrX8AL7C++Rd/LZNSI4WpajXbPm9kQPmbD8OfSklsCk1NdLf/XOeZu/KgJ1vioNtQwixULons/TiAjnWldlw==" Jun 16 19:42:28 richdacvolumio go-librespot[22236]: time="2025-06-16T19:42:28+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 19:42:28 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jun 16 19:42:28 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jun 16 19:42:28 richdacvolumio go-librespot[22236]: time="2025-06-16T19:42:28+01:00" level=debug msg="completed keyexchange" Jun 16 19:42:28 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:28 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:28 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:28 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:29 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:29 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:29 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:29 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:29 richdacvolumio go-librespot[22236]: time="2025-06-16T19:42:29+01:00" level=debug msg="completed challenge" Jun 16 19:42:29 richdacvolumio go-librespot[22236]: time="2025-06-16T19:42:29+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 19:42:29 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 19:42:29 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 19:42:29 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jun 16 19:42:29 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jun 16 19:42:29 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:29 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:29 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:29 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:29 richdacvolumio volumio[1007]: info: Initializing connection to go-librespot Websocket Jun 16 19:42:29 richdacvolumio volumio[1007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 19:42:30 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:30 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:30 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:30 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:30 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jun 16 19:42:30 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jun 16 19:42:30 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:30 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:30 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:30 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:30 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:30 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:30 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:30 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:31 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:31 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:31 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:31 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:31 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jun 16 19:42:31 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jun 16 19:42:31 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:31 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:31 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:31 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:31 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 16 19:42:31 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:31 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:31 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:31 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:32 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:32 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:32 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:32 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:32 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:32 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:32 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:32 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:32 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 19:42:32 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 184. Jun 16 19:42:32 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 19:42:32 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 19:42:32 richdacvolumio go-librespot[22364]: Librespot-go daemon starting... Jun 16 19:42:32 richdacvolumio go-librespot[22364]: time="2025-06-16T19:42:32+01:00" level=info msg="generated new device id: be199a5a1092528e1f8e9c5cc08f3bbe417d4926" Jun 16 19:42:32 richdacvolumio go-librespot[22364]: time="2025-06-16T19:42:32+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 19:42:32 richdacvolumio go-librespot[22364]: time="2025-06-16T19:42:32+01:00" level=debug msg="obtained new client token: AADiTs00rwM4SOJ6HgjmBjSPFW3MSnz9TwsmITDUA5dHrscIXfctMdETt+2rH/lTOU7OxtKbsJlK5JN6lnFQw9iwFU+00ihJQ/cE/UtznlGyyzpVFzV9N8icMmVaFPSH/yMqzdTUBDq/KxZquaaQhX+6KrSbq9zC9idLjvK0QnXLTq8oSw2N8mt3VovkWB+85C0T15rWwGoS4I66kabrIVS2/46YUhiewwUwVmfC+5Y+ftpjknfi/6iUAPmxGg==" Jun 16 19:42:32 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:32 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:32 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:32 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:32 richdacvolumio volumio[1007]: info: Initializing connection to go-librespot Websocket Jun 16 19:42:32 richdacvolumio go-librespot[22364]: time="2025-06-16T19:42:32+01:00" level=debug msg="new websocket client" Jun 16 19:42:32 richdacvolumio volumio[1007]: info: Connection to go-librespot Websocket established Jun 16 19:42:32 richdacvolumio go-librespot[22364]: time="2025-06-16T19:42:32+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 19:42:33 richdacvolumio go-librespot[22364]: time="2025-06-16T19:42:33+01:00" level=debug msg="completed keyexchange" Jun 16 19:42:33 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:33 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:33 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:33 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:33 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jun 16 19:42:33 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jun 16 19:42:33 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:33 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:33 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:33 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:33 richdacvolumio go-librespot[22364]: time="2025-06-16T19:42:33+01:00" level=debug msg="completed challenge" Jun 16 19:42:33 richdacvolumio go-librespot[22364]: time="2025-06-16T19:42:33+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 19:42:33 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 19:42:33 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 19:42:33 richdacvolumio volumio[1007]: info: Connection to go-librespot Websocket closed Jun 16 19:42:33 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jun 16 19:42:33 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jun 16 19:42:33 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:33 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:33 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:33 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:34 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:34 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:34 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:34 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:34 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jun 16 19:42:34 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jun 16 19:42:34 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:34 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:34 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:34 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:34 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:34 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:34 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:34 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:35 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:35 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:35 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:35 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:35 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 16 19:42:35 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jun 16 19:42:35 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jun 16 19:42:35 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:35 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:35 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:35 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:35 richdacvolumio volumio[1007]: info: Getting Spotify volume Jun 16 19:42:35 richdacvolumio volumio[1007]: (node:1007) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 19:42:35 richdacvolumio volumio[1007]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jun 16 19:42:35 richdacvolumio volumio[1007]: (node:1007) 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: 3096) Jun 16 19:42:35 richdacvolumio volumio[1007]: 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 19:42:35 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:35 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:35 richdacvolumio volumio[1007]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 16 19:42:35 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:35 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:35 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:35 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:36 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jun 16 19:42:36 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jun 16 19:42:36 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:36 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:36 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:36 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:36 richdacvolumio volumio[1007]: info: Initializing connection to go-librespot Websocket Jun 16 19:42:36 richdacvolumio volumio[1007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 19:42:36 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:36 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:36 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:36 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:36 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 19:42:36 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 185. Jun 16 19:42:36 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 19:42:36 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 19:42:36 richdacvolumio go-librespot[22475]: Librespot-go daemon starting... Jun 16 19:42:36 richdacvolumio go-librespot[22475]: time="2025-06-16T19:42:36+01:00" level=info msg="generated new device id: a154043bb4a555be5c5356da6d0b2c4bc2f6639f" Jun 16 19:42:36 richdacvolumio go-librespot[22475]: time="2025-06-16T19:42:36+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 19:42:36 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jun 16 19:42:36 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jun 16 19:42:36 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:36 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:36 richdacvolumio go-librespot[22475]: time="2025-06-16T19:42:36+01:00" level=debug msg="obtained new client token: AADfmfah0lB7YJgrQ8COu28TWNUwpDOwp7natRzV0OK+sFsnuIU/F8X3V+QgnC4D5ze147SSfI9xWuMqoVBaNWUcETTGqS4vMXHIRGroS7NPPvM0dFOrc2eJEmeASeZ/Qf4IkBSEnjCAlgP+Qk+jBoAwEWLWRj2gsuV90UeqlakjEwJekopZPj24fKElt5T2YCyI2b6nQeQcGFQIkUfT1xGGTf9K/qAcvXnJdH999eUCCcRE3d5lR+FvDknwBw==" Jun 16 19:42:36 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:36 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:37 richdacvolumio go-librespot[22475]: time="2025-06-16T19:42:37+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 19:42:37 richdacvolumio go-librespot[22475]: time="2025-06-16T19:42:37+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 19:42:37 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 19:42:37 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 19:42:37 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:37 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:37 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:37 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:37 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jun 16 19:42:37 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jun 16 19:42:37 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:37 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:37 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:37 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:37 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jun 16 19:42:37 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jun 16 19:42:38 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:38 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:38 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:38 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:38 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jun 16 19:42:38 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jun 16 19:42:38 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jun 16 19:42:38 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jun 16 19:42:38 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:38 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:38 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:38 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:38 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jun 16 19:42:38 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jun 16 19:42:38 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jun 16 19:42:38 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jun 16 19:42:38 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:38 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:38 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:38 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:38 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jun 16 19:42:38 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jun 16 19:42:38 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jun 16 19:42:38 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jun 16 19:42:39 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jun 16 19:42:39 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jun 16 19:42:39 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:39 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:39 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:39 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:39 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 16 19:42:39 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:39 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:39 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:39 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:39 richdacvolumio volumio[1007]: info: Initializing connection to go-librespot Websocket Jun 16 19:42:39 richdacvolumio volumio[1007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 19:42:39 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:39 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:39 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:39 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:40 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:40 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:40 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:40 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:40 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 19:42:40 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 186. Jun 16 19:42:40 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 19:42:40 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 19:42:40 richdacvolumio go-librespot[22609]: Librespot-go daemon starting... Jun 16 19:42:40 richdacvolumio go-librespot[22609]: time="2025-06-16T19:42:40+01:00" level=info msg="generated new device id: e9cae3fcd07cda03f507f6f8c0e07274b56da77b" Jun 16 19:42:40 richdacvolumio go-librespot[22609]: time="2025-06-16T19:42:40+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 19:42:40 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:40 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:40 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:40 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:40 richdacvolumio go-librespot[22609]: time="2025-06-16T19:42:40+01:00" level=debug msg="obtained new client token: AAA3GTHSpTzyeQwdYjb2arR8a73CsWgvAlvqG4hMX523RAEN1ybi+m3sAfnOBJQ7A+m4AgR89wlzT11yAUgqGKg8dnrDHNRcz53QiY4pwPJsb2rEtgsMkqKOuVpRJgiOF+E4csU869sAFKRdoaM4B9a2igOB2kiT+s6kNOjzt0UNEnDEMQkVr3z6q+PnUNFv39xLT8uB5wrn4zPUS6RRaG8JEa6OHYjna+QbieeGLqnirTcLtIdICMk5z7EAIg==" Jun 16 19:42:40 richdacvolumio go-librespot[22609]: time="2025-06-16T19:42:40+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 19:42:40 richdacvolumio go-librespot[22609]: time="2025-06-16T19:42:40+01:00" level=debug msg="completed keyexchange" Jun 16 19:42:40 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:40 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:40 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:40 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:41 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:41 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:41 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:41 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:41 richdacvolumio go-librespot[22609]: time="2025-06-16T19:42:41+01:00" level=debug msg="completed challenge" Jun 16 19:42:41 richdacvolumio go-librespot[22609]: time="2025-06-16T19:42:41+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 19:42:41 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 19:42:41 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 19:42:41 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:41 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:41 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:41 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:41 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:41 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:41 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:41 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:42 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:42 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:42 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:42 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:42 richdacvolumio volumio[1007]: info: Initializing connection to go-librespot Websocket Jun 16 19:42:42 richdacvolumio volumio[1007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 19:42:42 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:42 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:42 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:42 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:42 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:42 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:42 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:42 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:43 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:43 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:43 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:43 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:43 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 16 19:42:43 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:43 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:43 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:43 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:43 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:43 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:43 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:43 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:44 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:44 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:44 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:44 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:44 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 19:42:44 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 187. Jun 16 19:42:44 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 19:42:44 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 19:42:44 richdacvolumio go-librespot[22702]: Librespot-go daemon starting... Jun 16 19:42:44 richdacvolumio go-librespot[22702]: time="2025-06-16T19:42:44+01:00" level=info msg="generated new device id: 8930f518b1c595d8d417275558b736c404a579ca" Jun 16 19:42:44 richdacvolumio go-librespot[22702]: time="2025-06-16T19:42:44+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 19:42:44 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:44 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:44 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:44 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:44 richdacvolumio go-librespot[22702]: time="2025-06-16T19:42:44+01:00" level=debug msg="obtained new client token: AADwbTjYKiw2NUogHWY7rVTU8OCJ3lhnoKxsrZGg7SsMU+9q1SsQyo9LqBu4xvp6dhtC4vDDIbSRv671yS1DPNiVn/yVy6vcRSQh4fUYfUWl2eAeVk2F8927Q8VEGWeAGC2vxGL9m7OjjhW+Fptgg8RXXTIZhEHbd4brH9eriohv82PvufSn893UAEulSRX7XobF/W/YE1JRK5r/lNF8hg93Q7tMW5kLMNwnljr1YYe2pMsjV43SvZ3I5Ut5+Q==" Jun 16 19:42:44 richdacvolumio go-librespot[22702]: time="2025-06-16T19:42:44+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 19:42:44 richdacvolumio go-librespot[22702]: time="2025-06-16T19:42:44+01:00" level=debug msg="completed keyexchange" Jun 16 19:42:44 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:44 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:45 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:45 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:45 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:45 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:45 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:45 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:45 richdacvolumio go-librespot[22702]: time="2025-06-16T19:42:45+01:00" level=debug msg="completed challenge" Jun 16 19:42:45 richdacvolumio go-librespot[22702]: time="2025-06-16T19:42:45+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 19:42:45 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 19:42:45 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 19:42:45 richdacvolumio volumio[1007]: info: Initializing connection to go-librespot Websocket Jun 16 19:42:45 richdacvolumio volumio[1007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 19:42:45 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:45 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:45 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:45 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:46 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:46 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:46 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:46 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:46 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:46 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:46 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:46 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:46 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:46 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:46 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:46 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:47 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:47 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:47 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:47 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:47 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:47 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:47 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:47 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:47 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 16 19:42:47 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:47 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:47 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:47 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:48 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:48 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:48 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:48 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:48 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:48 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:48 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:48 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:48 richdacvolumio volumio[1007]: info: Initializing connection to go-librespot Websocket Jun 16 19:42:48 richdacvolumio volumio[1007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 19:42:48 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 19:42:48 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 188. Jun 16 19:42:48 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 19:42:48 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:48 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:48 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:48 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:48 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 19:42:48 richdacvolumio go-librespot[22782]: Librespot-go daemon starting... Jun 16 19:42:48 richdacvolumio go-librespot[22782]: time="2025-06-16T19:42:48+01:00" level=info msg="generated new device id: 23caef0de91f7b42de3eb84872dbad896286bcd8" Jun 16 19:42:48 richdacvolumio go-librespot[22782]: time="2025-06-16T19:42:48+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 19:42:49 richdacvolumio go-librespot[22782]: time="2025-06-16T19:42:49+01:00" level=debug msg="obtained new client token: AABPuBouWXtEaAWOfRLl19vZDJ+iLNDpdxWlgjHOIcnRue0/z1WdZtyZzcAuOU3+XM7kU9iuor7HAzVQjnbuzbPrKzapIvAOXi1+aWjwY3GOLpudMcW8yHagkhyYbscSEeStPmxKbw3oAsrsfYBL/qCAKj4LMXmaYCsAtaMG8iEIcRTnyJ2kkMUU5akeABKM2xP/GngmhzI04aehuZr0wj/u23ll4zCw77+JjxbQt0pipA3IJwQb7lwd" Jun 16 19:42:49 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:49 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:49 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:49 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:49 richdacvolumio go-librespot[22782]: time="2025-06-16T19:42:49+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 19:42:49 richdacvolumio go-librespot[22782]: time="2025-06-16T19:42:49+01:00" level=debug msg="completed keyexchange" Jun 16 19:42:49 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:49 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:49 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:49 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:49 richdacvolumio go-librespot[22782]: time="2025-06-16T19:42:49+01:00" level=debug msg="completed challenge" Jun 16 19:42:49 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:49 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:49 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:49 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:49 richdacvolumio go-librespot[22782]: time="2025-06-16T19:42: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 19:42:49 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 19:42:49 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 19:42:50 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:50 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:50 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:50 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:50 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:50 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:50 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:50 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:50 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:50 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:50 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:50 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:51 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:51 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:51 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:51 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:51 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 16 19:42:51 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:51 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:51 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:51 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:51 richdacvolumio volumio[1007]: info: Initializing connection to go-librespot Websocket Jun 16 19:42:51 richdacvolumio volumio[1007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 19:42:51 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:51 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:51 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:51 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:52 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:52 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:52 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:52 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:52 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:52 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:52 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:52 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:52 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:52 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:52 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:52 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:52 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 19:42:52 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 189. Jun 16 19:42:52 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 19:42:53 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 19:42:53 richdacvolumio go-librespot[22869]: Librespot-go daemon starting... Jun 16 19:42:53 richdacvolumio go-librespot[22869]: time="2025-06-16T19:42:53+01:00" level=info msg="generated new device id: 98f4f926a7cc4f0acbfcb63732f252b4cb6d47a7" Jun 16 19:42:53 richdacvolumio go-librespot[22869]: time="2025-06-16T19:42:53+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 19:42:53 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:53 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:53 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:53 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:53 richdacvolumio go-librespot[22869]: time="2025-06-16T19:42:53+01:00" level=debug msg="obtained new client token: AAAGA1guY88hM4dioBae1rojY1R1BR9zBYcXMsdR0TgQE5xlAfOJBxkPaOm4TB/OEdJW8Wog6G2wLe2I4PYslNQqgoCbVN6tJ+XxIMwltdvcwtuYNWOITqW4KWjxUh5RkhuVVXEIMOjTDChBK4MfXa+K323SRRUhZ89luQrY+hdaP7fFKWy1kvSWm3gd6AtZZ01eB082qH68ZBEpUlMMe0ZX2MWaT/5GDD+Yar4iR7KmEDR/y2ORPMrXBjQ=" Jun 16 19:42:53 richdacvolumio go-librespot[22869]: time="2025-06-16T19:42: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-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jun 16 19:42:53 richdacvolumio go-librespot[22869]: time="2025-06-16T19:42:53+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 19:42:53 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 19:42:53 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 19:42:53 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:53 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:53 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:53 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:53 richdacvolumio volumio[1007]: info: Disabling MyMusic plugin upnp_browser Jun 16 19:42:53 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesMedia Servers Jun 16 19:42:53 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 16 19:42:53 richdacvolumio volumio[1007]: Cannot find translation for source Bandcamp Discover Jun 16 19:42:53 richdacvolumio volumio[1007]: Cannot find translation for source Mixcloud Jun 16 19:42:53 richdacvolumio volumio[1007]: Cannot find translation for source YouTube2 Jun 16 19:42:53 richdacvolumio volumio[1007]: Cannot find translation for source 80s80s Radio Jun 16 19:42:53 richdacvolumio volumio[1007]: Cannot find translation for source Mother Earth Radio Jun 16 19:42:53 richdacvolumio volumio[1007]: info: Disabling plugin upnp_browser Jun 16 19:42:53 richdacvolumio volumio[1007]: info: Done. Jun 16 19:42:53 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:53 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:53 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:53 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:54 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:54 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:54 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:54 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:54 richdacvolumio volumio[1007]: info: Initializing connection to go-librespot Websocket Jun 16 19:42:54 richdacvolumio volumio[1007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 19:42:54 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:54 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:54 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:54 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:54 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:54 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:54 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:54 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:55 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:55 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:55 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:55 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:55 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 16 19:42:55 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:55 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:55 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:55 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:55 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:55 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:55 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:55 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:56 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:56 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:56 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:56 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:56 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 19:42:56 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 190. Jun 16 19:42:56 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 19:42:56 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 19:42:56 richdacvolumio go-librespot[22937]: Librespot-go daemon starting... Jun 16 19:42:56 richdacvolumio go-librespot[22937]: time="2025-06-16T19:42:56+01:00" level=info msg="generated new device id: 8914f44cc3b81715846e216a8a08f55570bd82ff" Jun 16 19:42:56 richdacvolumio go-librespot[22937]: time="2025-06-16T19:42:56+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 19:42:56 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:56 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:56 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:56 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:56 richdacvolumio go-librespot[22937]: time="2025-06-16T19:42:56+01:00" level=debug msg="obtained new client token: AADmlihh2/shh23tlGN00imsLnjs0PRBOx91YPgE+YBf5go7xY9skZ0fYcYGCOCNNayiNAWFdrH1s2sn+A5+mckg4CVE68vmCxSb9Xe9ewDTtmiFFibnvGSri5d1DOnmvn3FqAbQVOFDvR3+JKWE+/fSSylLEtxqTBT3aJ7rNed0nc2FsNYQ4dXIypJ18MH5enhJ0vIJIcgkv8KluWtw/cgZEzVhZm8Oa+TAgZQWFlRwbYSOWyYSqUjCQaC7JQ==" Jun 16 19:42:56 richdacvolumio go-librespot[22937]: time="2025-06-16T19:42:56+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 19:42:57 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:57 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:57 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:57 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:57 richdacvolumio go-librespot[22937]: time="2025-06-16T19:42:57+01:00" level=debug msg="completed keyexchange" Jun 16 19:42:57 richdacvolumio volumio[1007]: info: Enabling MyMusic plugin upnp_browser Jun 16 19:42:57 richdacvolumio volumio[1007]: info: Enabling plugin upnp_browser Jun 16 19:42:57 richdacvolumio volumio[1007]: info: Loading plugin "upnp_browser"... Jun 16 19:42:57 richdacvolumio volumio[1007]: info: PLUGIN START: upnp_browser Jun 16 19:42:57 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 16 19:42:57 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 16 19:42:57 richdacvolumio volumio[1007]: info: [1750099377036] CoreMusicLibrary::Adding element Media Servers Jun 16 19:42:57 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 16 19:42:57 richdacvolumio volumio[1007]: Cannot find translation for source Bandcamp Discover Jun 16 19:42:57 richdacvolumio volumio[1007]: Cannot find translation for source Mixcloud Jun 16 19:42:57 richdacvolumio volumio[1007]: Cannot find translation for source YouTube2 Jun 16 19:42:57 richdacvolumio volumio[1007]: Cannot find translation for source 80s80s Radio Jun 16 19:42:57 richdacvolumio volumio[1007]: Cannot find translation for source Mother Earth Radio Jun 16 19:42:57 richdacvolumio volumio[1007]: info: Done. Jun 16 19:42:57 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:57 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:57 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:57 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:57 richdacvolumio go-librespot[22937]: time="2025-06-16T19:42:57+01:00" level=debug msg="completed challenge" Jun 16 19:42:57 richdacvolumio go-librespot[22937]: time="2025-06-16T19:42:57+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 19:42:57 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 19:42:57 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 19:42:57 richdacvolumio volumio[1007]: info: Initializing connection to go-librespot Websocket Jun 16 19:42:57 richdacvolumio volumio[1007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 19:42:57 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:57 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:57 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:57 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:58 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:58 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:58 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:58 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:58 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:58 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:58 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:58 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:58 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:58 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:58 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:58 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:59 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:59 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:59 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:59 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:59 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:59 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:59 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:59 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:59 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 16 19:42:59 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:59 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:42:59 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:42:59 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:00 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:00 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:00 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:00 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:00 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:00 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:00 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:00 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:00 richdacvolumio volumio[1007]: info: Initializing connection to go-librespot Websocket Jun 16 19:43:00 richdacvolumio volumio[1007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 19:43:00 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 19:43:00 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 191. Jun 16 19:43:00 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 19:43:00 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:00 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:00 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:00 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:00 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 19:43:00 richdacvolumio go-librespot[23017]: Librespot-go daemon starting... Jun 16 19:43:00 richdacvolumio go-librespot[23017]: time="2025-06-16T19:43:00+01:00" level=info msg="generated new device id: 60e4eb802b3d720420b26f01327eeaca9c5c00c6" Jun 16 19:43:00 richdacvolumio go-librespot[23017]: time="2025-06-16T19:43:00+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 19:43:01 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:01 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:01 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:01 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:01 richdacvolumio go-librespot[23017]: time="2025-06-16T19:43:01+01:00" level=debug msg="obtained new client token: AAC9XB4cetP5wq1blpe7sEIZVzU7sAmwOnZaNsQdcOnTJ4L4YtLrrsH8DoExCiv+1DhWbaynJQ9yck/0PKYzeSuZwXsYyyacHDbAw7jUCSPCtQaVo8eCbRvnpaH6+9xWsrsxASVI2RPkYXT8DEiK+dqr7rzXeW59Jvp1rJHmx+SGJz0HhdxnF0YiepMl3AeJmi7zEztZgaG34UGRXo1QBykacSnL7smokNkREYYkC0D36zGng4KXGkjMVY4=" Jun 16 19:43:01 richdacvolumio go-librespot[23017]: time="2025-06-16T19:43: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 19:43:01 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:01 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:01 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:01 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:01 richdacvolumio go-librespot[23017]: time="2025-06-16T19:43:01+01:00" level=debug msg="completed keyexchange" Jun 16 19:43:01 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:01 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:01 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:01 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:01 richdacvolumio go-librespot[23017]: time="2025-06-16T19:43:01+01:00" level=debug msg="completed challenge" Jun 16 19:43:02 richdacvolumio go-librespot[23017]: time="2025-06-16T19:43: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 19:43:02 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 19:43:02 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 19:43:02 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:02 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:02 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:02 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:02 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:02 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:02 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:02 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:02 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:02 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:02 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:02 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:03 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:03 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:03 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:03 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:03 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:03 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:03 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:03 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:03 richdacvolumio volumio[1007]: info: Initializing connection to go-librespot Websocket Jun 16 19:43:03 richdacvolumio volumio[1007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 19:43:03 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 16 19:43:03 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:03 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:03 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:03 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:04 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:04 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:04 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:04 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:04 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:04 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:04 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:04 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:04 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:04 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:04 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:04 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:05 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 19:43:05 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 192. Jun 16 19:43:05 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 19:43:05 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:05 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:05 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:05 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:05 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 19:43:05 richdacvolumio go-librespot[23147]: Librespot-go daemon starting... Jun 16 19:43:05 richdacvolumio go-librespot[23147]: time="2025-06-16T19:43:05+01:00" level=info msg="generated new device id: c0a1dd5e346f30e24d8cc357164d9548501a4c61" Jun 16 19:43:05 richdacvolumio go-librespot[23147]: time="2025-06-16T19:43:05+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 19:43:05 richdacvolumio go-librespot[23147]: time="2025-06-16T19:43:05+01:00" level=debug msg="obtained new client token: AACB2w6oTQZtKldby3l47UX7YvEnHAhw6mf0vkeR0opL9Uznz2iGHdjiQVtUbOm8Ws2nh44/a+DNDI7JtC1z09UUZPhMQAKfsLPzdYC5XrXTkaBfU56ApAi5J4Td+SO120WpknCIf5Axp3HbLvTZqMFc1j3O6tiuqHb6/wJ3l3fhBKfcfvHhkseFIeUEjsZFtffXMsa3/30DhRH4MG9pFiaWra1ZoBz3W9UkyJv8d3Mu3Fa8/6lafT+GSUBf6Q==" Jun 16 19:43:05 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:05 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:05 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:05 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:05 richdacvolumio go-librespot[23147]: time="2025-06-16T19:43:05+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 19:43:05 richdacvolumio go-librespot[23147]: time="2025-06-16T19:43:05+01:00" level=debug msg="completed keyexchange" Jun 16 19:43:05 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:05 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:05 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:05 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:06 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:06 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:06 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:06 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:06 richdacvolumio go-librespot[23147]: time="2025-06-16T19:43:06+01:00" level=debug msg="completed challenge" Jun 16 19:43:06 richdacvolumio go-librespot[23147]: time="2025-06-16T19:43: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 19:43:06 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 19:43:06 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 19:43:06 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:06 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:06 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:06 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:06 richdacvolumio volumio[1007]: info: Initializing connection to go-librespot Websocket Jun 16 19:43:06 richdacvolumio volumio[1007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 19:43:06 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:06 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:06 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:06 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:07 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:07 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:07 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:07 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:07 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:07 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:07 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:07 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:07 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 16 19:43:07 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:07 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:07 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:07 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:08 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:08 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:08 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:08 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:08 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:08 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:08 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:08 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:08 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:08 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:08 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:08 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:09 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:09 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:09 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:09 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:09 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 19:43:09 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 193. Jun 16 19:43:09 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 19:43:09 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 19:43:09 richdacvolumio go-librespot[23234]: Librespot-go daemon starting... Jun 16 19:43:09 richdacvolumio go-librespot[23234]: time="2025-06-16T19:43:09+01:00" level=info msg="generated new device id: bfdf80e8acf27fc3339b6b108c026e59e8c7c640" Jun 16 19:43:09 richdacvolumio go-librespot[23234]: time="2025-06-16T19:43:09+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 19:43:09 richdacvolumio volumio[1007]: info: Initializing connection to go-librespot Websocket Jun 16 19:43:09 richdacvolumio go-librespot[23234]: time="2025-06-16T19:43:09+01:00" level=debug msg="new websocket client" Jun 16 19:43:09 richdacvolumio volumio[1007]: info: Connection to go-librespot Websocket established Jun 16 19:43:09 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:09 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:09 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:09 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:09 richdacvolumio go-librespot[23234]: time="2025-06-16T19:43:09+01:00" level=debug msg="obtained new client token: AACO1cwsvUY7GtfNwdt/xxMg6/XS70YcZxScmgbtDulhR7xDbbLJZMUZsb5122zwAyTPqI0H+lhtNnDlNeAS1fUT0UClafI8Qze9l0xIpGhNaFolOrLcThyGCCIaK2L5uDJLa0naR8Cl82tg3KPpE6JsvrnzLLnnMTmpw15cwzuXSr1lYD5VnRuX+sv9FFRKULnn3issthuueoM9x1xwba7auBff2+YcwuBroYtKfImo7HvrJ86sRXsQXS7Evw==" Jun 16 19:43:09 richdacvolumio go-librespot[23234]: time="2025-06-16T19:43:09+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 19:43:09 richdacvolumio go-librespot[23234]: time="2025-06-16T19:43:09+01:00" level=debug msg="completed keyexchange" Jun 16 19:43:10 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:10 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:10 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:10 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:10 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:10 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:10 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:10 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:10 richdacvolumio go-librespot[23234]: time="2025-06-16T19:43:10+01:00" level=debug msg="completed challenge" Jun 16 19:43:10 richdacvolumio go-librespot[23234]: time="2025-06-16T19:43:10+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 19:43:10 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 19:43:10 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 19:43:10 richdacvolumio volumio[1007]: info: Connection to go-librespot Websocket closed Jun 16 19:43:10 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:10 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:10 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:10 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:11 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:11 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:11 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:11 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:11 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:11 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:11 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:11 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:11 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 16 19:43:11 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:11 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:11 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:11 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:12 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:12 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:12 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:12 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:12 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:12 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:12 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:12 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:12 richdacvolumio volumio[1007]: info: Getting Spotify volume Jun 16 19:43:12 richdacvolumio volumio[1007]: (node:1007) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 19:43:12 richdacvolumio volumio[1007]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jun 16 19:43:12 richdacvolumio volumio[1007]: (node:1007) 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: 3097) Jun 16 19:43:12 richdacvolumio volumio[1007]: 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 19:43:12 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:12 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:12 richdacvolumio volumio[1007]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 16 19:43:12 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:12 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:12 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:12 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:13 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:13 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:13 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:13 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:13 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:13 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:13 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:13 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:13 richdacvolumio volumio[1007]: info: Initializing connection to go-librespot Websocket Jun 16 19:43:13 richdacvolumio volumio[1007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 19:43:13 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 19:43:13 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 194. Jun 16 19:43:13 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 19:43:13 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:13 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:13 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:13 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:13 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 19:43:13 richdacvolumio go-librespot[23314]: Librespot-go daemon starting... Jun 16 19:43:13 richdacvolumio go-librespot[23314]: time="2025-06-16T19:43:13+01:00" level=info msg="generated new device id: 828b34e3f540c62ab236c0d73aef9fc9ed95586a" Jun 16 19:43:13 richdacvolumio go-librespot[23314]: time="2025-06-16T19:43:13+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 19:43:14 richdacvolumio go-librespot[23314]: time="2025-06-16T19:43:14+01:00" level=debug msg="obtained new client token: AAAwQnPl7doCfHIECFh15GDLPK41XweAQ7cJY+slP3hSz9OGGc9q+1a07VwZHCpG2gAijglD/5Docl9hCEe5fghMvRrtCDU4S6gOou0euAnfCnxNTSNpFXWlaq5xGsnBvkmepSM37zVg0WpEw1PyTv2mApn3sdGSrR1oLJXs4DAmEK5M+Ttrj+p3nkm1j8sdEhpyWN9MvDFYhcuC7xXQQMx+W6Jk5W+hhmC/iTHDaqxh4qF80nsqgq2rhWPKBw==" Jun 16 19:43:14 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:14 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:14 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:14 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:14 richdacvolumio go-librespot[23314]: time="2025-06-16T19:43:14+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 19:43:14 richdacvolumio go-librespot[23314]: time="2025-06-16T19:43:14+01:00" level=debug msg="completed keyexchange" Jun 16 19:43:14 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:14 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:14 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:14 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:14 richdacvolumio go-librespot[23314]: time="2025-06-16T19:43:14+01:00" level=debug msg="completed challenge" Jun 16 19:43:14 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:14 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:14 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:14 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:14 richdacvolumio go-librespot[23314]: time="2025-06-16T19:43:14+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 19:43:14 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 19:43:14 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 19:43:15 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:15 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:15 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:15 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:15 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:15 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:15 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:15 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:15 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 16 19:43:15 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:15 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:15 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:15 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:16 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:16 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:16 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:16 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:16 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:16 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:16 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:16 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:16 richdacvolumio volumio[1007]: info: Initializing connection to go-librespot Websocket Jun 16 19:43:16 richdacvolumio volumio[1007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 19:43:16 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:16 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:16 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:16 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:17 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:17 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:17 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:17 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:17 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:17 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:17 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:17 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:17 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:17 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:17 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:17 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:17 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 19:43:17 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 195. Jun 16 19:43:17 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 19:43:18 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 19:43:18 richdacvolumio go-librespot[23401]: Librespot-go daemon starting... Jun 16 19:43:18 richdacvolumio go-librespot[23401]: time="2025-06-16T19:43:18+01:00" level=info msg="generated new device id: 36dbfeb6019c319a74c02988778c1bb86db52882" Jun 16 19:43:18 richdacvolumio go-librespot[23401]: time="2025-06-16T19:43:18+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 19:43:18 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:18 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:18 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:18 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:18 richdacvolumio go-librespot[23401]: time="2025-06-16T19:43:18+01:00" level=debug msg="obtained new client token: AAB3BYIM7D2Dq5GjpX6JYYRFt55maBaQALOR8IWOcEFNyEt+vGGR7CAS1a+D18lNk8+SpsE4fPu5XnVgCTV8NJy5ZKsN6XDQHZ8puFJ8kQaOoklBlkAiF9q4kpYc32Z+4bmcutkJbkDWDW5wLldwfv8IrcxRGqTh5ZOrrf3XAHmo0JkoMN2aLeGrFpoWKXU7S6XpjJOL7J+mS9OiCko7fwTVqVt5Rq6WRdrwwouBMErcK0ebpjIXC3vVfVI=" Jun 16 19:43:18 richdacvolumio go-librespot[23401]: time="2025-06-16T19:43:18+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 19:43:18 richdacvolumio go-librespot[23401]: time="2025-06-16T19:43:18+01:00" level=debug msg="completed keyexchange" Jun 16 19:43:18 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:18 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:18 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:18 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:18 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:18 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:18 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:18 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:18 richdacvolumio go-librespot[23401]: time="2025-06-16T19:43:18+01:00" level=debug msg="completed challenge" Jun 16 19:43:19 richdacvolumio go-librespot[23401]: time="2025-06-16T19:43:19+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 19:43:19 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 19:43:19 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 19:43:19 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:19 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:19 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:19 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:19 richdacvolumio volumio[1007]: info: Initializing connection to go-librespot Websocket Jun 16 19:43:19 richdacvolumio volumio[1007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 19:43:19 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:19 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:19 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:19 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:19 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 16 19:43:19 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:19 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:19 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:19 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:20 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:20 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:20 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:20 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:20 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:20 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:20 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:20 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:20 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:20 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:20 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:20 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:21 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:21 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:21 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:21 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:21 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:21 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:21 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:21 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:21 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:21 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:22 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:22 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:22 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 19:43:22 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 196. Jun 16 19:43:22 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 19:43:22 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 19:43:22 richdacvolumio go-librespot[23481]: Librespot-go daemon starting... Jun 16 19:43:22 richdacvolumio go-librespot[23481]: time="2025-06-16T19:43:22+01:00" level=info msg="generated new device id: f25b58f1bf0fde28198262b34d3a4abcce200fa3" Jun 16 19:43:22 richdacvolumio go-librespot[23481]: time="2025-06-16T19:43:22+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 19:43:22 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:22 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:22 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:22 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:22 richdacvolumio go-librespot[23481]: time="2025-06-16T19:43:22+01:00" level=debug msg="obtained new client token: AAAEP5J25Z/gRkrqUG06OqvbJPu7N7bBiS6QRrrm5HX8TPhPqHwWZ6Kr2nnmHX8hHECAc5MU/LPkZlZsIBjpnfFJjrzzWMUiXXTCXsWBsKBfBypWVoSqzTlLv1cz50MvBC7dddSfWDNtOrZrjfyaVe9kMi1clnZ6Vuyv5v5IXjJYperbl9wJe799bZvjESVDXXKJk+lEBygK1u3WZpESqL+85Do6R8B6kMNqnLGqB4gQ8Jv5RmF0UL8NeuJ9cg==" Jun 16 19:43:22 richdacvolumio volumio[1007]: info: Initializing connection to go-librespot Websocket Jun 16 19:43:22 richdacvolumio go-librespot[23481]: time="2025-06-16T19:43:22+01:00" level=debug msg="new websocket client" Jun 16 19:43:22 richdacvolumio volumio[1007]: info: Connection to go-librespot Websocket established Jun 16 19:43:22 richdacvolumio go-librespot[23481]: time="2025-06-16T19:43:22+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 19:43:22 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:22 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:22 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:22 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:22 richdacvolumio go-librespot[23481]: time="2025-06-16T19:43:22+01:00" level=debug msg="completed keyexchange" Jun 16 19:43:23 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:23 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:23 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:23 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:23 richdacvolumio go-librespot[23481]: time="2025-06-16T19:43:23+01:00" level=debug msg="completed challenge" Jun 16 19:43:23 richdacvolumio go-librespot[23481]: time="2025-06-16T19:43:23+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 19:43:23 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 19:43:23 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 19:43:23 richdacvolumio volumio[1007]: info: Connection to go-librespot Websocket closed Jun 16 19:43:23 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:23 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:23 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:23 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:23 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 16 19:43:23 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:23 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:23 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:23 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:24 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:24 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:24 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:24 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:24 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:24 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:24 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:24 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:24 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:24 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:24 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:24 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:25 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:25 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:25 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:25 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:25 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:25 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:25 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:25 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:25 richdacvolumio volumio[1007]: info: Getting Spotify volume Jun 16 19:43:25 richdacvolumio volumio[1007]: (node:1007) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 19:43:25 richdacvolumio volumio[1007]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jun 16 19:43:25 richdacvolumio volumio[1007]: (node:1007) 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: 3098) Jun 16 19:43:25 richdacvolumio volumio[1007]: 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 19:43:25 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:25 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:25 richdacvolumio volumio[1007]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 16 19:43:25 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:25 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:25 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:25 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:26 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:26 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:26 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:26 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:26 richdacvolumio volumio[1007]: info: Initializing connection to go-librespot Websocket Jun 16 19:43:26 richdacvolumio volumio[1007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 19:43:26 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:26 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:26 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:26 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:26 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 19:43:26 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 197. Jun 16 19:43:26 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 19:43:26 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 19:43:26 richdacvolumio go-librespot[23565]: Librespot-go daemon starting... Jun 16 19:43:26 richdacvolumio go-librespot[23565]: time="2025-06-16T19:43:26+01:00" level=info msg="generated new device id: e6874146c480e5438dc11a2428dc9d6510ab936d" Jun 16 19:43:26 richdacvolumio go-librespot[23565]: time="2025-06-16T19:43:26+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 19:43:26 richdacvolumio go-librespot[23565]: time="2025-06-16T19:43:26+01:00" level=debug msg="obtained new client token: AACs+DquBbe1Sehc9h/F64wTp9C9j9Rt4D66P1OaOhrXcTkPrRDV5Vb6GyjkQxL49+26ahtiBJA6XIFWhI5DzSXqKzJnu9x/7j0YuIlR/ivrkVfBRkRV8xELb0C7DyhyUWwaoGLKL79SV6pypCCh5SYVxw43jrUPoAWKL0WJFA8kc3HF/8ODJwtdLAFmLboWlyqBpl3PeiIvG9zHYdwWmkokhcjixxyaMJb+LCDKtPYwTDZoqADGPmUYKstEzw==" Jun 16 19:43:26 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:26 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:26 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:26 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:26 richdacvolumio go-librespot[23565]: time="2025-06-16T19:43:26+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 19:43:26 richdacvolumio go-librespot[23565]: time="2025-06-16T19:43:26+01:00" level=debug msg="completed keyexchange" Jun 16 19:43:27 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:27 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:27 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:27 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:27 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:27 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:27 richdacvolumio go-librespot[23565]: time="2025-06-16T19:43:27+01:00" level=debug msg="completed challenge" Jun 16 19:43:27 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:27 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:27 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:27 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:27 richdacvolumio go-librespot[23565]: time="2025-06-16T19:43:27+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 19:43:27 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 19:43:27 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 19:43:27 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:27 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:27 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:27 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:28 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:28 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:28 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:28 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:28 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:28 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:28 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:28 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:28 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:28 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:28 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:28 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:29 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:29 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:29 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:29 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:29 richdacvolumio volumio[1007]: info: Initializing connection to go-librespot Websocket Jun 16 19:43:29 richdacvolumio volumio[1007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 19:43:29 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:29 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:29 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:29 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:29 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:29 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:29 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:29 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:30 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:30 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:30 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:30 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:30 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:30 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:30 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:30 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:30 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 19:43:30 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 198. Jun 16 19:43:30 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 19:43:30 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 19:43:30 richdacvolumio go-librespot[23648]: Librespot-go daemon starting... Jun 16 19:43:30 richdacvolumio go-librespot[23648]: time="2025-06-16T19:43:30+01:00" level=info msg="generated new device id: 45ce13f349cb6550be65afd20dfa8f0cc7ed21c4" Jun 16 19:43:30 richdacvolumio go-librespot[23648]: time="2025-06-16T19:43:30+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 19:43:30 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:30 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:30 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:30 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:31 richdacvolumio go-librespot[23648]: time="2025-06-16T19:43:31+01:00" level=debug msg="obtained new client token: AACAvCCgi1RZPtDMX+0sP4K2DeUqvq7cyUgMn/OzAf8XWrOJ8vNzMQSjs73O86thAi9cWcUIuK8tcBg+HjXZWbRDNqIMbSqrK0R35+qA4c0o0k2Y71wkzQML2FK7Oz5VcPZSPyzmZ/aCNEvGACjr2A1afXv23hWlHeUzCrUiPzJlXa4DkIM8bL5HS+3VLviT72VAqelfcskMoPbQ5wg5Io/7BgY8mqrgUWAq97qJdTF4/I1rqnrrf2sbKOw=" Jun 16 19:43:31 richdacvolumio go-librespot[23648]: time="2025-06-16T19:43:31+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 19:43:31 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:31 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:31 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:31 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:31 richdacvolumio go-librespot[23648]: time="2025-06-16T19:43:31+01:00" level=debug msg="completed keyexchange" Jun 16 19:43:31 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:31 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:31 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:31 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:31 richdacvolumio go-librespot[23648]: time="2025-06-16T19:43:31+01:00" level=debug msg="completed challenge" Jun 16 19:43:31 richdacvolumio go-librespot[23648]: time="2025-06-16T19:43:31+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 19:43:31 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 19:43:31 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 19:43:31 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:31 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:31 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:31 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:32 richdacvolumio volumio[1007]: info: Initializing connection to go-librespot Websocket Jun 16 19:43:32 richdacvolumio volumio[1007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 19:43:32 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:32 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:32 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:32 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:32 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:32 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:32 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:32 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:32 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:32 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:32 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:32 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:33 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:33 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:33 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:33 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:33 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:33 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:33 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:33 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:34 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:34 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:34 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:34 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:34 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:34 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:34 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:34 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:34 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:34 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:34 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:34 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:34 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 19:43:34 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 199. Jun 16 19:43:34 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 19:43:35 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 19:43:35 richdacvolumio go-librespot[23728]: Librespot-go daemon starting... Jun 16 19:43:35 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:35 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:35 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:35 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:35 richdacvolumio go-librespot[23728]: time="2025-06-16T19:43:35+01:00" level=info msg="generated new device id: 361bd0b0289c072240c3d5649072abdebbe4e185" Jun 16 19:43:35 richdacvolumio go-librespot[23728]: time="2025-06-16T19:43:35+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 19:43:35 richdacvolumio go-librespot[23728]: time="2025-06-16T19:43:35+01:00" level=debug msg="obtained new client token: AAAI9/Htx7boqXGe5fRr4JkobVdKBhuSKnmRGpAIUO3/OD0uoA84FVmor7edS3J42tWqG/BPBfK0dXcb4hxKXTKu0A8ipe3WqMxbQbyccwPZt2PDVCoBFlvxn5Cdr4fIpYJtbOxn9G08CRBZbf1wTgG/9ddPcluk9GTJPoZOulE+Cvmrp8nK4+oxUAZbzMeV+f8xHxIVMZ6bVESbJnlNLHpusqavKZNBnekw8EfAI+wf8ufENDfbXLI+Khw=" Jun 16 19:43:35 richdacvolumio volumio[1007]: info: Initializing connection to go-librespot Websocket Jun 16 19:43:35 richdacvolumio go-librespot[23728]: time="2025-06-16T19:43:35+01:00" level=debug msg="new websocket client" Jun 16 19:43:35 richdacvolumio volumio[1007]: info: Connection to go-librespot Websocket established Jun 16 19:43:35 richdacvolumio go-librespot[23728]: time="2025-06-16T19:43:35+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 19:43:35 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:35 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:35 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:35 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:35 richdacvolumio go-librespot[23728]: time="2025-06-16T19:43:35+01:00" level=debug msg="completed keyexchange" Jun 16 19:43:35 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:35 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:35 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:35 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:35 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetQueue Jun 16 19:43:35 richdacvolumio volumio[1007]: info: CoreStateMachine::getQueue Jun 16 19:43:35 richdacvolumio volumio[1007]: info: CorePlayQueue::getQueue Jun 16 19:43:35 richdacvolumio go-librespot[23728]: time="2025-06-16T19:43:35+01:00" level=debug msg="completed challenge" Jun 16 19:43:36 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:36 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:36 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:36 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:36 richdacvolumio go-librespot[23728]: time="2025-06-16T19:43:36+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 19:43:36 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 19:43:36 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 19:43:36 richdacvolumio volumio[1007]: info: Connection to go-librespot Websocket closed Jun 16 19:43:36 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:36 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:36 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:36 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:36 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:36 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:36 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:36 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:37 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:37 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:37 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:37 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:37 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:37 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:37 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:37 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:37 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:37 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:37 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:37 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:37 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 16 19:43:37 richdacvolumio volumio[1007]: info: Preload queue cleared Jun 16 19:43:38 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:38 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:38 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:38 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:38 richdacvolumio volumio[1007]: info: Getting Spotify volume Jun 16 19:43:38 richdacvolumio volumio[1007]: (node:1007) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 19:43:38 richdacvolumio volumio[1007]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jun 16 19:43:38 richdacvolumio volumio[1007]: (node:1007) 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: 3099) Jun 16 19:43:38 richdacvolumio volumio[1007]: 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 19:43:38 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:38 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:38 richdacvolumio volumio[1007]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 16 19:43:38 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:38 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:38 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:38 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:38 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:38 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:38 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:38 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:39 richdacvolumio volumio[1007]: info: Initializing connection to go-librespot Websocket Jun 16 19:43:39 richdacvolumio volumio[1007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 19:43:39 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:39 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:39 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:39 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:39 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 19:43:39 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 200. Jun 16 19:43:39 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 19:43:39 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 19:43:39 richdacvolumio go-librespot[23814]: Librespot-go daemon starting... Jun 16 19:43:39 richdacvolumio go-librespot[23814]: time="2025-06-16T19:43:39+01:00" level=info msg="generated new device id: f56152d351503ad83d97f83d104b09e4487d4c8e" Jun 16 19:43:39 richdacvolumio go-librespot[23814]: time="2025-06-16T19:43:39+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 19:43:39 richdacvolumio go-librespot[23814]: time="2025-06-16T19:43:39+01:00" level=debug msg="obtained new client token: AAAjMOS5qDywSNGnrxzc/UWq7e0ShKp1BUgsA89TQ1X5dOIkjBmCXVXKAWhA+bll9HaqIeHOOA6FMb5b6tFrI2jIGhejtHP5Z2Yre+fnevYBkURt3aM1usy/Fr7YvbVOCJViR4Hlo3ojkxMW57ryLNtp88j7GGd/mcKgVWAXAyTy31WJ7xLc1lHqeTSpJKRrxKmzzSHevhARlLFlXl4SK0oE2Jv2R/y0uwUuF+XcStDG2Se+Ty6Nquf9PUdxHA==" Jun 16 19:43:39 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:39 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:39 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:39 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:39 richdacvolumio go-librespot[23814]: time="2025-06-16T19:43:39+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 19:43:39 richdacvolumio go-librespot[23814]: time="2025-06-16T19:43:39+01:00" level=debug msg="completed keyexchange" Jun 16 19:43:39 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:39 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:39 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:39 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:40 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:40 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:40 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:40 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:40 richdacvolumio go-librespot[23814]: time="2025-06-16T19:43:40+01:00" level=debug msg="completed challenge" Jun 16 19:43:40 richdacvolumio go-librespot[23814]: time="2025-06-16T19:43:40+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 19:43:40 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 19:43:40 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 19:43:40 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:40 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:40 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:40 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:40 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:40 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:40 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:40 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:41 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:41 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:41 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:41 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:41 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:41 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:41 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:41 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:41 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:41 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:41 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:41 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:42 richdacvolumio volumio[1007]: info: Initializing connection to go-librespot Websocket Jun 16 19:43:42 richdacvolumio volumio[1007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 19:43:42 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:42 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:42 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:42 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:42 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:42 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:42 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:42 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:42 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:42 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:42 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:42 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:43 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:43 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:43 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:43 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:43 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 19:43:43 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 201. Jun 16 19:43:43 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 19:43:43 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 19:43:43 richdacvolumio go-librespot[23895]: Librespot-go daemon starting... Jun 16 19:43:43 richdacvolumio go-librespot[23895]: time="2025-06-16T19:43:43+01:00" level=info msg="generated new device id: 9dfd2937de086661ebfeaed1176e92f96c952715" Jun 16 19:43:43 richdacvolumio go-librespot[23895]: time="2025-06-16T19:43:43+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 19:43:43 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:43 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:43 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:43 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:43 richdacvolumio go-librespot[23895]: time="2025-06-16T19:43:43+01:00" level=debug msg="obtained new client token: AABgYY3i9l4nvso1AtRX2nBbCqGUJPgGMkGL1zHD1ptAG0VnpB4y+TQolRJ4Zw7Z/f1z2gik8ff3cscYkby2npcJHu+8z0+mTerkWEKKpLI+AcZznfoi0LYTzonwRTPEza0UITDScFJWu5iqwfBMynQdDnWcor2XW8fxJ/jgSo1NhLxTyo4h4TtS0EMesQchS5K50QmBSRbpj9M7rLw53Ow46nSFUnX0A9COnww2YiNaeaPhZeDIwvPpYOvT4w==" Jun 16 19:43:43 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:43 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:43 richdacvolumio go-librespot[23895]: time="2025-06-16T19:43: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-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jun 16 19:43:43 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:43 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:44 richdacvolumio go-librespot[23895]: time="2025-06-16T19:43:44+01:00" level=debug msg="completed keyexchange" Jun 16 19:43:44 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:44 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:44 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:44 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:44 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 16 19:43:44 richdacvolumio volumio[1007]: info: Preload queue cleared Jun 16 19:43:44 richdacvolumio go-librespot[23895]: time="2025-06-16T19:43:44+01:00" level=debug msg="completed challenge" Jun 16 19:43:44 richdacvolumio go-librespot[23895]: time="2025-06-16T19:43: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 19:43:44 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 19:43:44 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 19:43:44 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:44 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:44 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:44 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:44 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:44 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:44 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:44 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:45 richdacvolumio volumio[1007]: info: Initializing connection to go-librespot Websocket Jun 16 19:43:45 richdacvolumio volumio[1007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 19:43:45 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:45 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:45 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:45 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:45 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:45 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:45 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:45 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:45 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:45 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:45 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:45 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:46 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 16 19:43:46 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:46 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:46 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:46 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:46 richdacvolumio volumio[1007]: info: Preload queue cleared Jun 16 19:43:46 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:46 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:46 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:46 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:47 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:47 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:47 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:47 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:47 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:47 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:47 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:47 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:47 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:47 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:47 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:47 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:47 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 19:43:47 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 202. Jun 16 19:43:47 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 19:43:47 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 19:43:47 richdacvolumio go-librespot[23977]: Librespot-go daemon starting... Jun 16 19:43:47 richdacvolumio go-librespot[23977]: time="2025-06-16T19:43:47+01:00" level=info msg="generated new device id: 9413d99408fc59e11cd20338c68463dff974693b" Jun 16 19:43:47 richdacvolumio go-librespot[23977]: time="2025-06-16T19:43:47+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 19:43:47 richdacvolumio go-librespot[23977]: time="2025-06-16T19:43:47+01:00" level=debug msg="obtained new client token: AAAFGGASp9Hwq+QJRw0/LpYLq6mKdK0o+W/DprZv232j6vd1ubxur3Zzyul8+KCCutwuCXV7siB1XpOLBRR9wYNZ1bedK8F/x1iRhO1V0xipVWFDif60on8/o2FedoHu2Z09uZ1PDFX1rm1SKXpYHjypu0t74eTwEG51fq/c3FJmYOloIzuSyI3hDQFpN/UlmbC+izCXaAyHwDiPIvzkBklUSK6iBOSFAQSPI3uGfoZpc4Au209htf+QUzTs4A==" Jun 16 19:43:48 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:48 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:48 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:48 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:48 richdacvolumio volumio[1007]: info: Initializing connection to go-librespot Websocket Jun 16 19:43:48 richdacvolumio go-librespot[23977]: time="2025-06-16T19:43:48+01:00" level=debug msg="new websocket client" Jun 16 19:43:48 richdacvolumio volumio[1007]: info: Connection to go-librespot Websocket established Jun 16 19:43:48 richdacvolumio go-librespot[23977]: time="2025-06-16T19:43: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-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jun 16 19:43:48 richdacvolumio go-librespot[23977]: time="2025-06-16T19:43:48+01:00" level=debug msg="completed keyexchange" Jun 16 19:43:48 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:48 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:48 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:48 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:48 richdacvolumio go-librespot[23977]: time="2025-06-16T19:43:48+01:00" level=debug msg="completed challenge" Jun 16 19:43:48 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:48 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:48 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:48 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:48 richdacvolumio go-librespot[23977]: time="2025-06-16T19:43:48+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 19:43:48 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 19:43:48 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 19:43:48 richdacvolumio volumio[1007]: info: Connection to go-librespot Websocket closed Jun 16 19:43:49 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:49 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:49 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:49 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:49 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:49 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:49 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:49 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:49 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:49 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:49 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:49 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:50 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:50 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:50 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:50 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:50 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:50 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:50 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:50 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:50 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:50 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:50 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:50 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:51 richdacvolumio volumio[1007]: info: Getting Spotify volume Jun 16 19:43:51 richdacvolumio volumio[1007]: (node:1007) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 19:43:51 richdacvolumio volumio[1007]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jun 16 19:43:51 richdacvolumio volumio[1007]: (node:1007) 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: 3100) Jun 16 19:43:51 richdacvolumio volumio[1007]: 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 19:43:51 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:51 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:51 richdacvolumio volumio[1007]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 16 19:43:51 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:51 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:51 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:51 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:51 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:51 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:51 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:51 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:51 richdacvolumio volumio[1007]: info: Initializing connection to go-librespot Websocket Jun 16 19:43:51 richdacvolumio volumio[1007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 16 19:43:51 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:51 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:51 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:51 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:51 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 19:43:51 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 203. Jun 16 19:43:51 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jun 16 19:43:52 richdacvolumio systemd[1]: Started go-librespot Daemon. Jun 16 19:43:52 richdacvolumio go-librespot[24062]: Librespot-go daemon starting... Jun 16 19:43:52 richdacvolumio go-librespot[24062]: time="2025-06-16T19:43:52+01:00" level=info msg="generated new device id: 5bc4c39528df1ce052deb618d1173825942f12a7" Jun 16 19:43:52 richdacvolumio go-librespot[24062]: time="2025-06-16T19:43:52+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jun 16 19:43:52 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:52 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:52 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:52 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:52 richdacvolumio go-librespot[24062]: time="2025-06-16T19:43:52+01:00" level=debug msg="obtained new client token: AABKU0RHZz5YRy+8eCeAz6t6WxMlRiaXGc+DNevdUL0xQ3tbwbucW523aW082B/BnjuLAtdmtBOKVs3n7lrqlqpif18VCqwxSn64b/Lx9vMyM5n9gIN0SPyrRlkM36+sYOaScjFlaXVWReZxsRUnDlht6HUufTgT1iNSiGnW8qsl5ZZwUjJySwrYWy8+t/ighhjuvWgnn3nq/yKJBlwYb1vSHSwhwo81srJee2w5CUNPYQdimWUnL97mwxqYTA==" Jun 16 19:43:52 richdacvolumio go-librespot[24062]: time="2025-06-16T19:43:52+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 19:43:52 richdacvolumio go-librespot[24062]: time="2025-06-16T19:43:52+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 19:43:52 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 19:43:52 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 19:43:52 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:52 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:52 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:52 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:52 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:52 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:52 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:52 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:53 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:53 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:53 richdacvolumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 16 19:43:53 richdacvolumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 16 19:43:53 richdacvolumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 16 19:43:53 richdacvolumio volumio[1007]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 16 19:43:53 richdacvolumio volumio[1007]: TypeError: Cannot read property 'length' of undefined Jun 16 19:43:53 richdacvolumio volumio[1007]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Jun 16 19:43:53 richdacvolumio volumio[1007]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Jun 16 19:43:53 richdacvolumio volumio[1007]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Jun 16 19:43:53 richdacvolumio volumio[1007]: at Parser.emit (events.js:315:20) Jun 16 19:43:53 richdacvolumio volumio[1007]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Jun 16 19:43:53 richdacvolumio volumio[1007]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Jun 16 19:43:53 richdacvolumio volumio[1007]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Jun 16 19:43:53 richdacvolumio volumio[1007]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Jun 16 19:43:53 richdacvolumio volumio[1007]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Jun 16 19:43:53 richdacvolumio volumio[1007]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Jun 16 19:43:53 richdacvolumio volumio[1007]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Jun 16 19:43:53 richdacvolumio volumio[1007]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Jun 16 19:43:53 richdacvolumio volumio[1007]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Jun 16 19:43:53 richdacvolumio volumio[1007]: at IncomingMessage.emit (events.js:327:22) Jun 16 19:43:53 richdacvolumio volumio[1007]: at endReadableNT (internal/streams/readable.js:1327:12) Jun 16 19:43:53 richdacvolumio volumio[1007]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jun 16 19:43:53 richdacvolumio volumio[1007]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 16 19:43:53 richdacvolumio sudo[24104]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-16 19:42 Jun 16 19:43:53 richdacvolumio sudo[24104]: 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="4b122b2365bb8c09786cd63b50d1ea6db780eb4e" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="49f98390f2d84c6549f33dc85b694fbd99e4c720" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 04 Jun 2024 08:41:12 PM CEST" VOLUMIO_VERSION="3.703" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="8e78a6e3f56f1bcbbd1760812129a8e9"