-- Logs begin at Mon 2025-03-17 19:51:45 CET, end at Mon 2025-03-17 20:18:43 CET. -- Mar 17 20:17:02 jj-volumio volumio[1074]: info: Getting Spotify volume Mar 17 20:17:02 jj-volumio volumio[1074]: (node:1074) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 20:17:02 jj-volumio volumio[1074]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Mar 17 20:17:02 jj-volumio volumio[1074]: (node:1074) 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: 20) Mar 17 20:17:02 jj-volumio volumio[1074]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Mar 17 20:17:02 jj-volumio volumio[1074]: info: CoreCommandRouter::volumioGetState Mar 17 20:17:02 jj-volumio volumio[1074]: info: CorePlayQueue::getTrack 0 Mar 17 20:17:02 jj-volumio volumio[1074]: info: Initializing connection to go-librespot Websocket Mar 17 20:17:02 jj-volumio volumio[1074]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 20:17:02 jj-volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 20:17:02 jj-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 251. Mar 17 20:17:02 jj-volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 20:17:02 jj-volumio systemd[1]: Started go-librespot Daemon. Mar 17 20:17:02 jj-volumio go-librespot[8432]: go-librespot daemon starting... Mar 17 20:17:02 jj-volumio go-librespot[8432]: time="2025-03-17T20:17:02+01:00" level=info msg="running go-librespot 0.2.0" Mar 17 20:17:02 jj-volumio go-librespot[8432]: time="2025-03-17T20:17:02+01:00" level=debug msg="app state loaded" Mar 17 20:17:02 jj-volumio go-librespot[8432]: time="2025-03-17T20:17:02+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 17 20:17:02 jj-volumio go-librespot[8432]: time="2025-03-17T20:17:02+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 17 20:17:02 jj-volumio go-librespot[8432]: time="2025-03-17T20:17:02+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 17 20:17:02 jj-volumio go-librespot[8432]: time="2025-03-17T20:17:02+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 17 20:17:02 jj-volumio go-librespot[8432]: time="2025-03-17T20:17:02+01:00" level=info msg="zeroconf server listening on port 41463" Mar 17 20:17:02 jj-volumio go-librespot[8432]: time="2025-03-17T20:17:02+01:00" level=debug msg="obtained new client token: AABJtjRWvhrOSLDht/yTYMMp93CCJfbKtgApVX9lq/st8RfEhWQMTdpotje5l9gIgfMVJJViE0If6mUiotXNkLckkT1KXtcHEdK/yvj+tsNeL53Fag+/dzqWPr/owFfhR8KlQTHqgjI7AD/gaAzPuv9YmNVzUyuYY8LLD2uUVh3sUKZjsS0ItR9AtTMsRhQeUxZ0mJCATBhXx87rT2jIPqzGBnh35c8kX8Gd76lzIfVWIR855GqmkP3P" Mar 17 20:17:02 jj-volumio go-librespot[8432]: time="2025-03-17T20:17:02+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Mar 17 20:17:02 jj-volumio go-librespot[8432]: time="2025-03-17T20:17:02+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 17 20:17:02 jj-volumio go-librespot[8432]: time="2025-03-17T20:17:02+01:00" level=debug msg="completed keyexchange" Mar 17 20:17:02 jj-volumio go-librespot[8432]: time="2025-03-17T20:17:02+01:00" level=debug msg="completed challenge" Mar 17 20:17:02 jj-volumio go-librespot[8432]: time="2025-03-17T20:17:02+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 17 20:17:02 jj-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 20:17:02 jj-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 20:17:05 jj-volumio volumio[1074]: info: Initializing connection to go-librespot Websocket Mar 17 20:17:05 jj-volumio volumio[1074]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 20:17:06 jj-volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 20:17:06 jj-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 252. Mar 17 20:17:06 jj-volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 20:17:06 jj-volumio systemd[1]: Started go-librespot Daemon. Mar 17 20:17:06 jj-volumio go-librespot[8458]: go-librespot daemon starting... Mar 17 20:17:06 jj-volumio go-librespot[8458]: time="2025-03-17T20:17:06+01:00" level=info msg="running go-librespot 0.2.0" Mar 17 20:17:06 jj-volumio go-librespot[8458]: time="2025-03-17T20:17:06+01:00" level=debug msg="app state loaded" Mar 17 20:17:06 jj-volumio go-librespot[8458]: time="2025-03-17T20:17:06+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 17 20:17:06 jj-volumio go-librespot[8458]: time="2025-03-17T20:17:06+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 17 20:17:06 jj-volumio go-librespot[8458]: time="2025-03-17T20:17:06+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 17 20:17:06 jj-volumio go-librespot[8458]: time="2025-03-17T20:17:06+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 17 20:17:06 jj-volumio go-librespot[8458]: time="2025-03-17T20:17:06+01:00" level=info msg="zeroconf server listening on port 33367" Mar 17 20:17:06 jj-volumio go-librespot[8458]: time="2025-03-17T20:17:06+01:00" level=debug msg="obtained new client token: AABxYpNmdufLWFLXtP1eWVz4176SkMzHqwYRqbj5aSURWO6PRUzAJBO6IOUMVZb7g8aeSMgYUPXdspoYDLlbb7qGSb4uE0ceQ77wT16aEWMgE8tvlbZgDOnNPvsM3PP5UXJ8xTz4fHVpnc+5oMICLo1Sv5TjMapa/61SjDMqiDZdK7gVXbEo/mTchnqGwnvqORzocLa/WU7uN5wSP48ts7ItfiNI1d9lxxABdEMEvo78jmRfhtHcaLcI" Mar 17 20:17:06 jj-volumio go-librespot[8458]: time="2025-03-17T20:17:06+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 17 20:17:06 jj-volumio go-librespot[8458]: time="2025-03-17T20:17:06+01:00" level=debug msg="completed keyexchange" Mar 17 20:17:06 jj-volumio go-librespot[8458]: time="2025-03-17T20:17:06+01:00" level=debug msg="completed challenge" Mar 17 20:17:06 jj-volumio go-librespot[8458]: time="2025-03-17T20:17:06+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 17 20:17:06 jj-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 20:17:06 jj-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 20:17:08 jj-volumio volumio[1074]: info: Initializing connection to go-librespot Websocket Mar 17 20:17:08 jj-volumio volumio[1074]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 20:17:09 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 17 20:17:09 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 17 20:17:09 jj-volumio volumio[1074]: info: Discovery: Getting this device information Mar 17 20:17:09 jj-volumio volumio[1074]: info: CoreCommandRouter::volumioGetState Mar 17 20:17:09 jj-volumio volumio[1074]: info: CorePlayQueue::getTrack 0 Mar 17 20:17:09 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 17 20:17:09 jj-volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 20:17:09 jj-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 253. Mar 17 20:17:09 jj-volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 20:17:09 jj-volumio systemd[1]: Started go-librespot Daemon. Mar 17 20:17:09 jj-volumio go-librespot[8465]: go-librespot daemon starting... Mar 17 20:17:09 jj-volumio go-librespot[8465]: time="2025-03-17T20:17:09+01:00" level=info msg="running go-librespot 0.2.0" Mar 17 20:17:09 jj-volumio go-librespot[8465]: time="2025-03-17T20:17:09+01:00" level=debug msg="app state loaded" Mar 17 20:17:09 jj-volumio go-librespot[8465]: time="2025-03-17T20:17:09+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 17 20:17:09 jj-volumio go-librespot[8465]: time="2025-03-17T20:17:09+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 17 20:17:09 jj-volumio go-librespot[8465]: time="2025-03-17T20:17:09+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 17 20:17:09 jj-volumio go-librespot[8465]: time="2025-03-17T20:17:09+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 17 20:17:09 jj-volumio go-librespot[8465]: time="2025-03-17T20:17:09+01:00" level=info msg="zeroconf server listening on port 42291" Mar 17 20:17:09 jj-volumio go-librespot[8465]: time="2025-03-17T20:17:09+01:00" level=debug msg="obtained new client token: AADWAzzty4oCzZdCJcmWY7Z5DTgKHhxryacWRV28A802U83QJJ8DHJoMsEyAligkR74da+z+lX+sBpvgWF1J0Fh/B0/oQ7shHlSirn4QmrJDlxW5CmbkVzx+3wogONG9wA2rXhjlGCtue/awHKeHKSR3UnDbMAMg+7lNGWCWBhE7xgJ4w0Q7v6rCArsQtvsD1eISaYGFLOVE2mUntD5LIF0oNKpDeU3dCX334HpaWlpAse7aC6x0wwbp" Mar 17 20:17:09 jj-volumio go-librespot[8465]: time="2025-03-17T20:17:09+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 17 20:17:09 jj-volumio go-librespot[8465]: time="2025-03-17T20:17:09+01:00" level=debug msg="completed keyexchange" Mar 17 20:17:09 jj-volumio go-librespot[8465]: time="2025-03-17T20:17:09+01:00" level=debug msg="completed challenge" Mar 17 20:17:09 jj-volumio go-librespot[8465]: time="2025-03-17T20:17:09+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 17 20:17:09 jj-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 20:17:09 jj-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 20:17:11 jj-volumio volumio[1074]: info: Initializing connection to go-librespot Websocket Mar 17 20:17:11 jj-volumio volumio[1074]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 20:17:13 jj-volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 20:17:13 jj-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 254. Mar 17 20:17:13 jj-volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 20:17:13 jj-volumio systemd[1]: Started go-librespot Daemon. Mar 17 20:17:13 jj-volumio go-librespot[8473]: go-librespot daemon starting... Mar 17 20:17:13 jj-volumio go-librespot[8473]: time="2025-03-17T20:17:13+01:00" level=info msg="running go-librespot 0.2.0" Mar 17 20:17:13 jj-volumio go-librespot[8473]: time="2025-03-17T20:17:13+01:00" level=debug msg="app state loaded" Mar 17 20:17:13 jj-volumio go-librespot[8473]: time="2025-03-17T20:17:13+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 17 20:17:13 jj-volumio go-librespot[8473]: time="2025-03-17T20:17:13+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 17 20:17:13 jj-volumio go-librespot[8473]: time="2025-03-17T20:17:13+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 17 20:17:13 jj-volumio go-librespot[8473]: time="2025-03-17T20:17:13+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 17 20:17:13 jj-volumio go-librespot[8473]: time="2025-03-17T20:17:13+01:00" level=info msg="zeroconf server listening on port 36417" Mar 17 20:17:13 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 17 20:17:13 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 17 20:17:13 jj-volumio go-librespot[8473]: time="2025-03-17T20:17:13+01:00" level=debug msg="obtained new client token: AACZB+qIsLZwjgBDEuB3e7wQFtEvsXZPU5ij9cVJEmPw1HMqoyLh3AhkMWGmO+YLdYvTDxqM4A326rAEv/pqOU4EfRjhInItVtgNQFKYygkilruuTf/ch1Dbtxuu9qHm9uBsZR6HbbD5afV27fZLJghPaeGaFQ5klXJtHx+S+3ynuzA3HOuJt9J4ZE1TtZMicCz2RboaDZKuPLo2vs8nw7CE92UxwbfCbUNrlky+cZj1zRcP2CvE+Wgu" Mar 17 20:17:13 jj-volumio go-librespot[8473]: time="2025-03-17T20:17:13+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 17 20:17:13 jj-volumio go-librespot[8473]: time="2025-03-17T20:17:13+01:00" level=debug msg="completed keyexchange" Mar 17 20:17:13 jj-volumio go-librespot[8473]: time="2025-03-17T20:17:13+01:00" level=debug msg="completed challenge" Mar 17 20:17:13 jj-volumio go-librespot[8473]: time="2025-03-17T20:17:13+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 17 20:17:13 jj-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 20:17:13 jj-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 20:17:14 jj-volumio volumio[1074]: info: Initializing connection to go-librespot Websocket Mar 17 20:17:14 jj-volumio volumio[1074]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 20:17:16 jj-volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 20:17:16 jj-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 255. Mar 17 20:17:16 jj-volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 20:17:16 jj-volumio systemd[1]: Started go-librespot Daemon. Mar 17 20:17:16 jj-volumio go-librespot[8494]: go-librespot daemon starting... Mar 17 20:17:16 jj-volumio go-librespot[8494]: time="2025-03-17T20:17:16+01:00" level=info msg="running go-librespot 0.2.0" Mar 17 20:17:16 jj-volumio go-librespot[8494]: time="2025-03-17T20:17:16+01:00" level=debug msg="app state loaded" Mar 17 20:17:16 jj-volumio go-librespot[8494]: time="2025-03-17T20:17:16+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 17 20:17:16 jj-volumio go-librespot[8494]: time="2025-03-17T20:17:16+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 17 20:17:16 jj-volumio go-librespot[8494]: time="2025-03-17T20:17:16+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 17 20:17:16 jj-volumio go-librespot[8494]: time="2025-03-17T20:17:16+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 17 20:17:16 jj-volumio go-librespot[8494]: time="2025-03-17T20:17:16+01:00" level=info msg="zeroconf server listening on port 40531" Mar 17 20:17:16 jj-volumio go-librespot[8494]: time="2025-03-17T20:17:16+01:00" level=debug msg="obtained new client token: AAC51CsD9BBwFIwQnHAD+FhNH3epp2DOX9Ug0wQ+7WQehqsY01qoQ7xqjmZ83Gts/A1Mz4gRZ0o73jyi2EI/r6vZdZvpHStAUbcKYaupOzf9l8AjNJyPb/6BQUqo3LddebTnqZNsVO99ujwb+AJjE5MWh4LVw3b2VTQBZdAhMcbdveob2eRgZnUWKIaWeANn1l46AeK964C+JRkR3Ii4A649sOXssjHK/xTwKhPnAFG2wJeGaEtXL/Nk" Mar 17 20:17:16 jj-volumio go-librespot[8494]: time="2025-03-17T20:17:16+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 17 20:17:16 jj-volumio go-librespot[8494]: time="2025-03-17T20:17:16+01:00" level=debug msg="completed keyexchange" Mar 17 20:17:16 jj-volumio go-librespot[8494]: time="2025-03-17T20:17:16+01:00" level=debug msg="completed challenge" Mar 17 20:17:16 jj-volumio go-librespot[8494]: time="2025-03-17T20:17:16+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 17 20:17:16 jj-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 20:17:16 jj-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 20:17:17 jj-volumio volumio[1074]: info: Initializing connection to go-librespot Websocket Mar 17 20:17:17 jj-volumio volumio[1074]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 20:17:19 jj-volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 20:17:19 jj-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 256. Mar 17 20:17:19 jj-volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 20:17:19 jj-volumio systemd[1]: Started go-librespot Daemon. Mar 17 20:17:19 jj-volumio go-librespot[8501]: go-librespot daemon starting... Mar 17 20:17:19 jj-volumio go-librespot[8501]: time="2025-03-17T20:17:19+01:00" level=info msg="running go-librespot 0.2.0" Mar 17 20:17:19 jj-volumio go-librespot[8501]: time="2025-03-17T20:17:19+01:00" level=debug msg="app state loaded" Mar 17 20:17:19 jj-volumio go-librespot[8501]: time="2025-03-17T20:17:19+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 17 20:17:20 jj-volumio go-librespot[8501]: time="2025-03-17T20:17:20+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 17 20:17:20 jj-volumio go-librespot[8501]: time="2025-03-17T20:17:20+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 17 20:17:20 jj-volumio go-librespot[8501]: time="2025-03-17T20:17:20+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 17 20:17:20 jj-volumio go-librespot[8501]: time="2025-03-17T20:17:20+01:00" level=info msg="zeroconf server listening on port 43457" Mar 17 20:17:20 jj-volumio go-librespot[8501]: time="2025-03-17T20:17:20+01:00" level=debug msg="obtained new client token: AADYfXNhwN5Fke+/3HAVxuGE5GvmWiPh7bO76UWhgPCozA1OaNtRpp9zAU17/cirmiqWLcjgBVP3swc+U6aB7NDRNpbdNDEOvdrbkIj9a4fT+Yok5DNIZaPY7jTiM4w+dY9HAi/87oMVXciw4qKyE5JQyvQQ+BF8FpJiXMNcO71oci2cAXBJeIXqlnLO6W8OJ+P944Zolq+sVZdxXqm6wg0j7MFJqzX7EPVLEw3I/xLBRtKgLKDgnQ==" Mar 17 20:17:20 jj-volumio go-librespot[8501]: time="2025-03-17T20:17:20+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 17 20:17:20 jj-volumio go-librespot[8501]: time="2025-03-17T20:17:20+01:00" level=debug msg="completed keyexchange" Mar 17 20:17:20 jj-volumio go-librespot[8501]: time="2025-03-17T20:17:20+01:00" level=debug msg="completed challenge" Mar 17 20:17:20 jj-volumio go-librespot[8501]: time="2025-03-17T20:17:20+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 17 20:17:20 jj-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 20:17:20 jj-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 20:17:20 jj-volumio volumio[1074]: info: Initializing connection to go-librespot Websocket Mar 17 20:17:20 jj-volumio volumio[1074]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 20:17:23 jj-volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 20:17:23 jj-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 257. Mar 17 20:17:23 jj-volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 20:17:23 jj-volumio systemd[1]: Started go-librespot Daemon. Mar 17 20:17:23 jj-volumio go-librespot[8512]: go-librespot daemon starting... Mar 17 20:17:23 jj-volumio go-librespot[8512]: time="2025-03-17T20:17:23+01:00" level=info msg="running go-librespot 0.2.0" Mar 17 20:17:23 jj-volumio go-librespot[8512]: time="2025-03-17T20:17:23+01:00" level=debug msg="app state loaded" Mar 17 20:17:23 jj-volumio go-librespot[8512]: time="2025-03-17T20:17:23+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 17 20:17:23 jj-volumio go-librespot[8512]: time="2025-03-17T20:17:23+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 17 20:17:23 jj-volumio go-librespot[8512]: time="2025-03-17T20:17:23+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 17 20:17:23 jj-volumio go-librespot[8512]: time="2025-03-17T20:17:23+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 17 20:17:23 jj-volumio go-librespot[8512]: time="2025-03-17T20:17:23+01:00" level=info msg="zeroconf server listening on port 45437" Mar 17 20:17:23 jj-volumio go-librespot[8512]: time="2025-03-17T20:17:23+01:00" level=debug msg="obtained new client token: AADb9K/pNHvKEjY3E/3hp1ZB3yHwUaJt9qRuxpa1QWddNr+jsyLlnY7+/AuUoP8UzLKbxomgjzQHyKqGPv+aLupCM0ZSzUDFAK2vF+77Nk+g4ZCd1zz3N1R5zcyahcmodQxK36nVlJeP9c7uvIzvWeBvRB+X0mHMlUkogB4AgRHpkfSuW36j111O0dLrurh++TpxPUYij1gKs+lpONJopHf4uNbfnXN90H8nTTnJgZaNCKmxX/ngF719" Mar 17 20:17:23 jj-volumio go-librespot[8512]: time="2025-03-17T20:17:23+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 17 20:17:23 jj-volumio go-librespot[8512]: time="2025-03-17T20:17:23+01:00" level=debug msg="completed keyexchange" Mar 17 20:17:23 jj-volumio go-librespot[8512]: time="2025-03-17T20:17:23+01:00" level=debug msg="completed challenge" Mar 17 20:17:23 jj-volumio volumio[1074]: info: Initializing connection to go-librespot Websocket Mar 17 20:17:23 jj-volumio go-librespot[8512]: time="2025-03-17T20:17:23+01:00" level=debug msg="new websocket client" Mar 17 20:17:23 jj-volumio volumio[1074]: info: Connection to go-librespot Websocket established Mar 17 20:17:23 jj-volumio go-librespot[8512]: time="2025-03-17T20:17:23+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 17 20:17:23 jj-volumio volumio[1074]: info: Connection to go-librespot Websocket closed Mar 17 20:17:23 jj-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 20:17:23 jj-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 20:17:23 jj-volumio volumio[1074]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 17 20:17:23 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Mar 17 20:17:24 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Mar 17 20:17:24 jj-volumio sudo[8522]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Mar 17 20:17:24 jj-volumio sudo[8522]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 17 20:17:24 jj-volumio sudo[8522]: pam_unix(sudo:session): session closed for user root Mar 17 20:17:24 jj-volumio sudo[8529]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Mar 17 20:17:24 jj-volumio sudo[8529]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 17 20:17:24 jj-volumio sudo[8529]: pam_unix(sudo:session): session closed for user root Mar 17 20:17:24 jj-volumio sudo[8537]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Mar 17 20:17:24 jj-volumio sudo[8537]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 17 20:17:24 jj-volumio sudo[8537]: pam_unix(sudo:session): session closed for user root Mar 17 20:17:24 jj-volumio sudo[8542]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Mar 17 20:17:24 jj-volumio sudo[8542]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 17 20:17:24 jj-volumio sudo[8542]: pam_unix(sudo:session): session closed for user root Mar 17 20:17:24 jj-volumio sudo[8548]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 17 20:17:24 jj-volumio sudo[8548]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 17 20:17:24 jj-volumio sudo[8548]: pam_unix(sudo:session): session closed for user root Mar 17 20:17:24 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Mar 17 20:17:24 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Mar 17 20:17:24 jj-volumio sudo[8551]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 17 20:17:24 jj-volumio sudo[8551]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 17 20:17:24 jj-volumio sudo[8551]: pam_unix(sudo:session): session closed for user root Mar 17 20:17:24 jj-volumio sudo[8554]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 17 20:17:24 jj-volumio sudo[8554]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 17 20:17:24 jj-volumio sudo[8554]: pam_unix(sudo:session): session closed for user root Mar 17 20:17:24 jj-volumio volumio[1074]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Mar 17 20:17:24 jj-volumio volumio[1074]: wlan0 Interface doesn't support scanning : Operation not supported Mar 17 20:17:24 jj-volumio volumio[1074]: info: Cannot use regular scanning, forcing with ap-force Mar 17 20:17:24 jj-volumio sudo[8557]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Mar 17 20:17:24 jj-volumio sudo[8557]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 17 20:17:24 jj-volumio sudo[8557]: pam_unix(sudo:session): session closed for user root Mar 17 20:17:24 jj-volumio volumio[1074]: command failed: Operation not supported (-95) Mar 17 20:17:24 jj-volumio volumio[1074]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Mar 17 20:17:24 jj-volumio volumio[1074]: command failed: Operation not supported (-95) Mar 17 20:17:26 jj-volumio volumio[1074]: info: Getting Spotify volume Mar 17 20:17:26 jj-volumio volumio[1074]: (node:1074) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 20:17:26 jj-volumio volumio[1074]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Mar 17 20:17:26 jj-volumio volumio[1074]: (node:1074) 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: 21) Mar 17 20:17:26 jj-volumio volumio[1074]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Mar 17 20:17:26 jj-volumio volumio[1074]: info: CoreCommandRouter::volumioGetState Mar 17 20:17:26 jj-volumio volumio[1074]: info: CorePlayQueue::getTrack 0 Mar 17 20:17:26 jj-volumio volumio[1074]: info: Initializing connection to go-librespot Websocket Mar 17 20:17:26 jj-volumio volumio[1074]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 20:17:26 jj-volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 20:17:26 jj-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 258. Mar 17 20:17:26 jj-volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 20:17:26 jj-volumio systemd[1]: Started go-librespot Daemon. Mar 17 20:17:26 jj-volumio go-librespot[8573]: go-librespot daemon starting... Mar 17 20:17:26 jj-volumio go-librespot[8573]: time="2025-03-17T20:17:26+01:00" level=info msg="running go-librespot 0.2.0" Mar 17 20:17:26 jj-volumio go-librespot[8573]: time="2025-03-17T20:17:26+01:00" level=debug msg="app state loaded" Mar 17 20:17:26 jj-volumio go-librespot[8573]: time="2025-03-17T20:17:26+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 17 20:17:27 jj-volumio go-librespot[8573]: time="2025-03-17T20:17:27+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 17 20:17:27 jj-volumio go-librespot[8573]: time="2025-03-17T20:17:27+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 17 20:17:27 jj-volumio go-librespot[8573]: time="2025-03-17T20:17:27+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 17 20:17:27 jj-volumio go-librespot[8573]: time="2025-03-17T20:17:27+01:00" level=info msg="zeroconf server listening on port 33855" Mar 17 20:17:27 jj-volumio go-librespot[8573]: time="2025-03-17T20:17:27+01:00" level=debug msg="obtained new client token: AACD+YFP1KV6BEBQZUtOdaP5iIGmmpaUuFvugMO0SxbSyhlB6XcHqdxQwWCyoTmaX7AvXSINYRUy2i7vfFXK/dEGWGcvAtkhjB6QNuKInmm4EYVnrH5CjvYTQ+yn8hNVy0EMUG7ZyJ7jpeOEN4ggU4QXmn6KkYrVAlozKlQqU4wB0eLLtGj1cPdOqgYE56KHzWmbERWqje39t585NNMGPMD7DrB1/tof8b9YpOalENrPUY1U92Rg8Q==" Mar 17 20:17:27 jj-volumio go-librespot[8573]: time="2025-03-17T20:17:27+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 17 20:17:27 jj-volumio go-librespot[8573]: time="2025-03-17T20:17:27+01:00" level=debug msg="completed keyexchange" Mar 17 20:17:27 jj-volumio go-librespot[8573]: time="2025-03-17T20:17:27+01:00" level=debug msg="completed challenge" Mar 17 20:17:27 jj-volumio go-librespot[8573]: time="2025-03-17T20:17:27+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 17 20:17:27 jj-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 20:17:27 jj-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 20:17:29 jj-volumio volumio[1074]: info: Initializing connection to go-librespot Websocket Mar 17 20:17:29 jj-volumio volumio[1074]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 20:17:30 jj-volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 20:17:30 jj-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 259. Mar 17 20:17:30 jj-volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 20:17:30 jj-volumio systemd[1]: Started go-librespot Daemon. Mar 17 20:17:30 jj-volumio go-librespot[8580]: go-librespot daemon starting... Mar 17 20:17:30 jj-volumio go-librespot[8580]: time="2025-03-17T20:17:30+01:00" level=info msg="running go-librespot 0.2.0" Mar 17 20:17:30 jj-volumio go-librespot[8580]: time="2025-03-17T20:17:30+01:00" level=debug msg="app state loaded" Mar 17 20:17:30 jj-volumio go-librespot[8580]: time="2025-03-17T20:17:30+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 17 20:17:30 jj-volumio go-librespot[8580]: time="2025-03-17T20:17:30+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 17 20:17:30 jj-volumio go-librespot[8580]: time="2025-03-17T20:17:30+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 17 20:17:30 jj-volumio go-librespot[8580]: time="2025-03-17T20:17:30+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 17 20:17:30 jj-volumio go-librespot[8580]: time="2025-03-17T20:17:30+01:00" level=info msg="zeroconf server listening on port 39947" Mar 17 20:17:30 jj-volumio go-librespot[8580]: time="2025-03-17T20:17:30+01:00" level=debug msg="obtained new client token: AACuHhkJvYzIcsPxn814ITVKQ03FSXHXHz2Ekvf2mBDI6FqpnncrQXS5yzdcoRj2zc+ALOkRafKGIDjRDPLgB94BxsPmWt6kFgGdBKoXqF1qC+sDyiDVxRPRaqCcmz2U9Yl2vAURNA2ljvQehnyFiUqPgNnvObKFdBPZCFPJZbG/YktJPeq0lWLAR0aDW6+4v8ujmae69/PErjftMlhBf5m+9PQIJUdYdQM9Jy/TOU/k6lEHp3PtSaqC" Mar 17 20:17:30 jj-volumio go-librespot[8580]: time="2025-03-17T20:17:30+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 17 20:17:30 jj-volumio go-librespot[8580]: time="2025-03-17T20:17:30+01:00" level=debug msg="completed keyexchange" Mar 17 20:17:30 jj-volumio go-librespot[8580]: time="2025-03-17T20:17:30+01:00" level=debug msg="completed challenge" Mar 17 20:17:30 jj-volumio go-librespot[8580]: time="2025-03-17T20:17:30+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 17 20:17:30 jj-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 20:17:30 jj-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 20:17:31 jj-volumio volumio[1074]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 17 20:17:31 jj-volumio volumio[1074]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 17 20:17:31 jj-volumio volumio[1074]: info: Retrieving Cloud Streaming UI Mar 17 20:17:31 jj-volumio volumio[1074]: info: Getting Tidal Cloud Configuration Mar 17 20:17:31 jj-volumio volumio[1074]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 17 20:17:31 jj-volumio volumio[1074]: info: Getting Qobuz Cloud Configuration Mar 17 20:17:31 jj-volumio volumio[1074]: info: Asking plugin for UI Config Mar 17 20:17:31 jj-volumio volumio[1074]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 17 20:17:31 jj-volumio volumio[1074]: info: Getting Spotify Cloud Configuration Mar 17 20:17:31 jj-volumio volumio[1074]: info: Asking plugin for UI Config Mar 17 20:17:31 jj-volumio volumio[1074]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 17 20:17:31 jj-volumio volumio[1074]: info: Saving Spotify Acccount Mar 17 20:17:31 jj-volumio volumio[1074]: info: Got it Mar 17 20:17:31 jj-volumio volumio[1074]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Mar 17 20:17:31 jj-volumio volumio[1074]: info: Got it Mar 17 20:17:31 jj-volumio volumio[1074]: info: Got Tidal Cloud Configuration Mar 17 20:17:31 jj-volumio volumio[1074]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 17 20:17:31 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Mar 17 20:17:31 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Mar 17 20:17:31 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Mar 17 20:17:31 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Mar 17 20:17:31 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 17 20:17:31 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 17 20:17:31 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 17 20:17:31 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 17 20:17:31 jj-volumio volumio[1074]: info: CoreCommandRouter::volumioGetBrowseSources Mar 17 20:17:31 jj-volumio volumio[1074]: info: CoreCommandRouter::volumioGetBrowseSources Mar 17 20:17:31 jj-volumio volumio[1074]: info: CoreCommandRouter::volumioGetBrowseSources Mar 17 20:17:31 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 17 20:17:31 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Mar 17 20:17:32 jj-volumio volumio[1074]: info: Initializing connection to go-librespot Websocket Mar 17 20:17:32 jj-volumio volumio[1074]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 20:17:33 jj-volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 20:17:33 jj-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 260. Mar 17 20:17:33 jj-volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 20:17:33 jj-volumio systemd[1]: Started go-librespot Daemon. Mar 17 20:17:33 jj-volumio go-librespot[8587]: go-librespot daemon starting... Mar 17 20:17:33 jj-volumio go-librespot[8587]: time="2025-03-17T20:17:33+01:00" level=info msg="running go-librespot 0.2.0" Mar 17 20:17:33 jj-volumio go-librespot[8587]: time="2025-03-17T20:17:33+01:00" level=debug msg="app state loaded" Mar 17 20:17:33 jj-volumio go-librespot[8587]: time="2025-03-17T20:17:33+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 17 20:17:33 jj-volumio go-librespot[8587]: time="2025-03-17T20:17:33+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 17 20:17:33 jj-volumio go-librespot[8587]: time="2025-03-17T20:17:33+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 17 20:17:33 jj-volumio go-librespot[8587]: time="2025-03-17T20:17:33+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 17 20:17:33 jj-volumio go-librespot[8587]: time="2025-03-17T20:17:33+01:00" level=info msg="zeroconf server listening on port 34607" Mar 17 20:17:33 jj-volumio go-librespot[8587]: time="2025-03-17T20:17:33+01:00" level=debug msg="obtained new client token: AABzBwgPNhAQoBz7wGi/gQ8OC0zr7d0SjI5tpgZazBxQJokDaHON/IONq4MHD8gn456L7XW5Nu5SHfK6GkWKt+CoNG4rzxLgdbTC/t0fdOY56YxHKu6UkPYwdK7yLE/t9rvmOvPJAma96NkejglxTsiyV7ZFA6TRkXlJwGHj+Ty4/8Gq7TWpZTRY359JPSkQw7xdccL+SV6fZlLVsCKJaYID1vwfaWUwOZ/SSdWSb8dSvTDg1UVbevOV" Mar 17 20:17:33 jj-volumio go-librespot[8587]: time="2025-03-17T20:17:33+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 17 20:17:33 jj-volumio go-librespot[8587]: time="2025-03-17T20:17:33+01:00" level=debug msg="completed keyexchange" Mar 17 20:17:33 jj-volumio go-librespot[8587]: time="2025-03-17T20:17:33+01:00" level=debug msg="completed challenge" Mar 17 20:17:33 jj-volumio go-librespot[8587]: time="2025-03-17T20:17:33+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 17 20:17:33 jj-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 20:17:33 jj-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 20:17:35 jj-volumio volumio[1074]: info: Initializing connection to go-librespot Websocket Mar 17 20:17:35 jj-volumio volumio[1074]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 20:17:35 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 17 20:17:36 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Mar 17 20:17:36 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Mar 17 20:17:37 jj-volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 20:17:37 jj-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 261. Mar 17 20:17:37 jj-volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 20:17:37 jj-volumio systemd[1]: Started go-librespot Daemon. Mar 17 20:17:37 jj-volumio go-librespot[8612]: go-librespot daemon starting... Mar 17 20:17:37 jj-volumio go-librespot[8612]: time="2025-03-17T20:17:37+01:00" level=info msg="running go-librespot 0.2.0" Mar 17 20:17:37 jj-volumio go-librespot[8612]: time="2025-03-17T20:17:37+01:00" level=debug msg="app state loaded" Mar 17 20:17:37 jj-volumio go-librespot[8612]: time="2025-03-17T20:17:37+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 17 20:17:37 jj-volumio go-librespot[8612]: time="2025-03-17T20:17:37+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 17 20:17:37 jj-volumio go-librespot[8612]: time="2025-03-17T20:17:37+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 17 20:17:37 jj-volumio go-librespot[8612]: time="2025-03-17T20:17:37+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 17 20:17:37 jj-volumio go-librespot[8612]: time="2025-03-17T20:17:37+01:00" level=info msg="zeroconf server listening on port 39609" Mar 17 20:17:37 jj-volumio go-librespot[8612]: time="2025-03-17T20:17:37+01:00" level=debug msg="obtained new client token: AABkSr90yZ9qtd3MKfnDClWTl2x0KZJtX7+mn8+YJbcXSpdxAbm7E1D+k4+6lP6h+AMaJly2p4sVFITAPbVVk8BnW39fwhejgBsI/r0bDq2HhjsSh72UGhnLlZpYwK/tvq2OsBkF+rJyqPwHkk6cKL9IHRtO9OfaZjFBzB4+og1KpDt763pK1SVxdaFSJsNXEYKDClx0hyE4xR8r3uETBRsyOpOFJ1a4otjNR7L1136/O2YdNM5NXsZX" Mar 17 20:17:37 jj-volumio go-librespot[8612]: time="2025-03-17T20:17:37+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 17 20:17:37 jj-volumio go-librespot[8612]: time="2025-03-17T20:17:37+01:00" level=debug msg="completed keyexchange" Mar 17 20:17:37 jj-volumio go-librespot[8612]: time="2025-03-17T20:17:37+01:00" level=debug msg="completed challenge" Mar 17 20:17:37 jj-volumio go-librespot[8612]: time="2025-03-17T20:17:37+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 17 20:17:37 jj-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 20:17:37 jj-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 20:17:38 jj-volumio volumio[1074]: info: Initializing connection to go-librespot Websocket Mar 17 20:17:38 jj-volumio volumio[1074]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 20:17:39 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 17 20:17:39 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 17 20:17:39 jj-volumio volumio[1074]: info: Discovery: Getting this device information Mar 17 20:17:39 jj-volumio volumio[1074]: info: CoreCommandRouter::volumioGetState Mar 17 20:17:39 jj-volumio volumio[1074]: info: CorePlayQueue::getTrack 0 Mar 17 20:17:39 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 17 20:17:39 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 17 20:17:40 jj-volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 20:17:40 jj-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 262. Mar 17 20:17:40 jj-volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 20:17:40 jj-volumio systemd[1]: Started go-librespot Daemon. Mar 17 20:17:40 jj-volumio go-librespot[8623]: go-librespot daemon starting... Mar 17 20:17:40 jj-volumio go-librespot[8623]: time="2025-03-17T20:17:40+01:00" level=info msg="running go-librespot 0.2.0" Mar 17 20:17:40 jj-volumio go-librespot[8623]: time="2025-03-17T20:17:40+01:00" level=debug msg="app state loaded" Mar 17 20:17:40 jj-volumio go-librespot[8623]: time="2025-03-17T20:17:40+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 17 20:17:40 jj-volumio go-librespot[8623]: time="2025-03-17T20:17:40+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 17 20:17:40 jj-volumio go-librespot[8623]: time="2025-03-17T20:17:40+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 17 20:17:40 jj-volumio go-librespot[8623]: time="2025-03-17T20:17:40+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 17 20:17:40 jj-volumio go-librespot[8623]: time="2025-03-17T20:17:40+01:00" level=info msg="zeroconf server listening on port 36693" Mar 17 20:17:40 jj-volumio go-librespot[8623]: time="2025-03-17T20:17:40+01:00" level=debug msg="obtained new client token: AAA6Cxf3BfoKYxnF1/EfRUy+BEjihYbbbjhW/w8pHigWL6ON33+YEZecNlm0YJUNCLsrYAWkbtiRul5Fh9mnfzF5rBQfO2sHMCVaIhwj8xDmFVl6nGuv7mwtvp9YJ10kLwf4POYI9l64gCPft5pJsD8OABDr9GCLt7hclmg4PbE1HoPGYs2pkcehdWuHGq1CF2rnBahv+6ujcxV470Ij4Sk2APxWIm1Sk8bkjZ+cfn2XBPAKd4CtrLzI" Mar 17 20:17:40 jj-volumio go-librespot[8623]: time="2025-03-17T20:17:40+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 17 20:17:40 jj-volumio go-librespot[8623]: time="2025-03-17T20:17:40+01:00" level=debug msg="completed keyexchange" Mar 17 20:17:40 jj-volumio go-librespot[8623]: time="2025-03-17T20:17:40+01:00" level=debug msg="completed challenge" Mar 17 20:17:40 jj-volumio go-librespot[8623]: time="2025-03-17T20:17:40+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 17 20:17:40 jj-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 20:17:40 jj-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 20:17:41 jj-volumio volumio[1074]: info: Initializing connection to go-librespot Websocket Mar 17 20:17:41 jj-volumio volumio[1074]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 20:17:43 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 17 20:17:43 jj-volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 20:17:43 jj-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 263. Mar 17 20:17:43 jj-volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 20:17:43 jj-volumio systemd[1]: Started go-librespot Daemon. Mar 17 20:17:43 jj-volumio go-librespot[8633]: go-librespot daemon starting... Mar 17 20:17:43 jj-volumio go-librespot[8633]: time="2025-03-17T20:17:43+01:00" level=info msg="running go-librespot 0.2.0" Mar 17 20:17:43 jj-volumio go-librespot[8633]: time="2025-03-17T20:17:43+01:00" level=debug msg="app state loaded" Mar 17 20:17:43 jj-volumio go-librespot[8633]: time="2025-03-17T20:17:43+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 17 20:17:44 jj-volumio go-librespot[8633]: time="2025-03-17T20:17:44+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 17 20:17:44 jj-volumio go-librespot[8633]: time="2025-03-17T20:17:44+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 17 20:17:44 jj-volumio go-librespot[8633]: time="2025-03-17T20:17:44+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 17 20:17:44 jj-volumio go-librespot[8633]: time="2025-03-17T20:17:44+01:00" level=info msg="zeroconf server listening on port 35089" Mar 17 20:17:44 jj-volumio go-librespot[8633]: time="2025-03-17T20:17:44+01:00" level=debug msg="obtained new client token: AABGnjbdlUAUoBrKtah2bnRqWkWup68uO3OPFqbHUUS4evQ/GWL/vZutJST8/GSqRj0s98cDWo649riU0zQ6fPwZ/gi42PBe4sSVCpjEWTXGWyz8SS/BhvMKYvrTfQ2mFjKqMtFdT8h9no5Vjr7DEh1kZ/4Qv0FEUu1j8PLqtQpYMTwr74ogWVkPp2fGfyD5RqA/9r6ViXJqIEWLz2ISsL2ZpIRXHA3wF/FWJ1pVaceme+zzpVszPQ==" Mar 17 20:17:44 jj-volumio go-librespot[8633]: time="2025-03-17T20:17:44+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 17 20:17:44 jj-volumio go-librespot[8633]: time="2025-03-17T20:17:44+01:00" level=debug msg="completed keyexchange" Mar 17 20:17:44 jj-volumio go-librespot[8633]: time="2025-03-17T20:17:44+01:00" level=debug msg="completed challenge" Mar 17 20:17:44 jj-volumio go-librespot[8633]: time="2025-03-17T20:17:44+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 17 20:17:44 jj-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 20:17:44 jj-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 20:17:44 jj-volumio volumio[1074]: info: Initializing connection to go-librespot Websocket Mar 17 20:17:44 jj-volumio volumio[1074]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 20:17:47 jj-volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 20:17:47 jj-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 264. Mar 17 20:17:47 jj-volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 20:17:47 jj-volumio systemd[1]: Started go-librespot Daemon. Mar 17 20:17:47 jj-volumio go-librespot[8654]: go-librespot daemon starting... Mar 17 20:17:47 jj-volumio go-librespot[8654]: time="2025-03-17T20:17:47+01:00" level=info msg="running go-librespot 0.2.0" Mar 17 20:17:47 jj-volumio go-librespot[8654]: time="2025-03-17T20:17:47+01:00" level=debug msg="app state loaded" Mar 17 20:17:47 jj-volumio go-librespot[8654]: time="2025-03-17T20:17:47+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 17 20:17:47 jj-volumio go-librespot[8654]: time="2025-03-17T20:17:47+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 17 20:17:47 jj-volumio go-librespot[8654]: time="2025-03-17T20:17:47+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 17 20:17:47 jj-volumio go-librespot[8654]: time="2025-03-17T20:17:47+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 17 20:17:47 jj-volumio go-librespot[8654]: time="2025-03-17T20:17:47+01:00" level=info msg="zeroconf server listening on port 46249" Mar 17 20:17:47 jj-volumio go-librespot[8654]: time="2025-03-17T20:17:47+01:00" level=debug msg="obtained new client token: AAB/7dLhFBGwT+J40zi3d9dCBcXKR6i0JY70vJceuNGdJHmqiM4AMpEVwhv4Io5VnATo5gT2/OxBc74lkc2k+J2rLPkcotbWLsvNhbj+d0z6sJwc8dRgEC0Mkv3PxXzSiEvxWbokkqKOnrpIm0EbLUV4JxN9UOke6T1gmhCE360Vd/GKiojVBC4zH7J3HDYRgRR10fhd1+KNJcwtYcmIonQpG5zhIZgaYeV+DAdwccrPnSChim3zU2Jr" Mar 17 20:17:47 jj-volumio go-librespot[8654]: time="2025-03-17T20:17:47+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Mar 17 20:17:47 jj-volumio volumio[1074]: info: Initializing connection to go-librespot Websocket Mar 17 20:17:47 jj-volumio go-librespot[8654]: time="2025-03-17T20:17:47+01:00" level=debug msg="new websocket client" Mar 17 20:17:47 jj-volumio volumio[1074]: info: Connection to go-librespot Websocket established Mar 17 20:17:47 jj-volumio go-librespot[8654]: time="2025-03-17T20:17:47+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 17 20:17:47 jj-volumio go-librespot[8654]: time="2025-03-17T20:17:47+01:00" level=debug msg="completed keyexchange" Mar 17 20:17:47 jj-volumio go-librespot[8654]: time="2025-03-17T20:17:47+01:00" level=debug msg="completed challenge" Mar 17 20:17:47 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 17 20:17:47 jj-volumio go-librespot[8654]: time="2025-03-17T20:17:47+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 17 20:17:47 jj-volumio volumio[1074]: info: Connection to go-librespot Websocket closed Mar 17 20:17:47 jj-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 20:17:47 jj-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 20:17:48 jj-volumio volumiologrotate[761]: ls: cannot access '/var/log/samba/log.wb-JJ': No such file or directory Mar 17 20:17:48 jj-volumio volumiologrotate[761]: ls: cannot access 'VOLUMIO': No such file or directory Mar 17 20:17:50 jj-volumio volumio[1074]: info: Getting Spotify volume Mar 17 20:17:50 jj-volumio volumio[1074]: (node:1074) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 20:17:50 jj-volumio volumio[1074]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Mar 17 20:17:50 jj-volumio volumio[1074]: (node:1074) 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: 22) Mar 17 20:17:50 jj-volumio volumio[1074]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Mar 17 20:17:50 jj-volumio volumio[1074]: info: CoreCommandRouter::volumioGetState Mar 17 20:17:50 jj-volumio volumio[1074]: info: CorePlayQueue::getTrack 0 Mar 17 20:17:50 jj-volumio volumio[1074]: info: Initializing connection to go-librespot Websocket Mar 17 20:17:50 jj-volumio volumio[1074]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 20:17:50 jj-volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 20:17:50 jj-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 265. Mar 17 20:17:50 jj-volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 20:17:50 jj-volumio systemd[1]: Started go-librespot Daemon. Mar 17 20:17:50 jj-volumio go-librespot[8709]: go-librespot daemon starting... Mar 17 20:17:50 jj-volumio go-librespot[8709]: time="2025-03-17T20:17:50+01:00" level=info msg="running go-librespot 0.2.0" Mar 17 20:17:50 jj-volumio go-librespot[8709]: time="2025-03-17T20:17:50+01:00" level=debug msg="app state loaded" Mar 17 20:17:50 jj-volumio go-librespot[8709]: time="2025-03-17T20:17:50+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 17 20:17:51 jj-volumio go-librespot[8709]: time="2025-03-17T20:17:51+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 17 20:17:51 jj-volumio go-librespot[8709]: time="2025-03-17T20:17:51+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 17 20:17:51 jj-volumio go-librespot[8709]: time="2025-03-17T20:17:51+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 17 20:17:51 jj-volumio go-librespot[8709]: time="2025-03-17T20:17:51+01:00" level=info msg="zeroconf server listening on port 36861" Mar 17 20:17:51 jj-volumio go-librespot[8709]: time="2025-03-17T20:17:51+01:00" level=debug msg="obtained new client token: AABQCxyZ8QvFycexohg6E/vheMwrGIdCpsKn8LVgcMpWcqZtW0G9n8jm9Q2FvRl7L4hCNt26+/VyWWuY08RhajeFskWaxgO3hP3GA4ME2w14bL2elsgEPmUepSJyD1ruwssx+NKaag41CQyYJnw43bKhhEhrqGckVrnP7SxDnRfYwr9klJ89fznYSfa6aAR7H3+mzX60ik/JkNtiWFU3pfuExl++fVJp/kVr29E11yyDOPFgD1P3Dw==" Mar 17 20:17:51 jj-volumio go-librespot[8709]: time="2025-03-17T20:17:51+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 17 20:17:51 jj-volumio go-librespot[8709]: time="2025-03-17T20:17:51+01:00" level=debug msg="completed keyexchange" Mar 17 20:17:51 jj-volumio go-librespot[8709]: time="2025-03-17T20:17:51+01:00" level=debug msg="completed challenge" Mar 17 20:17:51 jj-volumio go-librespot[8709]: time="2025-03-17T20:17:51+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 17 20:17:51 jj-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 20:17:51 jj-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 20:17:51 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 17 20:17:53 jj-volumio volumio[1074]: info: Initializing connection to go-librespot Websocket Mar 17 20:17:53 jj-volumio volumio[1074]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 20:17:54 jj-volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 20:17:54 jj-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 266. Mar 17 20:17:54 jj-volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 20:17:54 jj-volumio systemd[1]: Started go-librespot Daemon. Mar 17 20:17:54 jj-volumio go-librespot[8716]: go-librespot daemon starting... Mar 17 20:17:54 jj-volumio go-librespot[8716]: time="2025-03-17T20:17:54+01:00" level=info msg="running go-librespot 0.2.0" Mar 17 20:17:54 jj-volumio go-librespot[8716]: time="2025-03-17T20:17:54+01:00" level=debug msg="app state loaded" Mar 17 20:17:54 jj-volumio go-librespot[8716]: time="2025-03-17T20:17:54+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 17 20:17:54 jj-volumio go-librespot[8716]: time="2025-03-17T20:17:54+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 17 20:17:54 jj-volumio go-librespot[8716]: time="2025-03-17T20:17:54+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 17 20:17:54 jj-volumio go-librespot[8716]: time="2025-03-17T20:17:54+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 17 20:17:54 jj-volumio go-librespot[8716]: time="2025-03-17T20:17:54+01:00" level=info msg="zeroconf server listening on port 39839" Mar 17 20:17:54 jj-volumio go-librespot[8716]: time="2025-03-17T20:17:54+01:00" level=debug msg="obtained new client token: AABu+LCi2R4Re+yvrUXFxMZkFgWMZVPdYmrG5/3p474a8MXjcf9VUu3IQ+6wFvApuoxSuqxG/COz5c24YGd3///0D4ykTSm/OxS+2z8JbvQe6ahy55dDpU5YBtLpKMoHxgKxvDELUXJ1n7Cum7XSkfRxxBSjo2d+7/hC7WLcTUqJy/SkFcN5YoWr/or3emi+UlgRDCzzBbNnaDLb3he4YiEskFx+xcygFMJhlwb57vgRvhnL+r4dk5tY" Mar 17 20:17:54 jj-volumio go-librespot[8716]: time="2025-03-17T20:17:54+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 17 20:17:54 jj-volumio go-librespot[8716]: time="2025-03-17T20:17:54+01:00" level=debug msg="completed keyexchange" Mar 17 20:17:54 jj-volumio go-librespot[8716]: time="2025-03-17T20:17:54+01:00" level=debug msg="completed challenge" Mar 17 20:17:54 jj-volumio go-librespot[8716]: time="2025-03-17T20:17:54+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 17 20:17:54 jj-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 20:17:54 jj-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 20:17:55 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 17 20:17:56 jj-volumio volumio[1074]: info: Initializing connection to go-librespot Websocket Mar 17 20:17:56 jj-volumio volumio[1074]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 20:17:57 jj-volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 20:17:57 jj-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 267. Mar 17 20:17:57 jj-volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 20:17:57 jj-volumio systemd[1]: Started go-librespot Daemon. Mar 17 20:17:57 jj-volumio go-librespot[8737]: go-librespot daemon starting... Mar 17 20:17:57 jj-volumio go-librespot[8737]: time="2025-03-17T20:17:57+01:00" level=info msg="running go-librespot 0.2.0" Mar 17 20:17:57 jj-volumio go-librespot[8737]: time="2025-03-17T20:17:57+01:00" level=debug msg="app state loaded" Mar 17 20:17:57 jj-volumio go-librespot[8737]: time="2025-03-17T20:17:57+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 17 20:17:58 jj-volumio go-librespot[8737]: time="2025-03-17T20:17:58+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 17 20:17:58 jj-volumio go-librespot[8737]: time="2025-03-17T20:17:58+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 17 20:17:58 jj-volumio go-librespot[8737]: time="2025-03-17T20:17:58+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 17 20:17:58 jj-volumio go-librespot[8737]: time="2025-03-17T20:17:58+01:00" level=info msg="zeroconf server listening on port 45749" Mar 17 20:17:58 jj-volumio go-librespot[8737]: time="2025-03-17T20:17:58+01:00" level=debug msg="obtained new client token: AACJvMe+Qfw3B0Ac5x1pqj/OAdc6s2Zu5By4bRwzIt+BKmq4FFwuAmRGFrHxfRAkvvMljwBJT5fdsLudl1Uxbj/iNSnYE1ccoAAmpChkvBwfH7BUEg+DWnrrLcAi4MjcPOUnQO9coIP8ekCQVtPmPYEIX0gf0+0dIQ8afsI4KTK+U7WOtJE+Yz6nhVnbtnQItSZ/T2pO3dne1/O2AqzqYWMa6FnsaD8vz9eoQOqLg+0XzobSlyS8WA==" Mar 17 20:17:58 jj-volumio go-librespot[8737]: time="2025-03-17T20:17:58+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 17 20:17:58 jj-volumio go-librespot[8737]: time="2025-03-17T20:17:58+01:00" level=debug msg="completed keyexchange" Mar 17 20:17:58 jj-volumio go-librespot[8737]: time="2025-03-17T20:17:58+01:00" level=debug msg="completed challenge" Mar 17 20:17:58 jj-volumio go-librespot[8737]: time="2025-03-17T20:17:58+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 17 20:17:58 jj-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 20:17:58 jj-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 20:17:59 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 17 20:17:59 jj-volumio volumio[1074]: info: Initializing connection to go-librespot Websocket Mar 17 20:17:59 jj-volumio volumio[1074]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 20:18:01 jj-volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 20:18:01 jj-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 268. Mar 17 20:18:01 jj-volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 20:18:01 jj-volumio systemd[1]: Started go-librespot Daemon. Mar 17 20:18:01 jj-volumio go-librespot[8744]: go-librespot daemon starting... Mar 17 20:18:01 jj-volumio go-librespot[8744]: time="2025-03-17T20:18:01+01:00" level=info msg="running go-librespot 0.2.0" Mar 17 20:18:01 jj-volumio go-librespot[8744]: time="2025-03-17T20:18:01+01:00" level=debug msg="app state loaded" Mar 17 20:18:01 jj-volumio go-librespot[8744]: time="2025-03-17T20:18:01+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 17 20:18:01 jj-volumio go-librespot[8744]: time="2025-03-17T20:18:01+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 17 20:18:01 jj-volumio go-librespot[8744]: time="2025-03-17T20:18:01+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 17 20:18:01 jj-volumio go-librespot[8744]: time="2025-03-17T20:18:01+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 17 20:18:01 jj-volumio go-librespot[8744]: time="2025-03-17T20:18:01+01:00" level=info msg="zeroconf server listening on port 33827" Mar 17 20:18:01 jj-volumio go-librespot[8744]: time="2025-03-17T20:18:01+01:00" level=debug msg="obtained new client token: AADRIr7/D+jnUfzbwH9HpG8L7a51Ni3CW3ByORy/wOOPn36cSUxqxxH+zO8sdKMkbuHR2mn3BwpbXXTnU2qrvtGd6JCVskObSbwiVUJVlswKcUEEct63ZqSggN5VqGVTt4a4ovqic1CsyO0Ki++jIS/697qdblCgmXCxfRkXuC1ROJO9t1YSwD96PAmyN2XkFmKYrsoXV1QTEyFM0PdmpQEaCZYZOe9xtRldjJ2xQJiCiTfkFYUQPr+t" Mar 17 20:18:01 jj-volumio go-librespot[8744]: time="2025-03-17T20:18:01+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Mar 17 20:18:01 jj-volumio go-librespot[8744]: time="2025-03-17T20:18:01+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 17 20:18:01 jj-volumio go-librespot[8744]: time="2025-03-17T20:18:01+01:00" level=debug msg="completed keyexchange" Mar 17 20:18:01 jj-volumio go-librespot[8744]: time="2025-03-17T20:18:01+01:00" level=debug msg="completed challenge" Mar 17 20:18:01 jj-volumio go-librespot[8744]: time="2025-03-17T20:18:01+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 17 20:18:01 jj-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 20:18:01 jj-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 20:18:02 jj-volumio volumio[1074]: info: Initializing connection to go-librespot Websocket Mar 17 20:18:02 jj-volumio volumio[1074]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 20:18:03 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 17 20:18:04 jj-volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 20:18:04 jj-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 269. Mar 17 20:18:04 jj-volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 20:18:04 jj-volumio systemd[1]: Started go-librespot Daemon. Mar 17 20:18:04 jj-volumio go-librespot[8756]: go-librespot daemon starting... Mar 17 20:18:04 jj-volumio go-librespot[8756]: time="2025-03-17T20:18:04+01:00" level=info msg="running go-librespot 0.2.0" Mar 17 20:18:04 jj-volumio go-librespot[8756]: time="2025-03-17T20:18:04+01:00" level=debug msg="app state loaded" Mar 17 20:18:04 jj-volumio go-librespot[8756]: time="2025-03-17T20:18:04+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 17 20:18:04 jj-volumio go-librespot[8756]: time="2025-03-17T20:18:04+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 17 20:18:04 jj-volumio go-librespot[8756]: time="2025-03-17T20:18:04+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 17 20:18:04 jj-volumio go-librespot[8756]: time="2025-03-17T20:18:04+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 17 20:18:04 jj-volumio go-librespot[8756]: time="2025-03-17T20:18:04+01:00" level=info msg="zeroconf server listening on port 40309" Mar 17 20:18:04 jj-volumio go-librespot[8756]: time="2025-03-17T20:18:04+01:00" level=debug msg="obtained new client token: AABVqw8HjrJzqIRKuK9WUoo7Ic8QlqqKTAPExYIpsUeYxNJ2686dgVtqiJrnK1S4gYA/EfEV4wcewBACpxHyhC/Dsbdf1LA2tfaVp0pfu7pZJUorskBt41OZyZXtjIG3pWkHhuQZ4W9zb+fQLBUwmeWVIfmGK191SgSyzYdzkt4YI7vTIusBeauJr2Wn4QVZyd0pW9hZvw7aIy+/vpPpaZ5pU8HL+xwa+h+NFEc9ENfCcwbs3JyYt7Jg" Mar 17 20:18:04 jj-volumio go-librespot[8756]: time="2025-03-17T20:18:04+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 17 20:18:04 jj-volumio go-librespot[8756]: time="2025-03-17T20:18:04+01:00" level=debug msg="completed keyexchange" Mar 17 20:18:04 jj-volumio go-librespot[8756]: time="2025-03-17T20:18:04+01:00" level=debug msg="completed challenge" Mar 17 20:18:04 jj-volumio go-librespot[8756]: time="2025-03-17T20:18:04+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 17 20:18:04 jj-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 20:18:04 jj-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 20:18:05 jj-volumio volumio[1074]: info: Initializing connection to go-librespot Websocket Mar 17 20:18:05 jj-volumio volumio[1074]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 20:18:07 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 17 20:18:08 jj-volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 20:18:08 jj-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 270. Mar 17 20:18:08 jj-volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 20:18:08 jj-volumio systemd[1]: Started go-librespot Daemon. Mar 17 20:18:08 jj-volumio go-librespot[8777]: go-librespot daemon starting... Mar 17 20:18:08 jj-volumio go-librespot[8777]: time="2025-03-17T20:18:08+01:00" level=info msg="running go-librespot 0.2.0" Mar 17 20:18:08 jj-volumio go-librespot[8777]: time="2025-03-17T20:18:08+01:00" level=debug msg="app state loaded" Mar 17 20:18:08 jj-volumio go-librespot[8777]: time="2025-03-17T20:18:08+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 17 20:18:08 jj-volumio go-librespot[8777]: time="2025-03-17T20:18:08+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 17 20:18:08 jj-volumio go-librespot[8777]: time="2025-03-17T20:18:08+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 17 20:18:08 jj-volumio go-librespot[8777]: time="2025-03-17T20:18:08+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 17 20:18:08 jj-volumio go-librespot[8777]: time="2025-03-17T20:18:08+01:00" level=info msg="zeroconf server listening on port 37207" Mar 17 20:18:08 jj-volumio go-librespot[8777]: time="2025-03-17T20:18:08+01:00" level=debug msg="obtained new client token: AADSeLxm9WGIDQwiCBdCmuPhi95RH3nacUgoXDqRot+YaeSyEGDXOMrGBSn+WI2VqjEvRIbp9FEQMl0R41V7ouTap6YAU4ZKh5bCiV0zCw0zpF73AZw8gYo1pDKLgVojQYkxUMRL4Lu4UX5b50/e4lXJAK/Tqwcu9jeilM4Sy0UeyYjt6Np19HhHgWyKdIv6AKX8gzIusBEOVD/b50+YEOdKfqVtNA/uTZGnBhHT1V9Yk4bQFXZTvjct" Mar 17 20:18:08 jj-volumio go-librespot[8777]: time="2025-03-17T20:18:08+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 17 20:18:08 jj-volumio go-librespot[8777]: time="2025-03-17T20:18:08+01:00" level=debug msg="completed keyexchange" Mar 17 20:18:08 jj-volumio go-librespot[8777]: time="2025-03-17T20:18:08+01:00" level=debug msg="completed challenge" Mar 17 20:18:08 jj-volumio go-librespot[8777]: time="2025-03-17T20:18:08+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 17 20:18:08 jj-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 20:18:08 jj-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 20:18:08 jj-volumio volumio[1074]: info: Initializing connection to go-librespot Websocket Mar 17 20:18:08 jj-volumio volumio[1074]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 20:18:09 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 17 20:18:09 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 17 20:18:09 jj-volumio volumio[1074]: info: Discovery: Getting this device information Mar 17 20:18:09 jj-volumio volumio[1074]: info: CoreCommandRouter::volumioGetState Mar 17 20:18:09 jj-volumio volumio[1074]: info: CorePlayQueue::getTrack 0 Mar 17 20:18:09 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 17 20:18:11 jj-volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 20:18:11 jj-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 271. Mar 17 20:18:11 jj-volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 20:18:11 jj-volumio systemd[1]: Started go-librespot Daemon. Mar 17 20:18:11 jj-volumio go-librespot[8785]: go-librespot daemon starting... Mar 17 20:18:11 jj-volumio go-librespot[8785]: time="2025-03-17T20:18:11+01:00" level=info msg="running go-librespot 0.2.0" Mar 17 20:18:11 jj-volumio go-librespot[8785]: time="2025-03-17T20:18:11+01:00" level=debug msg="app state loaded" Mar 17 20:18:11 jj-volumio go-librespot[8785]: time="2025-03-17T20:18:11+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 17 20:18:11 jj-volumio go-librespot[8785]: time="2025-03-17T20:18:11+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 17 20:18:11 jj-volumio go-librespot[8785]: time="2025-03-17T20:18:11+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 17 20:18:11 jj-volumio go-librespot[8785]: time="2025-03-17T20:18:11+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 17 20:18:11 jj-volumio go-librespot[8785]: time="2025-03-17T20:18:11+01:00" level=info msg="zeroconf server listening on port 39443" Mar 17 20:18:11 jj-volumio go-librespot[8785]: time="2025-03-17T20:18:11+01:00" level=debug msg="obtained new client token: AAC2gpmY7URfKSneCNZxnYxgbuUsDn151N5nNlNTUwaKLr/af+rYWl4suT9mfLDDwoWkbYAepuhIwPr4NVnetOZ6R1s4cKayhCyF5PHRMT51YnqPKS/QsLuqp8DiZgVFlggcqSBa+Y6rCMG1sAwk9EKHdJ0P5DW1Hvbk01m7V0+idj16HRyiC4lLiebOYEnyuFMT/D9KBX2nrhVmoCiyDsAAY/1+3tKlUH/fYeWGTugBXz1voug3Z2D4" Mar 17 20:18:11 jj-volumio go-librespot[8785]: time="2025-03-17T20:18:11+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 17 20:18:11 jj-volumio go-librespot[8785]: time="2025-03-17T20:18:11+01:00" level=debug msg="completed keyexchange" Mar 17 20:18:11 jj-volumio go-librespot[8785]: time="2025-03-17T20:18:11+01:00" level=debug msg="completed challenge" Mar 17 20:18:11 jj-volumio go-librespot[8785]: time="2025-03-17T20:18:11+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 17 20:18:11 jj-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 20:18:11 jj-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 20:18:11 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 17 20:18:11 jj-volumio volumio[1074]: info: Initializing connection to go-librespot Websocket Mar 17 20:18:11 jj-volumio volumio[1074]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 20:18:14 jj-volumio volumio[1074]: info: Initializing connection to go-librespot Websocket Mar 17 20:18:14 jj-volumio volumio[1074]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 20:18:14 jj-volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 20:18:14 jj-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 272. Mar 17 20:18:14 jj-volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 20:18:14 jj-volumio systemd[1]: Started go-librespot Daemon. Mar 17 20:18:14 jj-volumio go-librespot[8792]: go-librespot daemon starting... Mar 17 20:18:14 jj-volumio go-librespot[8792]: time="2025-03-17T20:18:14+01:00" level=info msg="running go-librespot 0.2.0" Mar 17 20:18:14 jj-volumio go-librespot[8792]: time="2025-03-17T20:18:14+01:00" level=debug msg="app state loaded" Mar 17 20:18:14 jj-volumio go-librespot[8792]: time="2025-03-17T20:18:14+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 17 20:18:15 jj-volumio go-librespot[8792]: time="2025-03-17T20:18:15+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 17 20:18:15 jj-volumio go-librespot[8792]: time="2025-03-17T20:18:15+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 17 20:18:15 jj-volumio go-librespot[8792]: time="2025-03-17T20:18:15+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 17 20:18:15 jj-volumio go-librespot[8792]: time="2025-03-17T20:18:15+01:00" level=info msg="zeroconf server listening on port 38565" Mar 17 20:18:15 jj-volumio go-librespot[8792]: time="2025-03-17T20:18:15+01:00" level=debug msg="obtained new client token: AAAwZzth/5ABdn1JaGqQIXoYYx75IGw8+d8VM0oFrZ9zkpx4F2+Kq1DCzKoCFap/DAnPRkjZ0H5p6aUbmt/NFbUL0BokkvXAhMT6Y211zNhqUtA2i7JKaqG6G2RvkG5GRhZN/EbnMKVX23oYoJg76rERnREfaTlhNnG0LNihivGT3xqzkD93TqEl5ddZuo7OkFwOMRZFO8oV5M+tJ6jXaQNzUPFiK0Ci80N2F6nObguYg2Dz5vf6bA==" Mar 17 20:18:15 jj-volumio go-librespot[8792]: time="2025-03-17T20:18:15+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 17 20:18:15 jj-volumio go-librespot[8792]: time="2025-03-17T20:18:15+01:00" level=debug msg="completed keyexchange" Mar 17 20:18:15 jj-volumio go-librespot[8792]: time="2025-03-17T20:18:15+01:00" level=debug msg="completed challenge" Mar 17 20:18:15 jj-volumio go-librespot[8792]: time="2025-03-17T20:18:15+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 17 20:18:15 jj-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 20:18:15 jj-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 20:18:15 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 17 20:18:17 jj-volumio volumio[1074]: info: Initializing connection to go-librespot Websocket Mar 17 20:18:17 jj-volumio volumio[1074]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 20:18:18 jj-volumio sudo[8814]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 17 20:18:18 jj-volumio sudo[8814]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 17 20:18:18 jj-volumio sudo[8814]: pam_unix(sudo:session): session closed for user root Mar 17 20:18:18 jj-volumio sudo[8817]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 17 20:18:18 jj-volumio sudo[8817]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 17 20:18:18 jj-volumio sudo[8817]: pam_unix(sudo:session): session closed for user root Mar 17 20:18:18 jj-volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 20:18:18 jj-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 273. Mar 17 20:18:18 jj-volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 20:18:18 jj-volumio systemd[1]: Started go-librespot Daemon. Mar 17 20:18:18 jj-volumio go-librespot[8819]: go-librespot daemon starting... Mar 17 20:18:18 jj-volumio go-librespot[8819]: time="2025-03-17T20:18:18+01:00" level=info msg="running go-librespot 0.2.0" Mar 17 20:18:18 jj-volumio go-librespot[8819]: time="2025-03-17T20:18:18+01:00" level=debug msg="app state loaded" Mar 17 20:18:18 jj-volumio go-librespot[8819]: time="2025-03-17T20:18:18+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 17 20:18:18 jj-volumio volumio[1074]: verbose: New Socket.io Connection to 192.168.177.185 from 192.168.177.211 UA: Mozilla/5.0 (Linux; Android 15; NE2213 Build/AP3A.240617.008; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/134.0.6998.39 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Mar 17 20:18:18 jj-volumio go-librespot[8819]: time="2025-03-17T20:18:18+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 17 20:18:18 jj-volumio go-librespot[8819]: time="2025-03-17T20:18:18+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 17 20:18:18 jj-volumio go-librespot[8819]: time="2025-03-17T20:18:18+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 17 20:18:18 jj-volumio go-librespot[8819]: time="2025-03-17T20:18:18+01:00" level=info msg="zeroconf server listening on port 35653" Mar 17 20:18:18 jj-volumio go-librespot[8819]: time="2025-03-17T20:18:18+01:00" level=debug msg="obtained new client token: AACBfco/jYsy7V2ggqudDGPfKxN6LPmLnz6B3Hhm2d0kW/wXMwOqr2iKvK4lNP/Eeq/iWp1xgKydIFbDmnqTeV51rLizHYaBNqzW3BzpJBERxD1sUBC/ujhqbRyH+ZOfrF7CrHromCd3ysnS1NTudbUsARLwbLxuihtpRfBzn2M9IArx+ncEJARFxRGBSl1kDNMGtTnwURtCImfijStBBsTrbyqNg80uOJA82zmWRkP91eI7CEMWi2Ob" Mar 17 20:18:18 jj-volumio volumio[1074]: info: CoreCommandRouter::volumioGetVisibleSources Mar 17 20:18:18 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 17 20:18:18 jj-volumio volumio[1074]: info: CoreCommandRouter::volumioGetState Mar 17 20:18:18 jj-volumio volumio[1074]: info: CorePlayQueue::getTrack 0 Mar 17 20:18:18 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Mar 17 20:18:18 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 17 20:18:18 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 17 20:18:18 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 17 20:18:18 jj-volumio go-librespot[8819]: time="2025-03-17T20:18:18+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 17 20:18:18 jj-volumio go-librespot[8819]: time="2025-03-17T20:18:18+01:00" level=debug msg="completed keyexchange" Mar 17 20:18:18 jj-volumio go-librespot[8819]: time="2025-03-17T20:18:18+01:00" level=debug msg="completed challenge" Mar 17 20:18:18 jj-volumio go-librespot[8819]: time="2025-03-17T20:18:18+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 17 20:18:18 jj-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 20:18:18 jj-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 20:18:18 jj-volumio sudo[8827]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 17 20:18:18 jj-volumio sudo[8827]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 17 20:18:18 jj-volumio sudo[8827]: pam_unix(sudo:session): session closed for user root Mar 17 20:18:18 jj-volumio sudo[8830]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 17 20:18:18 jj-volumio sudo[8830]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 17 20:18:18 jj-volumio sudo[8830]: pam_unix(sudo:session): session closed for user root Mar 17 20:18:19 jj-volumio volumio[1074]: verbose: New Socket.io Connection to 192.168.177.185 from 192.168.177.211 UA: Mozilla/5.0 (Linux; Android 15; NE2213 Build/AP3A.240617.008; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/134.0.6998.39 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 Mar 17 20:18:19 jj-volumio volumio[1074]: info: CoreCommandRouter::volumioGetState Mar 17 20:18:19 jj-volumio volumio[1074]: info: CorePlayQueue::getTrack 0 Mar 17 20:18:19 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 17 20:18:19 jj-volumio volumio[1074]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Mar 17 20:18:19 jj-volumio volumio[1074]: info: Listing playlists Mar 17 20:18:20 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 17 20:18:20 jj-volumio volumio[1074]: info: Received Get System Info Mar 17 20:18:20 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 17 20:18:20 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 17 20:18:20 jj-volumio volumio[1074]: info: Discovery: Getting this device information Mar 17 20:18:20 jj-volumio volumio[1074]: info: CoreCommandRouter::volumioGetState Mar 17 20:18:20 jj-volumio volumio[1074]: info: CorePlayQueue::getTrack 0 Mar 17 20:18:20 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 17 20:18:20 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 17 20:18:20 jj-volumio volumio[1074]: info: Initializing connection to go-librespot Websocket Mar 17 20:18:20 jj-volumio volumio[1074]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 20:18:20 jj-volumio volumio[1074]: info: CoreCommandRouter::volumioGetQueue Mar 17 20:18:20 jj-volumio volumio[1074]: info: CoreStateMachine::getQueue Mar 17 20:18:20 jj-volumio volumio[1074]: info: CorePlayQueue::getQueue Mar 17 20:18:21 jj-volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 20:18:21 jj-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 274. Mar 17 20:18:21 jj-volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 20:18:21 jj-volumio systemd[1]: Started go-librespot Daemon. Mar 17 20:18:21 jj-volumio go-librespot[8833]: go-librespot daemon starting... Mar 17 20:18:21 jj-volumio go-librespot[8833]: time="2025-03-17T20:18:21+01:00" level=info msg="running go-librespot 0.2.0" Mar 17 20:18:21 jj-volumio go-librespot[8833]: time="2025-03-17T20:18:21+01:00" level=debug msg="app state loaded" Mar 17 20:18:21 jj-volumio go-librespot[8833]: time="2025-03-17T20:18:21+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 17 20:18:21 jj-volumio go-librespot[8833]: time="2025-03-17T20:18:21+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 17 20:18:21 jj-volumio go-librespot[8833]: time="2025-03-17T20:18:21+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 17 20:18:21 jj-volumio go-librespot[8833]: time="2025-03-17T20:18:21+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 17 20:18:21 jj-volumio go-librespot[8833]: time="2025-03-17T20:18:21+01:00" level=info msg="zeroconf server listening on port 35761" Mar 17 20:18:21 jj-volumio go-librespot[8833]: time="2025-03-17T20:18:21+01:00" level=debug msg="obtained new client token: AAAiuQfPFl4OJbwt5FWGA1HSXdPFPMRtOMDYQCMQCRtqhl/Aiw58zU6EQP0knsPaCPHIKgJ0zgsGKcteb/4kTfvWqpvG3ln8OG09nUq6iJNGQCbfWP7nOrR5WOBnoVGs5IkWqRh/JHeEt3T3/+F5/BNzUgyI5tBqjNTVDeBjJgR/DP0G0rXhHGOJ3IoQlBhFGtr4GUy0dZ+Fb9WRtx5SpidVNe/iIGZDnXJ65JhMzJE+SrjDq87ba/0D" Mar 17 20:18:21 jj-volumio go-librespot[8833]: time="2025-03-17T20:18:21+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 17 20:18:21 jj-volumio go-librespot[8833]: time="2025-03-17T20:18:21+01:00" level=debug msg="completed keyexchange" Mar 17 20:18:21 jj-volumio go-librespot[8833]: time="2025-03-17T20:18:21+01:00" level=debug msg="completed challenge" Mar 17 20:18:21 jj-volumio go-librespot[8833]: time="2025-03-17T20:18:21+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 17 20:18:21 jj-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 20:18:21 jj-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 20:18:22 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 17 20:18:22 jj-volumio volumio[1074]: info: Received Get System Info Mar 17 20:18:22 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 17 20:18:22 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 17 20:18:22 jj-volumio volumio[1074]: info: Discovery: Getting this device information Mar 17 20:18:22 jj-volumio volumio[1074]: info: CoreCommandRouter::volumioGetState Mar 17 20:18:22 jj-volumio volumio[1074]: info: CorePlayQueue::getTrack 0 Mar 17 20:18:22 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 17 20:18:22 jj-volumio volumio[1074]: info: CoreCommandRouter::volumioClearQueue Mar 17 20:18:22 jj-volumio volumio[1074]: info: CoreStateMachine::ClearQueue Mar 17 20:18:22 jj-volumio volumio[1074]: info: CoreStateMachine::stop Mar 17 20:18:22 jj-volumio volumio[1074]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 17 20:18:22 jj-volumio volumio[1074]: info: CorePlayQueue::clearPlayQueue Mar 17 20:18:22 jj-volumio volumio[1074]: info: CorePlayQueue::saveQueue Mar 17 20:18:22 jj-volumio volumio[1074]: info: CoreCommandRouter::volumioPushState Mar 17 20:18:22 jj-volumio volumio[1074]: info: MRS: Pushing multiroomSync output update for this device Mar 17 20:18:22 jj-volumio volumio[1074]: info: MRS: Pushing multiroomSync output Mar 17 20:18:22 jj-volumio volumio[1074]: info: CoreCommandRouter::volumioPushQueue Mar 17 20:18:23 jj-volumio volumio[1074]: info: Initializing connection to go-librespot Websocket Mar 17 20:18:23 jj-volumio volumio[1074]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 20:18:24 jj-volumio volumio[1074]: info: CoreCommandRouter::volumioGetVisibleSources Mar 17 20:18:24 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 17 20:18:24 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 17 20:18:25 jj-volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 20:18:25 jj-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 275. Mar 17 20:18:25 jj-volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 20:18:25 jj-volumio systemd[1]: Started go-librespot Daemon. Mar 17 20:18:25 jj-volumio go-librespot[8848]: go-librespot daemon starting... Mar 17 20:18:25 jj-volumio go-librespot[8848]: time="2025-03-17T20:18:25+01:00" level=info msg="running go-librespot 0.2.0" Mar 17 20:18:25 jj-volumio go-librespot[8848]: time="2025-03-17T20:18:25+01:00" level=debug msg="app state loaded" Mar 17 20:18:25 jj-volumio go-librespot[8848]: time="2025-03-17T20:18:25+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 17 20:18:25 jj-volumio go-librespot[8848]: time="2025-03-17T20:18:25+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 17 20:18:25 jj-volumio go-librespot[8848]: time="2025-03-17T20:18:25+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 17 20:18:25 jj-volumio go-librespot[8848]: time="2025-03-17T20:18:25+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 17 20:18:25 jj-volumio go-librespot[8848]: time="2025-03-17T20:18:25+01:00" level=info msg="zeroconf server listening on port 43051" Mar 17 20:18:25 jj-volumio go-librespot[8848]: time="2025-03-17T20:18:25+01:00" level=debug msg="obtained new client token: AADlKMvjB9hb8me95P6/Uz9k5bPgrQ76ZVZ/PMfYUOmaxX9/bGR+ad9BiuUPUSiB+D9h5co7ZokMg7YKVNq6lYE8fba2VGDtd6pInvEEWMrFDaDmuV3sy4OI9SWXYbWBtruUTwOOl5x3PAf+xuUkfj4MdouNCj69iinLTZmM0oNnlJ4cy3ufNkseFGkQQo71OI0JV1UbhzpfcJg8JE0aV6zXJyR8pBiAyRx1PWbC7Up50u+7QmVBsrRD" Mar 17 20:18:25 jj-volumio go-librespot[8848]: time="2025-03-17T20:18:25+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 17 20:18:25 jj-volumio go-librespot[8848]: time="2025-03-17T20:18:25+01:00" level=debug msg="completed keyexchange" Mar 17 20:18:25 jj-volumio go-librespot[8848]: time="2025-03-17T20:18:25+01:00" level=debug msg="completed challenge" Mar 17 20:18:25 jj-volumio go-librespot[8848]: time="2025-03-17T20:18:25+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 17 20:18:25 jj-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 20:18:25 jj-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 20:18:26 jj-volumio volumio[1074]: info: Initializing connection to go-librespot Websocket Mar 17 20:18:26 jj-volumio volumio[1074]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 20:18:28 jj-volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 20:18:28 jj-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 276. Mar 17 20:18:28 jj-volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 20:18:28 jj-volumio systemd[1]: Started go-librespot Daemon. Mar 17 20:18:28 jj-volumio go-librespot[8870]: go-librespot daemon starting... Mar 17 20:18:28 jj-volumio go-librespot[8870]: time="2025-03-17T20:18:28+01:00" level=info msg="running go-librespot 0.2.0" Mar 17 20:18:28 jj-volumio go-librespot[8870]: time="2025-03-17T20:18:28+01:00" level=debug msg="app state loaded" Mar 17 20:18:28 jj-volumio go-librespot[8870]: time="2025-03-17T20:18:28+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 17 20:18:28 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 17 20:18:28 jj-volumio go-librespot[8870]: time="2025-03-17T20:18:28+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 17 20:18:28 jj-volumio go-librespot[8870]: time="2025-03-17T20:18:28+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 17 20:18:28 jj-volumio go-librespot[8870]: time="2025-03-17T20:18:28+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 17 20:18:28 jj-volumio go-librespot[8870]: time="2025-03-17T20:18:28+01:00" level=info msg="zeroconf server listening on port 42125" Mar 17 20:18:28 jj-volumio go-librespot[8870]: time="2025-03-17T20:18:28+01:00" level=debug msg="obtained new client token: AAAjpyxru1FOKJCkf7LoEOdo7yTLVGouHn4Byqt9TKurGurvwxiNmPLzwBTh7nQZWXfolO/c22IQSFvGguh7s9tX+iDmJ+37GQJDuBJxFUyGuj+QVdDw/c10Q6+oQ/3H8Uepxaw5swskAVZeob1HXz4aD3Mjp4jSRhgZgnl8miRumFE2W6S+QAcdbYwBlfqIyllN06fsmXETU0YqkieWBiM3YmvEUbKN10puISuTLIPYj738khHxERsC" Mar 17 20:18:28 jj-volumio go-librespot[8870]: time="2025-03-17T20:18:28+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 17 20:18:28 jj-volumio go-librespot[8870]: time="2025-03-17T20:18:28+01:00" level=debug msg="completed keyexchange" Mar 17 20:18:28 jj-volumio go-librespot[8870]: time="2025-03-17T20:18:28+01:00" level=debug msg="completed challenge" Mar 17 20:18:28 jj-volumio go-librespot[8870]: time="2025-03-17T20:18:28+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 17 20:18:28 jj-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 20:18:28 jj-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 20:18:29 jj-volumio volumio[1074]: info: Initializing connection to go-librespot Websocket Mar 17 20:18:29 jj-volumio volumio[1074]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 20:18:30 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 17 20:18:30 jj-volumio volumio[1074]: info: Preload queue cleared Mar 17 20:18:32 jj-volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 20:18:32 jj-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 277. Mar 17 20:18:32 jj-volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 20:18:32 jj-volumio systemd[1]: Started go-librespot Daemon. Mar 17 20:18:32 jj-volumio go-librespot[8877]: go-librespot daemon starting... Mar 17 20:18:32 jj-volumio go-librespot[8877]: time="2025-03-17T20:18:32+01:00" level=info msg="running go-librespot 0.2.0" Mar 17 20:18:32 jj-volumio go-librespot[8877]: time="2025-03-17T20:18:32+01:00" level=debug msg="app state loaded" Mar 17 20:18:32 jj-volumio go-librespot[8877]: time="2025-03-17T20:18:32+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 17 20:18:32 jj-volumio go-librespot[8877]: time="2025-03-17T20:18:32+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 17 20:18:32 jj-volumio go-librespot[8877]: time="2025-03-17T20:18:32+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 17 20:18:32 jj-volumio go-librespot[8877]: time="2025-03-17T20:18:32+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 17 20:18:32 jj-volumio go-librespot[8877]: time="2025-03-17T20:18:32+01:00" level=info msg="zeroconf server listening on port 42497" Mar 17 20:18:32 jj-volumio go-librespot[8877]: time="2025-03-17T20:18:32+01:00" level=debug msg="obtained new client token: AABq0woALurSfzClZ1gr/tMnPph4xUqnGkQja8II3TMLBQZEgWJHcjHnwU5P5GFfBuaRbKDeC2JX27bhzoq40+2+Z2Z3v+oXQVYFsP2EMnykqgLO1T5rgg5T/nBO08HthJlYxiWlVdX81FsTxJyZGhxN8J/UeByXI1dEdrPi+OVP+lHdaAwdIksuu4ddtgbXIXD6FWMTnavd2AyeKMf5Ukd5xnXGJyScFyopHDF084/Plg3jv7inWPPX" Mar 17 20:18:32 jj-volumio go-librespot[8877]: time="2025-03-17T20:18:32+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 17 20:18:32 jj-volumio go-librespot[8877]: time="2025-03-17T20:18:32+01:00" level=debug msg="completed keyexchange" Mar 17 20:18:32 jj-volumio go-librespot[8877]: time="2025-03-17T20:18:32+01:00" level=debug msg="completed challenge" Mar 17 20:18:32 jj-volumio go-librespot[8877]: time="2025-03-17T20:18:32+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 17 20:18:32 jj-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 20:18:32 jj-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 20:18:32 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 17 20:18:32 jj-volumio volumio[1074]: info: Initializing connection to go-librespot Websocket Mar 17 20:18:32 jj-volumio volumio[1074]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 20:18:32 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 17 20:18:32 jj-volumio volumio[1074]: info: Preload queue cleared Mar 17 20:18:35 jj-volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 20:18:35 jj-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 278. Mar 17 20:18:35 jj-volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 20:18:35 jj-volumio systemd[1]: Started go-librespot Daemon. Mar 17 20:18:35 jj-volumio go-librespot[8898]: go-librespot daemon starting... Mar 17 20:18:35 jj-volumio go-librespot[8898]: time="2025-03-17T20:18:35+01:00" level=info msg="running go-librespot 0.2.0" Mar 17 20:18:35 jj-volumio go-librespot[8898]: time="2025-03-17T20:18:35+01:00" level=debug msg="app state loaded" Mar 17 20:18:35 jj-volumio go-librespot[8898]: time="2025-03-17T20:18:35+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 17 20:18:35 jj-volumio go-librespot[8898]: time="2025-03-17T20:18:35+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 17 20:18:35 jj-volumio go-librespot[8898]: time="2025-03-17T20:18:35+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 17 20:18:35 jj-volumio go-librespot[8898]: time="2025-03-17T20:18:35+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 17 20:18:35 jj-volumio go-librespot[8898]: time="2025-03-17T20:18:35+01:00" level=info msg="zeroconf server listening on port 39561" Mar 17 20:18:35 jj-volumio volumio[1074]: info: Initializing connection to go-librespot Websocket Mar 17 20:18:35 jj-volumio go-librespot[8898]: time="2025-03-17T20:18:35+01:00" level=debug msg="new websocket client" Mar 17 20:18:35 jj-volumio volumio[1074]: info: Connection to go-librespot Websocket established Mar 17 20:18:35 jj-volumio go-librespot[8898]: time="2025-03-17T20:18:35+01:00" level=debug msg="obtained new client token: AACv7j3Xlsf3Ie386qUHSNVMLOhvhNNDWTvr7BZ4pwkYmEWwYR4cyeCBSyUTwb/VBmmGyQSxZ8quRcEmUW9gQkVno0WzK/rKQQgX821yNnWrPNyoQ+Rxn5PLANnCC3eyJ2O+5ExmlwCsSsFvSFL82gSHPNp6d0RCa/ICtBH5hXST9csxLg0OwFuUFOnGSBPF6xa7Bjx1KMW1yredp4yq09orZoTMfvUHYDEBHzfjq2zdUNLJwar5bQyC" Mar 17 20:18:35 jj-volumio go-librespot[8898]: time="2025-03-17T20:18:35+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 17 20:18:35 jj-volumio go-librespot[8898]: time="2025-03-17T20:18:35+01:00" level=debug msg="completed keyexchange" Mar 17 20:18:35 jj-volumio go-librespot[8898]: time="2025-03-17T20:18:35+01:00" level=debug msg="completed challenge" Mar 17 20:18:35 jj-volumio go-librespot[8898]: time="2025-03-17T20:18:35+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 17 20:18:35 jj-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 20:18:35 jj-volumio volumio[1074]: info: Connection to go-librespot Websocket closed Mar 17 20:18:35 jj-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 20:18:35 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 17 20:18:36 jj-volumio volumio[1074]: info: Preload queue cleared Mar 17 20:18:36 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 17 20:18:36 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 17 20:18:36 jj-volumio volumio[1074]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Mar 17 20:18:36 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Mar 17 20:18:36 jj-volumio volumio[1074]: info: Received Get System Version Mar 17 20:18:36 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 17 20:18:36 jj-volumio volumio[1074]: info: Received Get System Info Mar 17 20:18:36 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 17 20:18:36 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 17 20:18:36 jj-volumio volumio[1074]: info: Discovery: Getting this device information Mar 17 20:18:36 jj-volumio volumio[1074]: info: CoreCommandRouter::volumioGetState Mar 17 20:18:36 jj-volumio volumio[1074]: info: CorePlayQueue::getTrack 0 Mar 17 20:18:36 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 17 20:18:37 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 17 20:18:38 jj-volumio volumio[1074]: info: Preload queue cleared Mar 17 20:18:38 jj-volumio volumio[1074]: info: Getting Spotify volume Mar 17 20:18:38 jj-volumio volumio[1074]: (node:1074) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 20:18:38 jj-volumio volumio[1074]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Mar 17 20:18:38 jj-volumio volumio[1074]: (node:1074) 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: 23) Mar 17 20:18:38 jj-volumio volumio[1074]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Mar 17 20:18:38 jj-volumio volumio[1074]: info: CoreCommandRouter::volumioGetState Mar 17 20:18:38 jj-volumio volumio[1074]: info: CorePlayQueue::getTrack 0 Mar 17 20:18:38 jj-volumio volumio[1074]: info: Initializing connection to go-librespot Websocket Mar 17 20:18:38 jj-volumio volumio[1074]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 20:18:39 jj-volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 20:18:39 jj-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 279. Mar 17 20:18:39 jj-volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 20:18:39 jj-volumio systemd[1]: Started go-librespot Daemon. Mar 17 20:18:39 jj-volumio go-librespot[8904]: go-librespot daemon starting... Mar 17 20:18:39 jj-volumio go-librespot[8904]: time="2025-03-17T20:18:39+01:00" level=info msg="running go-librespot 0.2.0" Mar 17 20:18:39 jj-volumio go-librespot[8904]: time="2025-03-17T20:18:39+01:00" level=debug msg="app state loaded" Mar 17 20:18:39 jj-volumio go-librespot[8904]: time="2025-03-17T20:18:39+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 17 20:18:39 jj-volumio go-librespot[8904]: time="2025-03-17T20:18:39+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 17 20:18:39 jj-volumio go-librespot[8904]: time="2025-03-17T20:18:39+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 17 20:18:39 jj-volumio go-librespot[8904]: time="2025-03-17T20:18:39+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 17 20:18:39 jj-volumio go-librespot[8904]: time="2025-03-17T20:18:39+01:00" level=info msg="zeroconf server listening on port 46385" Mar 17 20:18:39 jj-volumio go-librespot[8904]: time="2025-03-17T20:18:39+01:00" level=debug msg="obtained new client token: AAByociWNpTYRas4Gepqli+vOELE9H16uRI9w83h1ln2QIYdGW8oDqz+9k7wc5wIjR9GBWgXi6dlJEaEepCT4UscfE0LSiiI2wMnTfwcCugrtzODprBQtFiz2A7Xl9VVf21su0/vb+n58smGn14Up1UmkMMpWJzKahcOrOnJZdNWjQnS8Gh26U7QYaizwyw6QcKEaXYn4gDVlN2IBPfvseJ6a4EX4DTU32Ji+areszPCpWvq6ZfkEZSx" Mar 17 20:18:39 jj-volumio go-librespot[8904]: time="2025-03-17T20:18:39+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 17 20:18:39 jj-volumio go-librespot[8904]: time="2025-03-17T20:18:39+01:00" level=debug msg="completed keyexchange" Mar 17 20:18:39 jj-volumio go-librespot[8904]: time="2025-03-17T20:18:39+01:00" level=debug msg="completed challenge" Mar 17 20:18:39 jj-volumio go-librespot[8904]: time="2025-03-17T20:18:39+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 17 20:18:39 jj-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 20:18:39 jj-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 20:18:39 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 17 20:18:39 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 17 20:18:39 jj-volumio volumio[1074]: info: Discovery: Getting this device information Mar 17 20:18:39 jj-volumio volumio[1074]: info: CoreCommandRouter::volumioGetState Mar 17 20:18:39 jj-volumio volumio[1074]: info: CorePlayQueue::getTrack 0 Mar 17 20:18:39 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 17 20:18:40 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 17 20:18:41 jj-volumio volumio[1074]: info: Initializing connection to go-librespot Websocket Mar 17 20:18:41 jj-volumio volumio[1074]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 20:18:42 jj-volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 20:18:42 jj-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 280. Mar 17 20:18:42 jj-volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 20:18:42 jj-volumio systemd[1]: Started go-librespot Daemon. Mar 17 20:18:42 jj-volumio go-librespot[8912]: go-librespot daemon starting... Mar 17 20:18:42 jj-volumio go-librespot[8912]: time="2025-03-17T20:18:42+01:00" level=info msg="running go-librespot 0.2.0" Mar 17 20:18:42 jj-volumio go-librespot[8912]: time="2025-03-17T20:18:42+01:00" level=debug msg="app state loaded" Mar 17 20:18:42 jj-volumio go-librespot[8912]: time="2025-03-17T20:18:42+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 17 20:18:42 jj-volumio go-librespot[8912]: time="2025-03-17T20:18:42+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 17 20:18:42 jj-volumio go-librespot[8912]: time="2025-03-17T20:18:42+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 17 20:18:42 jj-volumio go-librespot[8912]: time="2025-03-17T20:18:42+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 17 20:18:42 jj-volumio go-librespot[8912]: time="2025-03-17T20:18:42+01:00" level=info msg="zeroconf server listening on port 36123" Mar 17 20:18:42 jj-volumio go-librespot[8912]: time="2025-03-17T20:18:42+01:00" level=debug msg="obtained new client token: AABvuF+rEGFgrUyAV0GZMi2xTw83kc1X8EtL1aM/ugkyqKwhW9yBB6B0s4XdnjdhxlIz9GQg47qzvdVtkoj/QAnQU/l8mwo/7c5FNxmhdqHq2GIolpuh+ao0dya1Ec6RO1uL7sciSRGChmGTJN97K7fFVt9oNnUXTeeXCzhsp0yL1DfQtXIM70kz4W5wPrg8TKoxibwkFZX9T9VvXEWvj13pFm/7lxoLv5HGX3hy95GsixHPTUbIO2i/" Mar 17 20:18:42 jj-volumio go-librespot[8912]: time="2025-03-17T20:18:42+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 17 20:18:42 jj-volumio go-librespot[8912]: time="2025-03-17T20:18:42+01:00" level=debug msg="completed keyexchange" Mar 17 20:18:42 jj-volumio go-librespot[8912]: time="2025-03-17T20:18:42+01:00" level=debug msg="completed challenge" Mar 17 20:18:42 jj-volumio go-librespot[8912]: time="2025-03-17T20:18:42+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 17 20:18:42 jj-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 20:18:42 jj-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 20:18:43 jj-volumio volumio[1074]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 17 20:18:43 jj-volumio volumio[1074]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 17 20:18:43 jj-volumio volumio[1074]: TypeError: Cannot read property 'length' of undefined Mar 17 20:18:43 jj-volumio volumio[1074]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Mar 17 20:18:43 jj-volumio volumio[1074]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Mar 17 20:18:43 jj-volumio volumio[1074]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Mar 17 20:18:43 jj-volumio volumio[1074]: at Parser.emit (events.js:400:28) Mar 17 20:18:43 jj-volumio volumio[1074]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Mar 17 20:18:43 jj-volumio volumio[1074]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Mar 17 20:18:43 jj-volumio volumio[1074]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Mar 17 20:18:43 jj-volumio volumio[1074]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Mar 17 20:18:43 jj-volumio volumio[1074]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Mar 17 20:18:43 jj-volumio volumio[1074]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Mar 17 20:18:43 jj-volumio volumio[1074]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Mar 17 20:18:43 jj-volumio volumio[1074]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Mar 17 20:18:43 jj-volumio volumio[1074]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Mar 17 20:18:43 jj-volumio volumio[1074]: at IncomingMessage.emit (events.js:412:35) Mar 17 20:18:43 jj-volumio volumio[1074]: at endReadableNT (internal/streams/readable.js:1333:12) Mar 17 20:18:43 jj-volumio volumio[1074]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Mar 17 20:18:43 jj-volumio volumio[1074]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 17 20:18:43 jj-volumio sudo[8931]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-17 20:17 Mar 17 20:18:43 jj-volumio sudo[8931]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="a01a833dd28483f88cb390596f5090b7187992af" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 27 Feb 2025 12:15:38 PM CET" VOLUMIO_VERSION="3.795" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="9e0e048b157c8fb0f19240808f3da58b"