-- Logs begin at Sat 2025-03-01 20:23:50 CST, end at Sat 2025-03-01 22:11:34 CST. -- Mar 01 22:10:00 dac.x1 go-librespot[23645]: time="2025-03-01T22:10:00+08:00" level=debug msg="obtained new client token: AACdPEhIK5vHwn6tWt0o1iSC7tsMrvKeYiCE8tr9LAMhmYGJr5lDna1ttbZf5DuMGZkRsqnyQjYXaXRuqmneqtQN4Zg6+APAmnaoyCHa5Wq4+0E0eSbsr+Xb1gY/bFnCMoCNbYXFK2Ujh/gQ8spjEgtq/30QSNFSM4Tjx4ndB1ycOQ8sMjt0bz0xTnweO/LwGSToCs9FWSU5U1jHvKeHyT5XNoDoGiykjTs4KyW9iNvg4OF5rQJI" Mar 01 22:10:00 dac.x1 go-librespot[23645]: time="2025-03-01T22:10:00+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 22:10:01 dac.x1 go-librespot[23645]: time="2025-03-01T22:10:01+08:00" level=debug msg="completed keyexchange" Mar 01 22:10:01 dac.x1 go-librespot[23645]: time="2025-03-01T22:10:01+08:00" level=debug msg="completed challenge" Mar 01 22:10:01 dac.x1 go-librespot[23645]: time="2025-03-01T22:10:01+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 22:10:01 dac.x1 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 22:10:01 dac.x1 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 22:10:01 dac.x1 volumio[2783]: info: Connection to go-librespot Websocket closed Mar 01 22:10:02 dac.x1 volumio[2783]: info: Getting Spotify volume Mar 01 22:10:02 dac.x1 volumio[2783]: (node:2783) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 22:10:02 dac.x1 volumio[2783]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 01 22:10:02 dac.x1 volumio[2783]: (node:2783) 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: 384) Mar 01 22:10:02 dac.x1 volumio[2783]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Mar 01 22:10:02 dac.x1 volumio[2783]: info: CoreCommandRouter::volumioGetState Mar 01 22:10:02 dac.x1 volumio[2783]: info: CorePlayQueue::getTrack 1 Mar 01 22:10:04 dac.x1 volumio[2783]: info: Initializing connection to go-librespot Websocket Mar 01 22:10:04 dac.x1 volumio[2783]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 22:10:04 dac.x1 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 22:10:04 dac.x1 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 698. Mar 01 22:10:04 dac.x1 systemd[1]: Stopped go-librespot Daemon. Mar 01 22:10:04 dac.x1 systemd[1]: Started go-librespot Daemon. Mar 01 22:10:04 dac.x1 go-librespot[23667]: go-librespot daemon starting... Mar 01 22:10:04 dac.x1 go-librespot[23667]: time="2025-03-01T22:10:04+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 22:10:04 dac.x1 go-librespot[23667]: time="2025-03-01T22:10:04+08:00" level=debug msg="app state loaded" Mar 01 22:10:04 dac.x1 go-librespot[23667]: time="2025-03-01T22:10:04+08:00" level=debug msg="stored credentials not found" Mar 01 22:10:04 dac.x1 go-librespot[23667]: time="2025-03-01T22:10:04+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 22:10:05 dac.x1 wpa_supplicant[865]: wlan0: Failed to initiate sched scan Mar 01 22:10:06 dac.x1 go-librespot[23667]: time="2025-03-01T22:10:06+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 01 22:10:06 dac.x1 go-librespot[23667]: time="2025-03-01T22:10:06+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 01 22:10:06 dac.x1 go-librespot[23667]: time="2025-03-01T22:10:06+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 01 22:10:06 dac.x1 go-librespot[23667]: time="2025-03-01T22:10:06+08:00" level=info msg="zeroconf server listening on port 38627" Mar 01 22:10:07 dac.x1 volumio[2783]: info: Initializing connection to go-librespot Websocket Mar 01 22:10:07 dac.x1 go-librespot[23667]: time="2025-03-01T22:10:07+08:00" level=debug msg="new websocket client" Mar 01 22:10:07 dac.x1 volumio[2783]: info: Connection to go-librespot Websocket established Mar 01 22:10:07 dac.x1 go-librespot[23667]: time="2025-03-01T22:10:07+08:00" level=debug msg="obtained new client token: AABhVCTOPhu3xGttTBEym0k5VfhM0m9yDAbhXa7KAbOtuK6hUndVBby9fuD90NtxrZjYNNmmTy0fYYFFXIZbseaj0+nI/cSrv3UiZoFxGvPpNb64/PXrBICA87OHrV/EAVa2B2oNV4pn5twbgubmY9rQbGUdjJEJuKwnmzTlJGTLCt+Ab7qhTSVuv1DKPHGA/taQxMRujDhWaF4Ii+f3Oe8I3OCMa69/U+HVYWTy7pcT6mUu55Rg4gk=" Mar 01 22:10:07 dac.x1 go-librespot[23667]: time="2025-03-01T22:10:07+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 22:10:07 dac.x1 go-librespot[23667]: time="2025-03-01T22:10:07+08:00" level=debug msg="completed keyexchange" Mar 01 22:10:07 dac.x1 go-librespot[23667]: time="2025-03-01T22:10:07+08:00" level=debug msg="completed challenge" Mar 01 22:10:07 dac.x1 go-librespot[23667]: time="2025-03-01T22:10:07+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 22:10:07 dac.x1 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 22:10:07 dac.x1 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 22:10:07 dac.x1 volumio[2783]: info: Connection to go-librespot Websocket closed Mar 01 22:10:09 dac.x1 volumio[2783]: info: MyVolumio login type: Token Mar 01 22:10:10 dac.x1 volumio[2783]: info: Getting Spotify volume Mar 01 22:10:10 dac.x1 volumio[2783]: (node:2783) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 22:10:10 dac.x1 volumio[2783]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 01 22:10:10 dac.x1 volumio[2783]: (node:2783) 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: 385) Mar 01 22:10:10 dac.x1 volumio[2783]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Mar 01 22:10:10 dac.x1 volumio[2783]: info: CoreCommandRouter::volumioGetState Mar 01 22:10:10 dac.x1 volumio[2783]: info: CorePlayQueue::getTrack 1 Mar 01 22:10:10 dac.x1 volumio[2783]: info: Initializing connection to go-librespot Websocket Mar 01 22:10:10 dac.x1 volumio[2783]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 22:10:11 dac.x1 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 22:10:11 dac.x1 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 699. Mar 01 22:10:11 dac.x1 systemd[1]: Stopped go-librespot Daemon. Mar 01 22:10:11 dac.x1 go-librespot[23694]: go-librespot daemon starting... Mar 01 22:10:11 dac.x1 systemd[1]: Started go-librespot Daemon. Mar 01 22:10:11 dac.x1 go-librespot[23694]: time="2025-03-01T22:10:11+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 22:10:11 dac.x1 go-librespot[23694]: time="2025-03-01T22:10:11+08:00" level=debug msg="app state loaded" Mar 01 22:10:11 dac.x1 go-librespot[23694]: time="2025-03-01T22:10:11+08:00" level=debug msg="stored credentials not found" Mar 01 22:10:11 dac.x1 go-librespot[23694]: time="2025-03-01T22:10:11+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 22:10:12 dac.x1 go-librespot[23694]: time="2025-03-01T22:10:12+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 22:10:12 dac.x1 go-librespot[23694]: time="2025-03-01T22:10:12+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 01 22:10:12 dac.x1 go-librespot[23694]: time="2025-03-01T22:10:12+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 01 22:10:12 dac.x1 go-librespot[23694]: time="2025-03-01T22:10:12+08:00" level=info msg="zeroconf server listening on port 42417" Mar 01 22:10:13 dac.x1 go-librespot[23694]: time="2025-03-01T22:10:13+08:00" level=debug msg="obtained new client token: AACANw7eq8cuCv5n4j6Uu+2ex1bDZW86RZSk4PZeJuRgiHZTFZiJjnWLtTI6N85hHHwlR/AbVgGsB3aor/tMaMgtjGzvHEI5kxCjMMn5OARqXSkOD5MopzN5FR+nKiTkCEqK96J2lJPqg7g6Vhx0JApl3hgrQwKRSVbSh7cR6iVY85PSHPEV3Dpx9MRGQbn1Cd/ChCtXUhNy7RCEfo1KvlQcjybEY1U5hCBkjFQ8i6f/sAwVo3G7MmM=" Mar 01 22:10:13 dac.x1 go-librespot[23694]: time="2025-03-01T22:10:13+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 22:10:13 dac.x1 go-librespot[23694]: time="2025-03-01T22:10:13+08:00" level=debug msg="completed keyexchange" Mar 01 22:10:13 dac.x1 go-librespot[23694]: time="2025-03-01T22:10:13+08:00" level=debug msg="completed challenge" Mar 01 22:10:13 dac.x1 go-librespot[23694]: time="2025-03-01T22:10:13+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 22:10:13 dac.x1 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 22:10:13 dac.x1 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 22:10:13 dac.x1 wpa_supplicant[865]: wlan0: Failed to initiate sched scan Mar 01 22:10:13 dac.x1 volumio[2783]: info: Initializing connection to go-librespot Websocket Mar 01 22:10:13 dac.x1 volumio[2783]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 22:10:16 dac.x1 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 22:10:16 dac.x1 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 700. Mar 01 22:10:16 dac.x1 systemd[1]: Stopped go-librespot Daemon. Mar 01 22:10:16 dac.x1 systemd[1]: Started go-librespot Daemon. Mar 01 22:10:16 dac.x1 go-librespot[23746]: go-librespot daemon starting... Mar 01 22:10:16 dac.x1 go-librespot[23746]: time="2025-03-01T22:10:16+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 22:10:16 dac.x1 go-librespot[23746]: time="2025-03-01T22:10:16+08:00" level=debug msg="app state loaded" Mar 01 22:10:16 dac.x1 go-librespot[23746]: time="2025-03-01T22:10:16+08:00" level=debug msg="stored credentials not found" Mar 01 22:10:16 dac.x1 go-librespot[23746]: time="2025-03-01T22:10:16+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 22:10:16 dac.x1 volumio[2783]: info: Initializing connection to go-librespot Websocket Mar 01 22:10:16 dac.x1 go-librespot[23746]: time="2025-03-01T22:10:16+08:00" level=debug msg="new websocket client" Mar 01 22:10:16 dac.x1 volumio[2783]: info: Connection to go-librespot Websocket established Mar 01 22:10:18 dac.x1 go-librespot[23746]: time="2025-03-01T22:10:18+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 22:10:18 dac.x1 go-librespot[23746]: time="2025-03-01T22:10:18+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 01 22:10:18 dac.x1 go-librespot[23746]: time="2025-03-01T22:10:18+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 01 22:10:18 dac.x1 go-librespot[23746]: time="2025-03-01T22:10:18+08:00" level=info msg="zeroconf server listening on port 34361" Mar 01 22:10:18 dac.x1 go-librespot[23746]: time="2025-03-01T22:10:18+08:00" level=debug msg="obtained new client token: AAB+91SOQdqXaQVkNPr0BMYhWKU1ZOv6ugrm6XvzY0WHQsSpFi6r6e8RwW9MGRKK5Db1IuwpmiQFNpSHFMDnXqY2MVoGa9ZR8GObe/Dfr/nkTWGCKvvA7/fauFjEMvgNgiaSHldU+CiUaKluAPB4ppOp2Icm6jEGQVltAr2Qas1IR1QrHXy/gTV6rtpWmak4pEGKI0PZNZS01TOqQKrTBBhH/oQf1EzHR56h3zd1yt69e95nk+UG8Zw=" Mar 01 22:10:18 dac.x1 go-librespot[23746]: time="2025-03-01T22:10:18+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 22:10:19 dac.x1 volumio[2783]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 01 22:10:19 dac.x1 volumio[2783]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 01 22:10:19 dac.x1 volumio[2783]: info: Discovery: Getting this device information Mar 01 22:10:19 dac.x1 volumio[2783]: info: CoreCommandRouter::volumioGetState Mar 01 22:10:19 dac.x1 volumio[2783]: info: CorePlayQueue::getTrack 1 Mar 01 22:10:19 dac.x1 volumio[2783]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 01 22:10:19 dac.x1 go-librespot[23746]: time="2025-03-01T22:10:19+08:00" level=debug msg="completed keyexchange" Mar 01 22:10:19 dac.x1 go-librespot[23746]: time="2025-03-01T22:10:19+08:00" level=debug msg="completed challenge" Mar 01 22:10:19 dac.x1 go-librespot[23746]: time="2025-03-01T22:10:19+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 22:10:19 dac.x1 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 22:10:19 dac.x1 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 22:10:19 dac.x1 volumio[2783]: info: Connection to go-librespot Websocket closed Mar 01 22:10:19 dac.x1 volumio[2783]: info: Getting Spotify volume Mar 01 22:10:19 dac.x1 volumio[2783]: (node:2783) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 22:10:19 dac.x1 volumio[2783]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 01 22:10:19 dac.x1 volumio[2783]: (node:2783) 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: 386) Mar 01 22:10:19 dac.x1 volumio[2783]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Mar 01 22:10:19 dac.x1 volumio[2783]: info: CoreCommandRouter::volumioGetState Mar 01 22:10:19 dac.x1 volumio[2783]: info: CorePlayQueue::getTrack 1 Mar 01 22:10:22 dac.x1 wpa_supplicant[865]: wlan0: Failed to initiate sched scan Mar 01 22:10:22 dac.x1 volumio[2783]: info: Initializing connection to go-librespot Websocket Mar 01 22:10:22 dac.x1 volumio[2783]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 22:10:22 dac.x1 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 22:10:22 dac.x1 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 701. Mar 01 22:10:22 dac.x1 systemd[1]: Stopped go-librespot Daemon. Mar 01 22:10:22 dac.x1 systemd[1]: Started go-librespot Daemon. Mar 01 22:10:22 dac.x1 go-librespot[23769]: go-librespot daemon starting... Mar 01 22:10:22 dac.x1 go-librespot[23769]: time="2025-03-01T22:10:22+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 22:10:22 dac.x1 go-librespot[23769]: time="2025-03-01T22:10:22+08:00" level=debug msg="app state loaded" Mar 01 22:10:22 dac.x1 go-librespot[23769]: time="2025-03-01T22:10:22+08:00" level=debug msg="stored credentials not found" Mar 01 22:10:22 dac.x1 go-librespot[23769]: time="2025-03-01T22:10:22+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 22:10:23 dac.x1 go-librespot[23769]: time="2025-03-01T22:10:23+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 22:10:23 dac.x1 go-librespot[23769]: time="2025-03-01T22:10:23+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 01 22:10:23 dac.x1 go-librespot[23769]: time="2025-03-01T22:10:23+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 01 22:10:23 dac.x1 go-librespot[23769]: time="2025-03-01T22:10:23+08:00" level=info msg="zeroconf server listening on port 45105" Mar 01 22:10:24 dac.x1 go-librespot[23769]: time="2025-03-01T22:10:24+08:00" level=debug msg="obtained new client token: AABEhWxK4lhiOcd1ogaasXQL8nYESNUPBgxpbFnrheX3fu4t8gPlL9bpCmec4F0xLf3KYL+X/Ngsb9B2VNc97ncP0bvD9zX9vvS9UyLixWaRqu/tbNo7Tfuk/O3OIZ2/U/3lqWEb25DC7BSRjbh217a+FkoIcSEXbwlbjF78W2xR6Ml7llLBhKHp69TcC/vJU4Q0JZUrh4ESwbpJQnXzgUHnuGgd96YVMa11O0LFwEP3tQ9GUwm8" Mar 01 22:10:24 dac.x1 go-librespot[23769]: time="2025-03-01T22:10:24+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 22:10:24 dac.x1 go-librespot[23769]: time="2025-03-01T22:10:24+08:00" level=debug msg="completed keyexchange" Mar 01 22:10:24 dac.x1 go-librespot[23769]: time="2025-03-01T22:10:24+08:00" level=debug msg="completed challenge" Mar 01 22:10:24 dac.x1 go-librespot[23769]: time="2025-03-01T22:10:24+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 22:10:24 dac.x1 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 22:10:24 dac.x1 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 22:10:25 dac.x1 volumio[2783]: info: Initializing connection to go-librespot Websocket Mar 01 22:10:25 dac.x1 volumio[2783]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 22:10:28 dac.x1 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 22:10:28 dac.x1 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 702. Mar 01 22:10:28 dac.x1 systemd[1]: Stopped go-librespot Daemon. Mar 01 22:10:28 dac.x1 systemd[1]: Started go-librespot Daemon. Mar 01 22:10:28 dac.x1 go-librespot[23780]: go-librespot daemon starting... Mar 01 22:10:28 dac.x1 go-librespot[23780]: time="2025-03-01T22:10:28+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 22:10:28 dac.x1 go-librespot[23780]: time="2025-03-01T22:10:28+08:00" level=debug msg="app state loaded" Mar 01 22:10:28 dac.x1 go-librespot[23780]: time="2025-03-01T22:10:28+08:00" level=debug msg="stored credentials not found" Mar 01 22:10:28 dac.x1 go-librespot[23780]: time="2025-03-01T22:10:28+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 22:10:28 dac.x1 volumio[2783]: info: Initializing connection to go-librespot Websocket Mar 01 22:10:28 dac.x1 go-librespot[23780]: time="2025-03-01T22:10:28+08:00" level=debug msg="new websocket client" Mar 01 22:10:28 dac.x1 volumio[2783]: info: Connection to go-librespot Websocket established Mar 01 22:10:28 dac.x1 go-librespot[23780]: time="2025-03-01T22:10:28+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 22:10:28 dac.x1 go-librespot[23780]: time="2025-03-01T22:10:28+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 01 22:10:28 dac.x1 go-librespot[23780]: time="2025-03-01T22:10:28+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 01 22:10:28 dac.x1 go-librespot[23780]: time="2025-03-01T22:10:28+08:00" level=info msg="zeroconf server listening on port 39161" Mar 01 22:10:29 dac.x1 go-librespot[23780]: time="2025-03-01T22:10:29+08:00" level=debug msg="obtained new client token: AAAgttxErjZrUUrQYTiwgci+qVMsNUeG6/exthjau4E54V8UtJEZDqRRM88uQYcrJDET+SxHxX8anfboWP6QRX15fZ8rSXpbcoMrvfP9jblDT8uYvEM5WARflhI680CthFIFgrIHbuFNwP2zfM3ZSp/O0tFlCE11JMaSx6FDnXoqqDQLSYFxW7k/x4T2FAlKJQ5FkLys8loDqBqBI3aMpaIVHt14ub1xv5tvvZxGKHGSA/PLiPqtm4s=" Mar 01 22:10:29 dac.x1 go-librespot[23780]: time="2025-03-01T22:10:29+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 22:10:29 dac.x1 go-librespot[23780]: time="2025-03-01T22:10:29+08:00" level=debug msg="completed keyexchange" Mar 01 22:10:29 dac.x1 go-librespot[23780]: time="2025-03-01T22:10:29+08:00" level=debug msg="completed challenge" Mar 01 22:10:29 dac.x1 go-librespot[23780]: time="2025-03-01T22:10:29+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 22:10:29 dac.x1 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 22:10:29 dac.x1 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 22:10:29 dac.x1 volumio[2783]: info: Connection to go-librespot Websocket closed Mar 01 22:10:30 dac.x1 wpa_supplicant[865]: wlan0: Failed to initiate sched scan Mar 01 22:10:31 dac.x1 volumio[2783]: info: Getting Spotify volume Mar 01 22:10:31 dac.x1 volumio[2783]: (node:2783) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 22:10:31 dac.x1 volumio[2783]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 01 22:10:31 dac.x1 volumio[2783]: (node:2783) 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: 387) Mar 01 22:10:31 dac.x1 volumio[2783]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Mar 01 22:10:31 dac.x1 volumio[2783]: info: CoreCommandRouter::volumioGetState Mar 01 22:10:31 dac.x1 volumio[2783]: info: CorePlayQueue::getTrack 1 Mar 01 22:10:32 dac.x1 volumio[2783]: info: Initializing connection to go-librespot Websocket Mar 01 22:10:32 dac.x1 volumio[2783]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 22:10:32 dac.x1 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 22:10:32 dac.x1 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 703. Mar 01 22:10:32 dac.x1 systemd[1]: Stopped go-librespot Daemon. Mar 01 22:10:32 dac.x1 systemd[1]: Started go-librespot Daemon. Mar 01 22:10:32 dac.x1 go-librespot[23804]: go-librespot daemon starting... Mar 01 22:10:32 dac.x1 go-librespot[23804]: time="2025-03-01T22:10:32+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 22:10:32 dac.x1 go-librespot[23804]: time="2025-03-01T22:10:32+08:00" level=debug msg="app state loaded" Mar 01 22:10:32 dac.x1 go-librespot[23804]: time="2025-03-01T22:10:32+08:00" level=debug msg="stored credentials not found" Mar 01 22:10:32 dac.x1 go-librespot[23804]: time="2025-03-01T22:10:32+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 22:10:33 dac.x1 go-librespot[23804]: time="2025-03-01T22:10:33+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 22:10:33 dac.x1 go-librespot[23804]: time="2025-03-01T22:10:33+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 01 22:10:33 dac.x1 go-librespot[23804]: time="2025-03-01T22:10:33+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 01 22:10:33 dac.x1 go-librespot[23804]: time="2025-03-01T22:10:33+08:00" level=info msg="zeroconf server listening on port 43715" Mar 01 22:10:35 dac.x1 volumio[2783]: info: Initializing connection to go-librespot Websocket Mar 01 22:10:35 dac.x1 go-librespot[23804]: time="2025-03-01T22:10:35+08:00" level=debug msg="new websocket client" Mar 01 22:10:35 dac.x1 volumio[2783]: info: Connection to go-librespot Websocket established Mar 01 22:10:38 dac.x1 go-librespot[23804]: time="2025-03-01T22:10:38+08:00" level=debug msg="obtained new client token: AAATQx9olLXGqedTKXGhVcXIRxuAa/yB01swG9HMynCMB9grPiaW6Ov4Nl2z0C3ZDM5ldmUXM0HfP2i6jImnYQcGd2Z9LzvSc0yvhHk2ANiLPHuxrFtCb1VXg2gcaiqXISLZzozZaB9xBJRG1QMNlg1PTq2CDWIHvFHOqfcReINUukC6fMJ5sgZtXok+sQgqcEWGjuIj0jl52tryj+dnBOERqG/2lWUwDlGOLKmcGsrDbu01p4jz2xQ=" Mar 01 22:10:38 dac.x1 volumio[2783]: info: Getting Spotify volume Mar 01 22:10:38 dac.x1 volumio[2783]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Mar 01 22:10:38 dac.x1 volumio[2783]: info: CoreCommandRouter::volumioGetState Mar 01 22:10:38 dac.x1 volumio[2783]: info: CorePlayQueue::getTrack 1 Mar 01 22:10:39 dac.x1 wpa_supplicant[865]: wlan0: Failed to initiate sched scan Mar 01 22:10:39 dac.x1 go-librespot[23804]: time="2025-03-01T22:10:39+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 22:10:39 dac.x1 go-librespot[23804]: time="2025-03-01T22:10:39+08:00" level=debug msg="completed keyexchange" Mar 01 22:10:39 dac.x1 go-librespot[23804]: time="2025-03-01T22:10:39+08:00" level=debug msg="completed challenge" Mar 01 22:10:39 dac.x1 go-librespot[23804]: time="2025-03-01T22:10:39+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 22:10:39 dac.x1 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 22:10:39 dac.x1 volumio[2783]: (node:2783) UnhandledPromiseRejectionWarning: Error: socket hang up Mar 01 22:10:39 dac.x1 volumio[2783]: at connResetException (internal/errors.js:607:14) Mar 01 22:10:39 dac.x1 volumio[2783]: at Socket.socketOnEnd (_http_client.js:493:23) Mar 01 22:10:39 dac.x1 volumio[2783]: at Socket.emit (events.js:327:22) Mar 01 22:10:39 dac.x1 volumio[2783]: at endReadableNT (internal/streams/readable.js:1327:12) Mar 01 22:10:39 dac.x1 volumio[2783]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Mar 01 22:10:39 dac.x1 volumio[2783]: (node:2783) 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: 388) Mar 01 22:10:39 dac.x1 volumio[2783]: info: Connection to go-librespot Websocket closed Mar 01 22:10:39 dac.x1 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 22:10:39 dac.x1 volumio[2783]: error: MyVolumio got a network error: A network error (such as timeout, interrupted connection or unreachable host) has occurred. Mar 01 22:10:39 dac.x1 volumio[2783]: info: Retrying Login Due to Network Error Mar 01 22:10:42 dac.x1 volumio[2783]: info: Initializing connection to go-librespot Websocket Mar 01 22:10:42 dac.x1 volumio[2783]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 22:10:42 dac.x1 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 22:10:42 dac.x1 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 704. Mar 01 22:10:42 dac.x1 systemd[1]: Stopped go-librespot Daemon. Mar 01 22:10:42 dac.x1 systemd[1]: Started go-librespot Daemon. Mar 01 22:10:42 dac.x1 go-librespot[23830]: go-librespot daemon starting... Mar 01 22:10:42 dac.x1 go-librespot[23830]: time="2025-03-01T22:10:42+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 22:10:42 dac.x1 go-librespot[23830]: time="2025-03-01T22:10:42+08:00" level=debug msg="app state loaded" Mar 01 22:10:42 dac.x1 go-librespot[23830]: time="2025-03-01T22:10:42+08:00" level=debug msg="stored credentials not found" Mar 01 22:10:42 dac.x1 go-librespot[23830]: time="2025-03-01T22:10:42+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 22:10:43 dac.x1 go-librespot[23830]: time="2025-03-01T22:10:43+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 01 22:10:43 dac.x1 go-librespot[23830]: time="2025-03-01T22:10:43+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 01 22:10:43 dac.x1 go-librespot[23830]: time="2025-03-01T22:10:43+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 01 22:10:43 dac.x1 go-librespot[23830]: time="2025-03-01T22:10:43+08:00" level=info msg="zeroconf server listening on port 36099" Mar 01 22:10:44 dac.x1 go-librespot[23830]: time="2025-03-01T22:10:44+08:00" level=debug msg="obtained new client token: AAC8cx+6SUbVShg7dhT21jwrDkFVwywyE36+pfCCNDScGn7P41R13Dp2VQITIcUHeTTriybZJW0HJw65uG3sCVTq+SWBs4eF51BA81ruURNJmZ8VT62aGmAYXfq/g028eBcYCi1Z1WgRakYkEHdKOQ6jfzvpw1eL80pkEDMnr28gKEDfo5/aNj4ImjoTz+jF4TKzF32TMXOUuBqgYB5M/LQyR7CY/i2TTKt2xIeq7gxenSiu8GVD" Mar 01 22:10:44 dac.x1 go-librespot[23830]: time="2025-03-01T22:10:44+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 22:10:44 dac.x1 go-librespot[23830]: time="2025-03-01T22:10:44+08:00" level=debug msg="completed keyexchange" Mar 01 22:10:44 dac.x1 go-librespot[23830]: time="2025-03-01T22:10:44+08:00" level=debug msg="completed challenge" Mar 01 22:10:44 dac.x1 go-librespot[23830]: time="2025-03-01T22:10:44+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 22:10:44 dac.x1 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 22:10:44 dac.x1 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 22:10:45 dac.x1 volumio[2783]: info: Initializing connection to go-librespot Websocket Mar 01 22:10:45 dac.x1 volumio[2783]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 22:10:47 dac.x1 wpa_supplicant[865]: wlan0: Failed to initiate sched scan Mar 01 22:10:47 dac.x1 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 22:10:47 dac.x1 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 705. Mar 01 22:10:47 dac.x1 systemd[1]: Stopped go-librespot Daemon. Mar 01 22:10:47 dac.x1 systemd[1]: Started go-librespot Daemon. Mar 01 22:10:47 dac.x1 go-librespot[23843]: go-librespot daemon starting... Mar 01 22:10:47 dac.x1 go-librespot[23843]: time="2025-03-01T22:10:47+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 22:10:47 dac.x1 go-librespot[23843]: time="2025-03-01T22:10:47+08:00" level=debug msg="app state loaded" Mar 01 22:10:47 dac.x1 go-librespot[23843]: time="2025-03-01T22:10:47+08:00" level=debug msg="stored credentials not found" Mar 01 22:10:47 dac.x1 go-librespot[23843]: time="2025-03-01T22:10:47+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 22:10:48 dac.x1 volumio[2783]: info: Initializing connection to go-librespot Websocket Mar 01 22:10:48 dac.x1 go-librespot[23843]: time="2025-03-01T22:10:48+08:00" level=debug msg="new websocket client" Mar 01 22:10:48 dac.x1 volumio[2783]: info: Connection to go-librespot Websocket established Mar 01 22:10:49 dac.x1 go-librespot[23843]: time="2025-03-01T22:10:49+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 22:10:49 dac.x1 go-librespot[23843]: time="2025-03-01T22:10:49+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 01 22:10:49 dac.x1 go-librespot[23843]: time="2025-03-01T22:10:49+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 01 22:10:49 dac.x1 go-librespot[23843]: time="2025-03-01T22:10:49+08:00" level=info msg="zeroconf server listening on port 34065" Mar 01 22:10:49 dac.x1 volumio[2783]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 01 22:10:49 dac.x1 volumio[2783]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 01 22:10:49 dac.x1 volumio[2783]: info: Discovery: Getting this device information Mar 01 22:10:49 dac.x1 volumio[2783]: info: CoreCommandRouter::volumioGetState Mar 01 22:10:49 dac.x1 volumio[2783]: info: CorePlayQueue::getTrack 1 Mar 01 22:10:49 dac.x1 volumio[2783]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 01 22:10:49 dac.x1 volumio[2783]: info: MyVolumio login type: Token Mar 01 22:10:49 dac.x1 go-librespot[23843]: time="2025-03-01T22:10:49+08:00" level=debug msg="obtained new client token: AAB9TLlDaIWJr+rpJRJqdYGp0j9pZCDqk4VmGsckyf5WzCSRHW85OFftI/FAIv9BfzCheoalEeuegdGgc7fVJk8Qj2Dz1Q0A1swN7jdSxAw7gk5Lf6SRV0c+25SCkcrq9MKDQPqxWR6ndlXLH/3HobDG7nIgc9WsiigFOkrSp/Y2fw0fp4+BZhbo25aPWUw5jdJHXWvqVYgzAqjx6xWr2Lv/YVTWuZy50jkZdNhhzez7X4L03eiMh/c=" Mar 01 22:10:50 dac.x1 go-librespot[23843]: time="2025-03-01T22:10:50+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 22:10:50 dac.x1 go-librespot[23843]: time="2025-03-01T22:10:50+08:00" level=debug msg="completed keyexchange" Mar 01 22:10:50 dac.x1 go-librespot[23843]: time="2025-03-01T22:10:50+08:00" level=debug msg="completed challenge" Mar 01 22:10:50 dac.x1 go-librespot[23843]: time="2025-03-01T22:10:50+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 22:10:50 dac.x1 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 22:10:50 dac.x1 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 22:10:50 dac.x1 volumio[2783]: info: Connection to go-librespot Websocket closed Mar 01 22:10:51 dac.x1 volumio[2783]: info: Getting Spotify volume Mar 01 22:10:51 dac.x1 volumio[2783]: (node:2783) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 22:10:51 dac.x1 volumio[2783]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 01 22:10:51 dac.x1 volumio[2783]: (node:2783) 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: 389) Mar 01 22:10:51 dac.x1 volumio[2783]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Mar 01 22:10:51 dac.x1 volumio[2783]: info: CoreCommandRouter::volumioGetState Mar 01 22:10:51 dac.x1 volumio[2783]: info: CorePlayQueue::getTrack 1 Mar 01 22:10:53 dac.x1 volumio[2783]: info: Initializing connection to go-librespot Websocket Mar 01 22:10:53 dac.x1 volumio[2783]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 22:10:53 dac.x1 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 22:10:53 dac.x1 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 706. Mar 01 22:10:53 dac.x1 systemd[1]: Stopped go-librespot Daemon. Mar 01 22:10:53 dac.x1 systemd[1]: Started go-librespot Daemon. Mar 01 22:10:53 dac.x1 go-librespot[23867]: go-librespot daemon starting... Mar 01 22:10:53 dac.x1 go-librespot[23867]: time="2025-03-01T22:10:53+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 22:10:53 dac.x1 go-librespot[23867]: time="2025-03-01T22:10:53+08:00" level=debug msg="app state loaded" Mar 01 22:10:53 dac.x1 go-librespot[23867]: time="2025-03-01T22:10:53+08:00" level=debug msg="stored credentials not found" Mar 01 22:10:53 dac.x1 go-librespot[23867]: time="2025-03-01T22:10:53+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 22:10:54 dac.x1 go-librespot[23867]: time="2025-03-01T22:10:54+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 22:10:54 dac.x1 go-librespot[23867]: time="2025-03-01T22:10:54+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 01 22:10:54 dac.x1 go-librespot[23867]: time="2025-03-01T22:10:54+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 01 22:10:54 dac.x1 go-librespot[23867]: time="2025-03-01T22:10:54+08:00" level=info msg="zeroconf server listening on port 36747" Mar 01 22:10:55 dac.x1 wpa_supplicant[865]: wlan0: Failed to initiate sched scan Mar 01 22:10:56 dac.x1 volumio[2783]: info: Initializing connection to go-librespot Websocket Mar 01 22:10:56 dac.x1 go-librespot[23867]: time="2025-03-01T22:10:56+08:00" level=debug msg="new websocket client" Mar 01 22:10:56 dac.x1 volumio[2783]: info: Connection to go-librespot Websocket established Mar 01 22:10:56 dac.x1 go-librespot[23867]: time="2025-03-01T22:10:56+08:00" level=debug msg="obtained new client token: AAAhFzcOYQzRaV1u6IaR8JfTNSLsP6xUyb0CKLE0xwuE0AiG9gUfOrA/nE7pywTP1wDw83WS3xFMuRCJyiP3rV5s2WdiW7O2oqG0XgGvarmj8kSsw1Wneslvy8U8CDsyh2Kfjl21XoUX4HpzR+xck613mEDlz0bBFMq0QZPAwQ7oTrrw8jN27DYjBri8PQeO1y+Gy+uLVt/NKgIVsgfpm12fm90FLBlvh2DLAKqtWuMTjWxRb0av" Mar 01 22:10:56 dac.x1 go-librespot[23867]: time="2025-03-01T22:10:56+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 22:10:56 dac.x1 go-librespot[23867]: time="2025-03-01T22:10:56+08:00" level=debug msg="completed keyexchange" Mar 01 22:10:56 dac.x1 go-librespot[23867]: time="2025-03-01T22:10:56+08:00" level=debug msg="completed challenge" Mar 01 22:10:56 dac.x1 go-librespot[23867]: time="2025-03-01T22:10:56+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 22:10:56 dac.x1 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 22:10:56 dac.x1 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 22:10:56 dac.x1 volumio[2783]: info: Connection to go-librespot Websocket closed Mar 01 22:10:59 dac.x1 volumio[2783]: info: Getting Spotify volume Mar 01 22:10:59 dac.x1 volumio[2783]: (node:2783) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 22:10:59 dac.x1 volumio[2783]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 01 22:10:59 dac.x1 volumio[2783]: (node:2783) 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: 390) Mar 01 22:10:59 dac.x1 volumio[2783]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Mar 01 22:10:59 dac.x1 volumio[2783]: info: CoreCommandRouter::volumioGetState Mar 01 22:10:59 dac.x1 volumio[2783]: info: CorePlayQueue::getTrack 1 Mar 01 22:10:59 dac.x1 volumio[2783]: info: Initializing connection to go-librespot Websocket Mar 01 22:10:59 dac.x1 volumio[2783]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 22:10:59 dac.x1 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 22:10:59 dac.x1 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 707. Mar 01 22:10:59 dac.x1 systemd[1]: Stopped go-librespot Daemon. Mar 01 22:10:59 dac.x1 systemd[1]: Started go-librespot Daemon. Mar 01 22:10:59 dac.x1 go-librespot[23878]: go-librespot daemon starting... Mar 01 22:10:59 dac.x1 go-librespot[23878]: time="2025-03-01T22:10:59+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 22:10:59 dac.x1 go-librespot[23878]: time="2025-03-01T22:10:59+08:00" level=debug msg="app state loaded" Mar 01 22:10:59 dac.x1 go-librespot[23878]: time="2025-03-01T22:10:59+08:00" level=debug msg="stored credentials not found" Mar 01 22:10:59 dac.x1 go-librespot[23878]: time="2025-03-01T22:10:59+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 22:11:01 dac.x1 go-librespot[23878]: time="2025-03-01T22:11:01+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 22:11:01 dac.x1 go-librespot[23878]: time="2025-03-01T22:11:01+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 01 22:11:01 dac.x1 go-librespot[23878]: time="2025-03-01T22:11:01+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 01 22:11:01 dac.x1 go-librespot[23878]: time="2025-03-01T22:11:01+08:00" level=info msg="zeroconf server listening on port 40965" Mar 01 22:11:01 dac.x1 go-librespot[23878]: time="2025-03-01T22:11:01+08:00" level=debug msg="obtained new client token: AACPeGvFClEA5yxiNiuON772vYoMLgV1pzf10e/ue2i5BF9n/Sk7F4r3PFzTZUW21vlA9MjAB+bFdVW7PPIvJ1ft3oJCkgy3inqZtPjYFBrY1Lu76UnWjXH/8E1vW/hkeckUSEdVDM+bFDZd+1VIs368cgcxP5BGjggOBoDuUH6V0JlD+q6NHDvo6+ApgPbcHUaDjtdiBV20vpH8HlAzrlf79c5K8U2ramMTcjBE7w50TVkxqfukWyI=" Mar 01 22:11:01 dac.x1 go-librespot[23878]: time="2025-03-01T22:11:01+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 22:11:01 dac.x1 go-librespot[23878]: time="2025-03-01T22:11:01+08:00" level=debug msg="completed keyexchange" Mar 01 22:11:01 dac.x1 go-librespot[23878]: time="2025-03-01T22:11:01+08:00" level=debug msg="completed challenge" Mar 01 22:11:01 dac.x1 go-librespot[23878]: time="2025-03-01T22:11:01+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 22:11:01 dac.x1 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 22:11:01 dac.x1 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 22:11:02 dac.x1 volumio[2783]: info: Initializing connection to go-librespot Websocket Mar 01 22:11:02 dac.x1 volumio[2783]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 22:11:04 dac.x1 wpa_supplicant[865]: wlan0: Failed to initiate sched scan Mar 01 22:11:04 dac.x1 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 22:11:04 dac.x1 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 708. Mar 01 22:11:04 dac.x1 systemd[1]: Stopped go-librespot Daemon. Mar 01 22:11:04 dac.x1 systemd[1]: Started go-librespot Daemon. Mar 01 22:11:04 dac.x1 go-librespot[23900]: go-librespot daemon starting... Mar 01 22:11:04 dac.x1 go-librespot[23900]: time="2025-03-01T22:11:04+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 22:11:04 dac.x1 go-librespot[23900]: time="2025-03-01T22:11:04+08:00" level=debug msg="app state loaded" Mar 01 22:11:04 dac.x1 go-librespot[23900]: time="2025-03-01T22:11:04+08:00" level=debug msg="stored credentials not found" Mar 01 22:11:04 dac.x1 go-librespot[23900]: time="2025-03-01T22:11:04+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 22:11:05 dac.x1 volumio[2783]: info: Initializing connection to go-librespot Websocket Mar 01 22:11:05 dac.x1 go-librespot[23900]: time="2025-03-01T22:11:05+08:00" level=debug msg="new websocket client" Mar 01 22:11:05 dac.x1 volumio[2783]: info: Connection to go-librespot Websocket established Mar 01 22:11:05 dac.x1 go-librespot[23900]: time="2025-03-01T22:11:05+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 22:11:05 dac.x1 go-librespot[23900]: time="2025-03-01T22:11:05+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 01 22:11:05 dac.x1 go-librespot[23900]: time="2025-03-01T22:11:05+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 01 22:11:05 dac.x1 go-librespot[23900]: time="2025-03-01T22:11:05+08:00" level=info msg="zeroconf server listening on port 37619" Mar 01 22:11:06 dac.x1 go-librespot[23900]: time="2025-03-01T22:11:06+08:00" level=debug msg="obtained new client token: AABkhdGGKnapLF2H+TDzj7idvuhX6Vwi6vEtvMZDpIubiY13tf2ky5ix1ja8YvaEmCDuqZHtO+87k/kYkF2PeB56KLAj98Y/vrmdS97RxuO/OulIsvbrnLHTTa/8s7jsogfStqeZyQbzCjEY91X5/uhEZQXYclZUqJmw82ZiCh5H/GutPxcI9zqQTi1kOgsBuxO68ZUDFbfPp7zVvrbpnEnOhRUBKPCQcNEXM/6usbYNoncuL0AN" Mar 01 22:11:06 dac.x1 go-librespot[23900]: time="2025-03-01T22:11:06+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 22:11:06 dac.x1 go-librespot[23900]: time="2025-03-01T22:11:06+08:00" level=debug msg="completed keyexchange" Mar 01 22:11:06 dac.x1 go-librespot[23900]: time="2025-03-01T22:11:06+08:00" level=debug msg="completed challenge" Mar 01 22:11:06 dac.x1 go-librespot[23900]: time="2025-03-01T22:11:06+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 22:11:06 dac.x1 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 22:11:06 dac.x1 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 22:11:06 dac.x1 volumio[2783]: info: Connection to go-librespot Websocket closed Mar 01 22:11:08 dac.x1 volumio[2783]: info: Getting Spotify volume Mar 01 22:11:08 dac.x1 volumio[2783]: (node:2783) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 22:11:08 dac.x1 volumio[2783]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 01 22:11:08 dac.x1 volumio[2783]: (node:2783) 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: 391) Mar 01 22:11:08 dac.x1 volumio[2783]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Mar 01 22:11:08 dac.x1 volumio[2783]: info: CoreCommandRouter::volumioGetState Mar 01 22:11:08 dac.x1 volumio[2783]: info: CorePlayQueue::getTrack 1 Mar 01 22:11:09 dac.x1 volumio[2783]: info: Initializing connection to go-librespot Websocket Mar 01 22:11:09 dac.x1 volumio[2783]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 22:11:09 dac.x1 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 22:11:09 dac.x1 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 709. Mar 01 22:11:09 dac.x1 systemd[1]: Stopped go-librespot Daemon. Mar 01 22:11:09 dac.x1 systemd[1]: Started go-librespot Daemon. Mar 01 22:11:09 dac.x1 go-librespot[23912]: go-librespot daemon starting... Mar 01 22:11:09 dac.x1 go-librespot[23912]: time="2025-03-01T22:11:09+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 22:11:09 dac.x1 go-librespot[23912]: time="2025-03-01T22:11:09+08:00" level=debug msg="app state loaded" Mar 01 22:11:09 dac.x1 go-librespot[23912]: time="2025-03-01T22:11:09+08:00" level=debug msg="stored credentials not found" Mar 01 22:11:09 dac.x1 go-librespot[23912]: time="2025-03-01T22:11:09+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 22:11:11 dac.x1 go-librespot[23912]: time="2025-03-01T22:11:11+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 22:11:11 dac.x1 go-librespot[23912]: time="2025-03-01T22:11:11+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 01 22:11:11 dac.x1 go-librespot[23912]: time="2025-03-01T22:11:11+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 01 22:11:11 dac.x1 go-librespot[23912]: time="2025-03-01T22:11:11+08:00" level=info msg="zeroconf server listening on port 35051" Mar 01 22:11:11 dac.x1 go-librespot[23912]: time="2025-03-01T22:11:11+08:00" level=debug msg="obtained new client token: AABbzItHwBo4//LGxMyxQoRE8TtpqneccTOE+iJbnNcinW9B3didLrW77lFAa7UQahJqDeKKSVgVNMrVDz9OzYAUoTZZlUh+K+KWfJiPBKWI4mu9d4p3ZTYsMCnFWgvgtVRf5hZnJZX9EtQ45lny4KOEPuCzqB4r1Bx3gFWvXJoRTMWLgRrNeOU9y6RSE5TfVELJYiYUHLSyV5nIuMAk9zGl5kpIAPwGKB2HgDuIjRRI63q3Z1W2nyM=" Mar 01 22:11:11 dac.x1 go-librespot[23912]: time="2025-03-01T22:11:11+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 22:11:11 dac.x1 go-librespot[23912]: time="2025-03-01T22:11:11+08:00" level=debug msg="completed keyexchange" Mar 01 22:11:11 dac.x1 go-librespot[23912]: time="2025-03-01T22:11:11+08:00" level=debug msg="completed challenge" Mar 01 22:11:11 dac.x1 go-librespot[23912]: time="2025-03-01T22:11:11+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 22:11:11 dac.x1 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 22:11:11 dac.x1 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 22:11:12 dac.x1 volumio[2783]: info: Initializing connection to go-librespot Websocket Mar 01 22:11:12 dac.x1 volumio[2783]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 22:11:12 dac.x1 wpa_supplicant[865]: wlan0: Failed to initiate sched scan Mar 01 22:11:14 dac.x1 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 22:11:14 dac.x1 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 710. Mar 01 22:11:14 dac.x1 systemd[1]: Stopped go-librespot Daemon. Mar 01 22:11:14 dac.x1 systemd[1]: Started go-librespot Daemon. Mar 01 22:11:14 dac.x1 go-librespot[23975]: go-librespot daemon starting... Mar 01 22:11:14 dac.x1 go-librespot[23975]: time="2025-03-01T22:11:14+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 22:11:14 dac.x1 go-librespot[23975]: time="2025-03-01T22:11:14+08:00" level=debug msg="app state loaded" Mar 01 22:11:14 dac.x1 go-librespot[23975]: time="2025-03-01T22:11:14+08:00" level=debug msg="stored credentials not found" Mar 01 22:11:14 dac.x1 go-librespot[23975]: time="2025-03-01T22:11:14+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 22:11:15 dac.x1 volumio[2783]: info: Initializing connection to go-librespot Websocket Mar 01 22:11:15 dac.x1 go-librespot[23975]: time="2025-03-01T22:11:15+08:00" level=debug msg="new websocket client" Mar 01 22:11:15 dac.x1 volumio[2783]: info: Connection to go-librespot Websocket established Mar 01 22:11:18 dac.x1 volumio[2783]: info: Getting Spotify volume Mar 01 22:11:18 dac.x1 volumio[2783]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Mar 01 22:11:18 dac.x1 volumio[2783]: info: CoreCommandRouter::volumioGetState Mar 01 22:11:18 dac.x1 volumio[2783]: info: CorePlayQueue::getTrack 1 Mar 01 22:11:19 dac.x1 volumio[2783]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 01 22:11:19 dac.x1 volumio[2783]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 01 22:11:19 dac.x1 volumio[2783]: info: Discovery: Getting this device information Mar 01 22:11:19 dac.x1 volumio[2783]: info: CoreCommandRouter::volumioGetState Mar 01 22:11:19 dac.x1 volumio[2783]: info: CorePlayQueue::getTrack 1 Mar 01 22:11:19 dac.x1 volumio[2783]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 01 22:11:19 dac.x1 go-librespot[23975]: time="2025-03-01T22:11:19+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 01 22:11:19 dac.x1 go-librespot[23975]: time="2025-03-01T22:11:19+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 01 22:11:19 dac.x1 go-librespot[23975]: time="2025-03-01T22:11:19+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 01 22:11:19 dac.x1 go-librespot[23975]: time="2025-03-01T22:11:19+08:00" level=info msg="zeroconf server listening on port 41437" Mar 01 22:11:19 dac.x1 volumio[2783]: error: MyVolumio got a network error: A network error (such as timeout, interrupted connection or unreachable host) has occurred. Mar 01 22:11:19 dac.x1 volumio[2783]: info: Retrying Login Due to Network Error Mar 01 22:11:20 dac.x1 go-librespot[23975]: time="2025-03-01T22:11:20+08:00" level=debug msg="obtained new client token: AACvKo8lb9nkqr98SvZLTgccVFkMpoVT9jcQMEuZdyO00kLokp4XtZnnkRVEl7WYtVxam6JEK1Lwc2rSXcUHXx4jyD3X/Xjb/HsgxtR2XtSjJfF4u3j5rScqDBgWJ5dWt+XCnbND8Y4Sq1sDV1/CjZNlJ6jVl6DgPPEL6FNtDFyTBWtHvbphVhPZZevqefItQG0EgsrH2tCCLsYoOhLAqcuErYN/IZAt6MHp+I8R+YDbT+6N0IA4xV8=" Mar 01 22:11:20 dac.x1 go-librespot[23975]: time="2025-03-01T22:11:20+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 22:11:20 dac.x1 go-librespot[23975]: time="2025-03-01T22:11:20+08:00" level=debug msg="completed keyexchange" Mar 01 22:11:20 dac.x1 go-librespot[23975]: time="2025-03-01T22:11:20+08:00" level=debug msg="completed challenge" Mar 01 22:11:20 dac.x1 go-librespot[23975]: time="2025-03-01T22:11:20+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 22:11:20 dac.x1 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 22:11:20 dac.x1 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 22:11:20 dac.x1 volumio[2783]: (node:2783) UnhandledPromiseRejectionWarning: Error: socket hang up Mar 01 22:11:20 dac.x1 volumio[2783]: at connResetException (internal/errors.js:607:14) Mar 01 22:11:20 dac.x1 volumio[2783]: at Socket.socketOnEnd (_http_client.js:493:23) Mar 01 22:11:20 dac.x1 volumio[2783]: at Socket.emit (events.js:327:22) Mar 01 22:11:20 dac.x1 volumio[2783]: at endReadableNT (internal/streams/readable.js:1327:12) Mar 01 22:11:20 dac.x1 volumio[2783]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Mar 01 22:11:20 dac.x1 volumio[2783]: (node:2783) 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: 392) Mar 01 22:11:20 dac.x1 volumio[2783]: info: Connection to go-librespot Websocket closed Mar 01 22:11:21 dac.x1 wpa_supplicant[865]: wlan0: Failed to initiate sched scan Mar 01 22:11:23 dac.x1 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 22:11:23 dac.x1 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 711. Mar 01 22:11:23 dac.x1 systemd[1]: Stopped go-librespot Daemon. Mar 01 22:11:23 dac.x1 volumio[2783]: info: Initializing connection to go-librespot Websocket Mar 01 22:11:23 dac.x1 volumio[2783]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 22:11:23 dac.x1 systemd[1]: Started go-librespot Daemon. Mar 01 22:11:23 dac.x1 go-librespot[24000]: go-librespot daemon starting... Mar 01 22:11:23 dac.x1 go-librespot[24000]: time="2025-03-01T22:11:23+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 22:11:23 dac.x1 go-librespot[24000]: time="2025-03-01T22:11:23+08:00" level=debug msg="app state loaded" Mar 01 22:11:23 dac.x1 go-librespot[24000]: time="2025-03-01T22:11:23+08:00" level=debug msg="stored credentials not found" Mar 01 22:11:23 dac.x1 go-librespot[24000]: time="2025-03-01T22:11:23+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 22:11:24 dac.x1 go-librespot[24000]: time="2025-03-01T22:11:24+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 22:11:24 dac.x1 go-librespot[24000]: time="2025-03-01T22:11:24+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 01 22:11:24 dac.x1 go-librespot[24000]: time="2025-03-01T22:11:24+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 01 22:11:24 dac.x1 go-librespot[24000]: time="2025-03-01T22:11:24+08:00" level=info msg="zeroconf server listening on port 38069" Mar 01 22:11:25 dac.x1 go-librespot[24000]: time="2025-03-01T22:11:25+08:00" level=debug msg="obtained new client token: AACQpil2uXqNtTueZqBIO456m1VbzpI1U0v1Fw2x7OQqiCub9D+YBhJUS7zM+qXCyo9nNsuSMk+Y0WsTl+3rvkC5j3T+/jqUZf9Hd2WCfON2Gn0zuqR7NLwqWnoJQVEkAhMhIfYuXxMb7HXEeSiFU0AM0NtJFw4h2ANJtm3aujCUBd0/twLRoGqacx1Gfibup89nq8VmJx3D7jKZtokPcf+gFWDoVxJmNQh2TAupCMU0Vi/HOLab" Mar 01 22:11:25 dac.x1 go-librespot[24000]: time="2025-03-01T22:11:25+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 22:11:25 dac.x1 go-librespot[24000]: time="2025-03-01T22:11:25+08:00" level=debug msg="completed keyexchange" Mar 01 22:11:25 dac.x1 go-librespot[24000]: time="2025-03-01T22:11:25+08:00" level=debug msg="completed challenge" Mar 01 22:11:25 dac.x1 go-librespot[24000]: time="2025-03-01T22:11:25+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 22:11:25 dac.x1 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 22:11:25 dac.x1 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 22:11:26 dac.x1 volumio[2783]: info: Initializing connection to go-librespot Websocket Mar 01 22:11:26 dac.x1 volumio[2783]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 22:11:28 dac.x1 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 22:11:28 dac.x1 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 712. Mar 01 22:11:28 dac.x1 systemd[1]: Stopped go-librespot Daemon. Mar 01 22:11:28 dac.x1 systemd[1]: Started go-librespot Daemon. Mar 01 22:11:28 dac.x1 go-librespot[24012]: go-librespot daemon starting... Mar 01 22:11:28 dac.x1 go-librespot[24012]: time="2025-03-01T22:11:28+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 22:11:28 dac.x1 go-librespot[24012]: time="2025-03-01T22:11:28+08:00" level=debug msg="app state loaded" Mar 01 22:11:28 dac.x1 go-librespot[24012]: time="2025-03-01T22:11:28+08:00" level=debug msg="stored credentials not found" Mar 01 22:11:28 dac.x1 go-librespot[24012]: time="2025-03-01T22:11:28+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 22:11:29 dac.x1 volumio[2783]: info: Initializing connection to go-librespot Websocket Mar 01 22:11:29 dac.x1 go-librespot[24012]: time="2025-03-01T22:11:29+08:00" level=debug msg="new websocket client" Mar 01 22:11:29 dac.x1 volumio[2783]: info: Connection to go-librespot Websocket established Mar 01 22:11:29 dac.x1 wpa_supplicant[865]: wlan0: Failed to initiate sched scan Mar 01 22:11:29 dac.x1 volumio[2783]: info: MyVolumio login type: Token Mar 01 22:11:30 dac.x1 go-librespot[24012]: time="2025-03-01T22:11:30+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 01 22:11:30 dac.x1 go-librespot[24012]: time="2025-03-01T22:11:30+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 01 22:11:30 dac.x1 go-librespot[24012]: time="2025-03-01T22:11:30+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 01 22:11:30 dac.x1 go-librespot[24012]: time="2025-03-01T22:11:30+08:00" level=info msg="zeroconf server listening on port 40375" Mar 01 22:11:30 dac.x1 go-librespot[24012]: time="2025-03-01T22:11:30+08:00" level=debug msg="obtained new client token: AACACUrO5QaJfSckhp3sXbV8SvzxKj8QdGls/K5q+ZJyFgJh9Wxln3jq/ZXQO0vaUpqTgxDOHLlIJ0/YqDQ0k8CyppbNfzJ1JAw7pnh5/aME/KcbqvGdEo+LCpjE/T0diiLAnr3dg2uYYVQ051dMbHDsxNLzgyOZXusDCfv2m06DwyFHVvuwYHez/1fN0hlLc0Fp68JfixqarDdwpUGHGn2RqAOTjp/NkF/ebcblYQPksshyyYgYR3Q=" Mar 01 22:11:30 dac.x1 go-librespot[24012]: time="2025-03-01T22:11:30+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 22:11:30 dac.x1 go-librespot[24012]: time="2025-03-01T22:11:30+08:00" level=debug msg="completed keyexchange" Mar 01 22:11:30 dac.x1 go-librespot[24012]: time="2025-03-01T22:11:30+08:00" level=debug msg="completed challenge" Mar 01 22:11:30 dac.x1 go-librespot[24012]: time="2025-03-01T22:11:30+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 22:11:30 dac.x1 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 22:11:30 dac.x1 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 22:11:30 dac.x1 volumio[2783]: info: Connection to go-librespot Websocket closed Mar 01 22:11:32 dac.x1 volumio[2783]: info: Getting Spotify volume Mar 01 22:11:32 dac.x1 volumio[2783]: (node:2783) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 22:11:32 dac.x1 volumio[2783]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 01 22:11:32 dac.x1 volumio[2783]: (node:2783) 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: 393) Mar 01 22:11:32 dac.x1 volumio[2783]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Mar 01 22:11:32 dac.x1 volumio[2783]: info: CoreCommandRouter::volumioGetState Mar 01 22:11:32 dac.x1 volumio[2783]: info: CorePlayQueue::getTrack 1 Mar 01 22:11:32 dac.x1 volumio[2783]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 01 22:11:33 dac.x1 volumio[2783]: Error: connect ETIMEDOUT 174.37.54.20:443 Mar 01 22:11:33 dac.x1 volumio[2783]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) { Mar 01 22:11:33 dac.x1 volumio[2783]: errno: -110, Mar 01 22:11:33 dac.x1 volumio[2783]: code: 'ETIMEDOUT', Mar 01 22:11:33 dac.x1 volumio[2783]: syscall: 'connect', Mar 01 22:11:33 dac.x1 volumio[2783]: address: '174.37.54.20', Mar 01 22:11:33 dac.x1 volumio[2783]: port: 443 Mar 01 22:11:33 dac.x1 volumio[2783]: } Mar 01 22:11:33 dac.x1 volumio[2783]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 01 22:11:34 dac.x1 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 22:11:34 dac.x1 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 713. Mar 01 22:11:34 dac.x1 systemd[1]: Stopped go-librespot Daemon. Mar 01 22:11:34 dac.x1 systemd[1]: Started go-librespot Daemon. Mar 01 22:11:34 dac.x1 go-librespot[24044]: go-librespot daemon starting... Mar 01 22:11:34 dac.x1 go-librespot[24044]: time="2025-03-01T22:11:34+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 22:11:34 dac.x1 go-librespot[24044]: time="2025-03-01T22:11:34+08:00" level=debug msg="app state loaded" Mar 01 22:11:34 dac.x1 go-librespot[24044]: time="2025-03-01T22:11:34+08:00" level=debug msg="stored credentials not found" Mar 01 22:11:34 dac.x1 go-librespot[24044]: time="2025-03-01T22:11:34+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 22:11:34 dac.x1 sudo[24052]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-01 22:10 Mar 01 22:11:34 dac.x1 sudo[24052]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="f6610a1100d2380eef33bd3004af43153c786f96" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="1c0e5daee99fe3a72cc38b0d1fe6cd78d7f001fe" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 16 Dec 2024 09:30:04 AM CET" VOLUMIO_VERSION="3.785" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fe0ac4b79aed19ccde4b5bd83d468193"