-- Logs begin at Fri 2024-03-29 19:02:47 CST, end at Fri 2024-03-29 19:32:35 CST. -- Mar 29 19:31:01 volumio volumio[919]: info: Initializing connection to go-librespot Websocket Mar 29 19:31:01 volumio volumio[919]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 19:31:01 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 19:31:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 269. Mar 29 19:31:01 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 19:31:01 volumio systemd[1]: Started go-librespot Daemon. Mar 29 19:31:01 volumio go-librespot[7167]: Librespot-go daemon starting... Mar 29 19:31:01 volumio go-librespot[7167]: time="2024-03-29T19:31:01+08:00" level=info msg="generated new device id: 32ec0635c6b299f329df484a87e9db565780a69c" Mar 29 19:31:01 volumio go-librespot[7167]: time="2024-03-29T19:31:01+08:00" level=debug msg="stored credentials not found" Mar 29 19:31:02 volumio wpa_supplicant[755]: wlan0: Failed to initiate sched scan Mar 29 19:31:02 volumio go-librespot[7167]: time="2024-03-29T19:31:02+08:00" level=debug msg="obtained new client token: AAAgcCwCtL/cuduc6CYjRI0DBLx+FEvPEVJg7+HwT4egDllKy0bweRUP98JE3CgXkesk5nalRxB+BvKICN2uM2WCr6kqv1UGwwtan187V75QSetVM2yy8dTetJExZPCUnN65JLMs1tFvmdnaXZ51RC4fauIvgf+NOhth4WQusnmDo1rmjuapU4A/YbmtPvj9UfC0ZS4hr6p3tMi02EbmdtzLYLBBj/QUT4hOyZLK6MKYABTxixbtJ477gr4=" Mar 29 19:31:03 volumio go-librespot[7167]: time="2024-03-29T19:31:03+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 29 19:31:03 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: appearance , setBackgrounds Mar 29 19:31:03 volumio go-librespot[7167]: time="2024-03-29T19:31:03+08:00" level=debug msg="completed keyexchange" Mar 29 19:31:03 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: appearance , getBackgrounds Mar 29 19:31:03 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Mar 29 19:31:03 volumio go-librespot[7167]: time="2024-03-29T19:31:03+08:00" level=debug msg="completed challenge" Mar 29 19:31:03 volumio go-librespot[7167]: time="2024-03-29T19:31:03+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: TravelRestriction" Mar 29 19:31:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 19:31:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 19:31:04 volumio volumio[919]: info: Initializing connection to go-librespot Websocket Mar 29 19:31:04 volumio volumio[919]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 19:31:04 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: appearance , setBackgrounds Mar 29 19:31:04 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: appearance , getBackgrounds Mar 29 19:31:05 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Mar 29 19:31:06 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: appearance , setBackgrounds Mar 29 19:31:06 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: appearance , getBackgrounds Mar 29 19:31:06 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Mar 29 19:31:07 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 19:31:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 270. Mar 29 19:31:07 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 19:31:07 volumio systemd[1]: Started go-librespot Daemon. Mar 29 19:31:07 volumio go-librespot[7190]: Librespot-go daemon starting... Mar 29 19:31:07 volumio go-librespot[7190]: time="2024-03-29T19:31:07+08:00" level=info msg="generated new device id: 8a9edabdf2ad6077cff8217791411fc0f1632149" Mar 29 19:31:07 volumio go-librespot[7190]: time="2024-03-29T19:31:07+08:00" level=debug msg="stored credentials not found" Mar 29 19:31:07 volumio volumio[919]: info: Initializing connection to go-librespot Websocket Mar 29 19:31:07 volumio go-librespot[7190]: time="2024-03-29T19:31:07+08:00" level=debug msg="new websocket client" Mar 29 19:31:07 volumio volumio[919]: info: Connection to go-librespot Websocket established Mar 29 19:31:08 volumio wpa_supplicant[755]: wlan0: Failed to initiate sched scan Mar 29 19:31:08 volumio go-librespot[7190]: time="2024-03-29T19:31:08+08:00" level=debug msg="obtained new client token: AAA+1pE7B27fALmB3Hk7fxI3mUSHYvcxBtgi5nL9feC4ykb+u9yrOMz/DGi2QdwXWxnjIYu+8sbNfvxBcFmndRqcosex7IldY4ARwy5bAMKl7rVh4fFON74kX5SymaENCtMLDatQRGc3yvW5+FkfvGl2hqEwk1v1Wy5Crp1GiDnn6CMkfgx9Xm0i6UJSCjRv+we2FLj5gbo39/fCmBl5Jq2zQOlOo+ChKhEHQDZV8slxVx3yLhUqCKjT4gM=" Mar 29 19:31:08 volumio go-librespot[7190]: time="2024-03-29T19:31:08+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 29 19:31:08 volumio go-librespot[7190]: time="2024-03-29T19:31:08+08:00" level=debug msg="completed keyexchange" Mar 29 19:31:09 volumio go-librespot[7190]: time="2024-03-29T19:31:09+08:00" level=debug msg="completed challenge" Mar 29 19:31:09 volumio go-librespot[7190]: time="2024-03-29T19:31:09+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: TravelRestriction" Mar 29 19:31:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 19:31:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 19:31:09 volumio volumio[919]: info: Connection to go-librespot Websocket closed Mar 29 19:31:10 volumio volumio[919]: info: Getting Spotify volume Mar 29 19:31:10 volumio volumio[919]: (node:919) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 19:31:10 volumio volumio[919]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 29 19:31:10 volumio volumio[919]: (node:919) 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: 219) Mar 29 19:31:10 volumio volumio[919]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Mar 29 19:31:10 volumio volumio[919]: info: CoreCommandRouter::volumioGetState Mar 29 19:31:10 volumio volumio[919]: info: CorePlayQueue::getTrack 14 Mar 29 19:31:10 volumio volumio[919]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 29 19:31:10 volumio volumio[919]: SPOTIFY: SPOTIFY VOLUME 99 Mar 29 19:31:10 volumio volumio[919]: SPOTIFY: VOLUMIO VOLUME 100 Mar 29 19:31:10 volumio volumio[919]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 29 19:31:12 volumio volumio[919]: info: Initializing connection to go-librespot Websocket Mar 29 19:31:12 volumio volumio[919]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 19:31:12 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 19:31:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 271. Mar 29 19:31:12 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 19:31:12 volumio systemd[1]: Started go-librespot Daemon. Mar 29 19:31:12 volumio go-librespot[7209]: Librespot-go daemon starting... Mar 29 19:31:13 volumio go-librespot[7209]: time="2024-03-29T19:31:13+08:00" level=info msg="generated new device id: 0e0a5a1850eabcc150d837411733a009e015378b" Mar 29 19:31:13 volumio go-librespot[7209]: time="2024-03-29T19:31:13+08:00" level=debug msg="stored credentials not found" Mar 29 19:31:13 volumio go-librespot[7209]: time="2024-03-29T19:31:13+08:00" level=debug msg="obtained new client token: AADmc2iuPC3B+nVr97WM1S/y77P4huzp/Li4buKP6qWf9CSrWrwECrstNFhi+xFKyWbUDoLtPx0JSJ7C8B0V66llnZjGeYh2NGFnCvP4DSBofpftv+UotqPxX3Lw8tYKilTuk6krBaI486RmG7I7p2aDlLTvcsmK9F+H2w9y52vFDzH2MSdlSHvcIIllt4Zshru9M48PfolnC0ZO2DLQL1oMuXpH3+tjIzciAPbzDFcPrHBeNOuNj4wPwdcF9g==" Mar 29 19:31:14 volumio wpa_supplicant[755]: wlan0: Failed to initiate sched scan Mar 29 19:31:14 volumio go-librespot[7209]: time="2024-03-29T19:31:14+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 29 19:31:14 volumio go-librespot[7209]: time="2024-03-29T19:31:14+08:00" level=debug msg="completed keyexchange" Mar 29 19:31:15 volumio go-librespot[7209]: time="2024-03-29T19:31:15+08:00" level=debug msg="completed challenge" Mar 29 19:31:15 volumio go-librespot[7209]: time="2024-03-29T19:31:15+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: TravelRestriction" Mar 29 19:31:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 19:31:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 19:31:15 volumio volumio[919]: info: Initializing connection to go-librespot Websocket Mar 29 19:31:15 volumio volumio[919]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 19:31:18 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 19:31:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 272. Mar 29 19:31:18 volumio volumio[919]: info: Initializing connection to go-librespot Websocket Mar 29 19:31:18 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 19:31:18 volumio volumio[919]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 19:31:18 volumio systemd[1]: Started go-librespot Daemon. Mar 29 19:31:18 volumio go-librespot[7230]: Librespot-go daemon starting... Mar 29 19:31:18 volumio go-librespot[7230]: time="2024-03-29T19:31:18+08:00" level=info msg="generated new device id: 6525a31bba71802ecced2a7106a04af7a46c3227" Mar 29 19:31:18 volumio go-librespot[7230]: time="2024-03-29T19:31:18+08:00" level=debug msg="stored credentials not found" Mar 29 19:31:19 volumio go-librespot[7230]: time="2024-03-29T19:31:19+08:00" level=debug msg="obtained new client token: AABbAuwuFZB9H/Qo77fat+/5wSwEQTmsW4mQLl1YozFeCjRbw+nc1Sb9y+uUSM5BlbtF1IP27wySbUv/PnMXuHRNXt1/XiXtanOfVE6JAP13mCV5hzJXgwrDOGDgm41rc2D48SHpLBOqy6DNMdRn0br0dRGudzAQfdIl2+aEUfeE6+OpCuKl4E7DFWF8MhdQFXS8cnOcNc3k7LrnRJ6IVTd36eeUYjLZegg9Y4B2HNJnaMOSERI4GUa6fUc9dQ==" Mar 29 19:31:20 volumio wpa_supplicant[755]: wlan0: Failed to initiate sched scan Mar 29 19:31:20 volumio go-librespot[7230]: time="2024-03-29T19:31:20+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 29 19:31:20 volumio go-librespot[7230]: time="2024-03-29T19:31:20+08:00" level=debug msg="completed keyexchange" Mar 29 19:31:21 volumio go-librespot[7230]: time="2024-03-29T19:31:21+08:00" level=debug msg="completed challenge" Mar 29 19:31:21 volumio go-librespot[7230]: time="2024-03-29T19:31:21+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: TravelRestriction" Mar 29 19:31:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 19:31:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 19:31:21 volumio volumio[919]: info: Initializing connection to go-librespot Websocket Mar 29 19:31:21 volumio volumio[919]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 19:31:22 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: appearance , setBackgrounds Mar 29 19:31:22 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: appearance , getBackgrounds Mar 29 19:31:22 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Mar 29 19:31:24 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 19:31:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 273. Mar 29 19:31:24 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 19:31:24 volumio systemd[1]: Started go-librespot Daemon. Mar 29 19:31:24 volumio go-librespot[7249]: Librespot-go daemon starting... Mar 29 19:31:24 volumio go-librespot[7249]: time="2024-03-29T19:31:24+08:00" level=info msg="generated new device id: 722e475dee5b13b0db405e0f441f2e6ed9020b25" Mar 29 19:31:24 volumio go-librespot[7249]: time="2024-03-29T19:31:24+08:00" level=debug msg="stored credentials not found" Mar 29 19:31:24 volumio volumio[919]: info: Initializing connection to go-librespot Websocket Mar 29 19:31:24 volumio go-librespot[7249]: time="2024-03-29T19:31:24+08:00" level=debug msg="new websocket client" Mar 29 19:31:24 volumio volumio[919]: info: Connection to go-librespot Websocket established Mar 29 19:31:25 volumio go-librespot[7249]: time="2024-03-29T19:31:25+08:00" level=debug msg="obtained new client token: AADlacfEJe4oBJ2+JEKX4mPdQ8mPAiMk+3xTPUi61o0RIfdgsUuGrd58ghy3CsW8XQNJWY+bvGZ9wOca8BjtT0SswqWdfgIk2YIQMaLAd8LYlK+Vj1E+VWhKIRWCiZxlkFKkqlnuQKu7vr+9fp5C9eid/1Emo5TPS2Cv/kzzcuaO0nsW++Ah1rYEENBRiruaheExs38qCGYyidkd0XvDirHroLtxO3yRRYrZmDZ9S/vDH4u2M4nVAOxfmZUFWA==" Mar 29 19:31:25 volumio wpa_supplicant[755]: wlan0: Failed to initiate sched scan Mar 29 19:31:26 volumio go-librespot[7249]: time="2024-03-29T19:31:26+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 29 19:31:26 volumio go-librespot[7249]: time="2024-03-29T19:31:26+08:00" level=debug msg="completed keyexchange" Mar 29 19:31:26 volumio go-librespot[7249]: time="2024-03-29T19:31:26+08:00" level=debug msg="completed challenge" Mar 29 19:31:26 volumio go-librespot[7249]: time="2024-03-29T19:31:26+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: TravelRestriction" Mar 29 19:31:26 volumio volumio[919]: info: Connection to go-librespot Websocket closed Mar 29 19:31:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 19:31:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 19:31:27 volumio volumio[919]: info: Getting Spotify volume Mar 29 19:31:27 volumio volumio[919]: (node:919) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 19:31:27 volumio volumio[919]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 29 19:31:27 volumio volumio[919]: (node:919) 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: 220) Mar 29 19:31:27 volumio volumio[919]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Mar 29 19:31:27 volumio volumio[919]: info: CoreCommandRouter::volumioGetState Mar 29 19:31:27 volumio volumio[919]: info: CorePlayQueue::getTrack 14 Mar 29 19:31:27 volumio volumio[919]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 29 19:31:27 volumio volumio[919]: SPOTIFY: SPOTIFY VOLUME 99 Mar 29 19:31:27 volumio volumio[919]: SPOTIFY: VOLUMIO VOLUME 100 Mar 29 19:31:27 volumio volumio[919]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 29 19:31:29 volumio volumio[919]: info: Initializing connection to go-librespot Websocket Mar 29 19:31:29 volumio volumio[919]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 19:31:30 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 19:31:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 274. Mar 29 19:31:30 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 19:31:30 volumio systemd[1]: Started go-librespot Daemon. Mar 29 19:31:30 volumio go-librespot[7310]: Librespot-go daemon starting... Mar 29 19:31:30 volumio go-librespot[7310]: time="2024-03-29T19:31:30+08:00" level=info msg="generated new device id: 1b1e85d4854eb8ffe0b7ea0efba54ca28720b28f" Mar 29 19:31:30 volumio go-librespot[7310]: time="2024-03-29T19:31:30+08:00" level=debug msg="stored credentials not found" Mar 29 19:31:31 volumio go-librespot[7310]: time="2024-03-29T19:31:31+08:00" level=debug msg="obtained new client token: AABA2yQPtEtwfUxRr68ikcaLK4KMVta+46ZJfh8anAlbG32M0jaEc+LPH2CXnyemIdRJBnhuDYzHYHUoVTxX/KqzDSfiLBbnuMfqZ9KLv/1eBsO8F1MZbdGQmLWTE+kj5OGPWQjEBIgLqI+9Z5MaKHOw3Y0S/vCCrTU7Bm73G3hNAIl7tsLivPbntScQBvoKeGjT9VRm37qC4oAbWV9Krm6UjkGuZVCJub0/4gLBGipv2MllRblkEoc47k8=" Mar 29 19:31:31 volumio go-librespot[7310]: time="2024-03-29T19:31:31+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 29 19:31:31 volumio wpa_supplicant[755]: wlan0: Failed to initiate sched scan Mar 29 19:31:32 volumio go-librespot[7310]: time="2024-03-29T19:31:32+08:00" level=debug msg="completed keyexchange" Mar 29 19:31:32 volumio go-librespot[7310]: time="2024-03-29T19:31:32+08:00" level=debug msg="completed challenge" Mar 29 19:31:32 volumio go-librespot[7310]: time="2024-03-29T19:31:32+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: TravelRestriction" Mar 29 19:31:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 19:31:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 19:31:32 volumio volumio[919]: error: [yt-cast-receiver] (YouTube) Error occurred in SendMessageTask: Mar 29 19:31:32 volumio volumio[919]: LoungeScreenDisconnected { Mar 29 19:31:32 volumio volumio[919]: AID: null, Mar 29 19:31:32 volumio volumio[919]: name: 'loungeScreenDisconnected', Mar 29 19:31:32 volumio volumio[919]: payload: {} Mar 29 19:31:32 volumio volumio[919]: } Mar 29 19:31:32 volumio volumio[919]: (IncompleteAPIDataError) Missing data required to construct query string from bind params Mar 29 19:31:32 volumio volumio[919]: Error info: { missing: [ 'loungeIdToken', 'SID', 'gsessionid' ] } Mar 29 19:31:32 volumio volumio[919]: Stack trace: Mar 29 19:31:32 volumio volumio[919]: IncompleteAPIDataError: Missing data required to construct query string from bind params Mar 29 19:31:32 volumio volumio[919]: at BindParams.toQueryString (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/BindParams.js:120:19) Mar 29 19:31:32 volumio volumio[919]: at Session._Session_doSendMessage (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:492:103) Mar 29 19:31:32 volumio volumio[919]: at SendMessageTask.run (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:552:71) Mar 29 19:31:32 volumio volumio[919]: at AsyncTaskQueue.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/utils/AsyncTaskQueue.js:51:36) Mar 29 19:31:32 volumio volumio[919]: at Session.end (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:237:71) Mar 29 19:31:32 volumio volumio[919]: at runMicrotasks () Mar 29 19:31:32 volumio volumio[919]: at processTicksAndRejections (internal/process/task_queues.js:93:5) Mar 29 19:31:32 volumio volumio[919]: (node:919) UnhandledPromiseRejectionWarning: TypeError: Cannot read property 'removeAllListeners' of undefined Mar 29 19:31:32 volumio volumio[919]: at Session._Session_refreshLoungeToken (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:372:16) Mar 29 19:31:32 volumio volumio[919]: at runMicrotasks () Mar 29 19:31:32 volumio volumio[919]: at processTicksAndRejections (internal/process/task_queues.js:93:5) Mar 29 19:31:32 volumio volumio[919]: (node:919) 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: 222) Mar 29 19:31:32 volumio volumio[919]: error: [yt-cast-receiver] (YouTube Music) Error occurred in SendMessageTask: Mar 29 19:31:32 volumio volumio[919]: LoungeScreenDisconnected { Mar 29 19:31:32 volumio volumio[919]: AID: null, Mar 29 19:31:32 volumio volumio[919]: name: 'loungeScreenDisconnected', Mar 29 19:31:32 volumio volumio[919]: payload: {} Mar 29 19:31:32 volumio volumio[919]: } Mar 29 19:31:32 volumio volumio[919]: (IncompleteAPIDataError) Missing data required to construct query string from bind params Mar 29 19:31:32 volumio volumio[919]: Error info: { missing: [ 'loungeIdToken', 'SID', 'gsessionid' ] } Mar 29 19:31:32 volumio volumio[919]: Stack trace: Mar 29 19:31:32 volumio volumio[919]: IncompleteAPIDataError: Missing data required to construct query string from bind params Mar 29 19:31:32 volumio volumio[919]: at BindParams.toQueryString (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/BindParams.js:120:19) Mar 29 19:31:32 volumio volumio[919]: at Session._Session_doSendMessage (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:492:103) Mar 29 19:31:32 volumio volumio[919]: at SendMessageTask.run (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:552:71) Mar 29 19:31:32 volumio volumio[919]: at AsyncTaskQueue.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/utils/AsyncTaskQueue.js:51:36) Mar 29 19:31:32 volumio volumio[919]: at Session.end (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:237:71) Mar 29 19:31:32 volumio volumio[919]: at runMicrotasks () Mar 29 19:31:32 volumio volumio[919]: at processTicksAndRejections (internal/process/task_queues.js:93:5) Mar 29 19:31:32 volumio volumio[919]: (node:919) UnhandledPromiseRejectionWarning: TypeError: Cannot read property 'removeAllListeners' of undefined Mar 29 19:31:32 volumio volumio[919]: at Session._Session_refreshLoungeToken (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:372:16) Mar 29 19:31:32 volumio volumio[919]: at runMicrotasks () Mar 29 19:31:32 volumio volumio[919]: at processTicksAndRejections (internal/process/task_queues.js:93:5) Mar 29 19:31:32 volumio volumio[919]: (node:919) 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: 224) Mar 29 19:31:32 volumio volumio[919]: error: [yt-cast-receiver] (YouTube Music) Error occurred in SendMessageTask: Mar 29 19:31:32 volumio volumio[919]: LoungeScreenDisconnected { Mar 29 19:31:32 volumio volumio[919]: AID: null, Mar 29 19:31:32 volumio volumio[919]: name: 'loungeScreenDisconnected', Mar 29 19:31:32 volumio volumio[919]: payload: {} Mar 29 19:31:32 volumio volumio[919]: } Mar 29 19:31:32 volumio volumio[919]: (IncompleteAPIDataError) Missing data required to construct query string from bind params Mar 29 19:31:32 volumio volumio[919]: Error info: { missing: [ 'loungeIdToken', 'SID', 'gsessionid' ] } Mar 29 19:31:32 volumio volumio[919]: Stack trace: Mar 29 19:31:32 volumio volumio[919]: IncompleteAPIDataError: Missing data required to construct query string from bind params Mar 29 19:31:32 volumio volumio[919]: at BindParams.toQueryString (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/BindParams.js:120:19) Mar 29 19:31:32 volumio volumio[919]: at Session._Session_doSendMessage (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:492:103) Mar 29 19:31:32 volumio volumio[919]: at SendMessageTask.run (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:552:71) Mar 29 19:31:32 volumio volumio[919]: at AsyncTaskQueue.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/utils/AsyncTaskQueue.js:51:36) Mar 29 19:31:32 volumio volumio[919]: at Session.end (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:237:71) Mar 29 19:31:32 volumio volumio[919]: at runMicrotasks () Mar 29 19:31:32 volumio volumio[919]: at processTicksAndRejections (internal/process/task_queues.js:93:5) Mar 29 19:31:32 volumio volumio[919]: (node:919) UnhandledPromiseRejectionWarning: TypeError: Cannot read property 'removeAllListeners' of undefined Mar 29 19:31:32 volumio volumio[919]: at Session._Session_refreshLoungeToken (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:372:16) Mar 29 19:31:32 volumio volumio[919]: at runMicrotasks () Mar 29 19:31:32 volumio volumio[919]: at processTicksAndRejections (internal/process/task_queues.js:93:5) Mar 29 19:31:32 volumio volumio[919]: (node:919) 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: 226) Mar 29 19:31:32 volumio volumio[919]: error: [yt-cast-receiver] (YouTube) Error occurred in SendMessageTask: Mar 29 19:31:32 volumio volumio[919]: LoungeScreenDisconnected { Mar 29 19:31:32 volumio volumio[919]: AID: null, Mar 29 19:31:32 volumio volumio[919]: name: 'loungeScreenDisconnected', Mar 29 19:31:32 volumio volumio[919]: payload: {} Mar 29 19:31:32 volumio volumio[919]: } Mar 29 19:31:32 volumio volumio[919]: (IncompleteAPIDataError) Missing data required to construct query string from bind params Mar 29 19:31:32 volumio volumio[919]: Error info: { missing: [ 'loungeIdToken', 'SID', 'gsessionid' ] } Mar 29 19:31:32 volumio volumio[919]: Stack trace: Mar 29 19:31:32 volumio volumio[919]: IncompleteAPIDataError: Missing data required to construct query string from bind params Mar 29 19:31:32 volumio volumio[919]: at BindParams.toQueryString (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/BindParams.js:120:19) Mar 29 19:31:32 volumio volumio[919]: at Session._Session_doSendMessage (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:492:103) Mar 29 19:31:32 volumio volumio[919]: at SendMessageTask.run (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:552:71) Mar 29 19:31:32 volumio volumio[919]: at AsyncTaskQueue.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/utils/AsyncTaskQueue.js:51:36) Mar 29 19:31:32 volumio volumio[919]: at Session.end (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:237:71) Mar 29 19:31:32 volumio volumio[919]: at runMicrotasks () Mar 29 19:31:32 volumio volumio[919]: at processTicksAndRejections (internal/process/task_queues.js:93:5) Mar 29 19:31:32 volumio volumio[919]: (node:919) UnhandledPromiseRejectionWarning: TypeError: Cannot read property 'removeAllListeners' of undefined Mar 29 19:31:32 volumio volumio[919]: at Session._Session_refreshLoungeToken (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:372:16) Mar 29 19:31:32 volumio volumio[919]: at runMicrotasks () Mar 29 19:31:32 volumio volumio[919]: at processTicksAndRejections (internal/process/task_queues.js:93:5) Mar 29 19:31:32 volumio volumio[919]: (node:919) 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: 228) Mar 29 19:31:32 volumio volumio[919]: info: Initializing connection to go-librespot Websocket Mar 29 19:31:32 volumio volumio[919]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 19:31:35 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 19:31:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 275. Mar 29 19:31:35 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 19:31:35 volumio systemd[1]: Started go-librespot Daemon. Mar 29 19:31:35 volumio go-librespot[7330]: Librespot-go daemon starting... Mar 29 19:31:35 volumio volumio[919]: info: Initializing connection to go-librespot Websocket Mar 29 19:31:35 volumio volumio[919]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 19:31:35 volumio go-librespot[7330]: time="2024-03-29T19:31:35+08:00" level=info msg="generated new device id: ecef7c1797cb8ddfcbb9869868e94f1a7233082a" Mar 29 19:31:35 volumio go-librespot[7330]: time="2024-03-29T19:31:35+08:00" level=debug msg="stored credentials not found" Mar 29 19:31:36 volumio volumio[919]: info: CALLMETHOD: miscellanea appearance setVolumio3UI [object Object] Mar 29 19:31:36 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: appearance , setVolumio3UI Mar 29 19:31:36 volumio go-librespot[7330]: time="2024-03-29T19:31:36+08:00" level=debug msg="obtained new client token: AABHOCNBC0zi5gKGwUufETVtEuJ1NmOsc3a+zH9nozl+12Gm3BwjYRLdG9VPdx0VsElEDRPr2EvWpATA72x3aH9IFV3FpXebbu2e0PWN2FG75Uq5jFiD8ncRxBr8koMxUo7jrpGtfIGNEmpj6BxdoSAK8M7jQZ1ZaTAp4zZgjEd5jf5vveR3BTLdqfM0ywuDfkf03edH/B96Mgl8RKTk5hqcZitY7HprQID1cRxhsuVdz2CUIefLerDr9ooFTw==" Mar 29 19:31:37 volumio go-librespot[7330]: time="2024-03-29T19:31:37+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 29 19:31:37 volumio go-librespot[7330]: time="2024-03-29T19:31:37+08:00" level=debug msg="completed keyexchange" Mar 29 19:31:37 volumio wpa_supplicant[755]: wlan0: Failed to initiate sched scan Mar 29 19:31:38 volumio go-librespot[7330]: time="2024-03-29T19:31:38+08:00" level=debug msg="completed challenge" Mar 29 19:31:38 volumio go-librespot[7330]: time="2024-03-29T19:31:38+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: TravelRestriction" Mar 29 19:31:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 19:31:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 19:31:38 volumio volumio[919]: info: Initializing connection to go-librespot Websocket Mar 29 19:31:38 volumio volumio[919]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 19:31:39 volumio volumio[919]: info: CoreCommandRouter::Reload Ui Mar 29 19:31:39 volumio sudo[7355]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 29 19:31:39 volumio sudo[7355]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 29 19:31:39 volumio sudo[7355]: pam_unix(sudo:session): session closed for user root Mar 29 19:31:39 volumio sudo[7358]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 29 19:31:39 volumio sudo[7358]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 29 19:31:39 volumio sudo[7358]: pam_unix(sudo:session): session closed for user root Mar 29 19:31:39 volumio volumio[919]: verbose: New Socket.io Connection to 192.168.2.103 from 192.168.2.101 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/15.4 Safari/605.1.15 Total Clients: 9 Mar 29 19:31:39 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Mar 29 19:31:39 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 29 19:31:39 volumio volumio[919]: info: CoreCommandRouter::volumioGetVisibleSources Mar 29 19:31:39 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 29 19:31:39 volumio volumio[919]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 29 19:31:39 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Mar 29 19:31:39 volumio volumio[919]: info: CoreCommandRouter::volumioGetState Mar 29 19:31:39 volumio volumio[919]: info: CorePlayQueue::getTrack 14 Mar 29 19:31:39 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 29 19:31:39 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 29 19:31:39 volumio volumio[919]: info: Received Get System Info Mar 29 19:31:39 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 29 19:31:39 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 29 19:31:39 volumio volumio[919]: info: Discovery: Getting this device information Mar 29 19:31:39 volumio volumio[919]: info: CoreCommandRouter::volumioGetState Mar 29 19:31:39 volumio volumio[919]: info: CorePlayQueue::getTrack 14 Mar 29 19:31:39 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 29 19:31:39 volumio volumio[919]: info: CoreCommandRouter::volumioGetState Mar 29 19:31:39 volumio volumio[919]: info: CorePlayQueue::getTrack 14 Mar 29 19:31:39 volumio volumio[919]: info: Listing playlists Mar 29 19:31:39 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Mar 29 19:31:39 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 29 19:31:40 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Mar 29 19:31:40 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Mar 29 19:31:40 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Mar 29 19:31:40 volumio volumio[919]: info: Received Get System Version Mar 29 19:31:40 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 29 19:31:41 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 29 19:31:41 volumio volumio[919]: info: Received Get System Info Mar 29 19:31:41 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 29 19:31:41 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 29 19:31:41 volumio volumio[919]: info: Discovery: Getting this device information Mar 29 19:31:41 volumio volumio[919]: info: CoreCommandRouter::volumioGetState Mar 29 19:31:41 volumio volumio[919]: info: CorePlayQueue::getTrack 14 Mar 29 19:31:41 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 29 19:31:41 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 19:31:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 276. Mar 29 19:31:41 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 19:31:41 volumio systemd[1]: Started go-librespot Daemon. Mar 29 19:31:41 volumio go-librespot[7376]: Librespot-go daemon starting... Mar 29 19:31:41 volumio go-librespot[7376]: time="2024-03-29T19:31:41+08:00" level=info msg="generated new device id: 1b2d387cb6ba5aaaa9f0dff774830cc257827b12" Mar 29 19:31:41 volumio go-librespot[7376]: time="2024-03-29T19:31:41+08:00" level=debug msg="stored credentials not found" Mar 29 19:31:41 volumio volumio[919]: info: Initializing connection to go-librespot Websocket Mar 29 19:31:41 volumio volumio[919]: info: Connection to go-librespot Websocket established Mar 29 19:31:41 volumio go-librespot[7376]: time="2024-03-29T19:31:41+08:00" level=debug msg="new websocket client" Mar 29 19:31:42 volumio go-librespot[7376]: time="2024-03-29T19:31:42+08:00" level=debug msg="obtained new client token: AAD1u1z2pSZWiQ8r4yG2YyTvxIDu+S2WsG6ey1BsurJzE3MVYAx8qOw/+iBYQjCCfA5IiE/HSi4FsUtJxn9SoTbWemquPETrklG7sod2syznpNWTtu1Jh9wF2jQZCH7lomGAQXHc4NVLIg0u6n6prtz3CA2IRtxieM+PnFC4MGOxpeedJUjYWTdoViL84RznQmq1cHmbRa8vdpnvi9QjlGPPwiwBJGBGdEZkZ0seJxxW0Wky4qgKD9h1oeU=" Mar 29 19:31:42 volumio go-librespot[7376]: time="2024-03-29T19:31:42+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 29 19:31:43 volumio go-librespot[7376]: time="2024-03-29T19:31:43+08:00" level=debug msg="completed keyexchange" Mar 29 19:31:43 volumio go-librespot[7376]: time="2024-03-29T19:31:43+08:00" level=debug msg="completed challenge" Mar 29 19:31:43 volumio go-librespot[7376]: time="2024-03-29T19:31:43+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: TravelRestriction" Mar 29 19:31:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 19:31:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 19:31:43 volumio volumio[919]: info: Connection to go-librespot Websocket closed Mar 29 19:31:43 volumio wpa_supplicant[755]: wlan0: Failed to initiate sched scan Mar 29 19:31:45 volumio volumio[919]: info: Getting Spotify volume Mar 29 19:31:45 volumio volumio[919]: (node:919) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 19:31:45 volumio volumio[919]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 29 19:31:45 volumio volumio[919]: (node:919) 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: 229) Mar 29 19:31:45 volumio volumio[919]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Mar 29 19:31:45 volumio volumio[919]: info: CoreCommandRouter::volumioGetState Mar 29 19:31:45 volumio volumio[919]: info: CorePlayQueue::getTrack 14 Mar 29 19:31:45 volumio volumio[919]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 29 19:31:45 volumio volumio[919]: SPOTIFY: SPOTIFY VOLUME 99 Mar 29 19:31:45 volumio volumio[919]: SPOTIFY: VOLUMIO VOLUME 100 Mar 29 19:31:45 volumio volumio[919]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 29 19:31:46 volumio volumio[919]: info: Initializing connection to go-librespot Websocket Mar 29 19:31:46 volumio volumio[919]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 19:31:46 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 19:31:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 277. Mar 29 19:31:46 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 19:31:46 volumio systemd[1]: Started go-librespot Daemon. Mar 29 19:31:46 volumio go-librespot[7398]: Librespot-go daemon starting... Mar 29 19:31:46 volumio go-librespot[7398]: time="2024-03-29T19:31:46+08:00" level=info msg="generated new device id: 379eddf7fbcc359a78c2f13ac38f79662bb3888f" Mar 29 19:31:46 volumio go-librespot[7398]: time="2024-03-29T19:31:46+08:00" level=debug msg="stored credentials not found" Mar 29 19:31:47 volumio go-librespot[7398]: time="2024-03-29T19:31:47+08:00" level=debug msg="obtained new client token: AADWUqkj/wLjkvjIF1Qc7pC7SQluG2mvCOspUz2XSJ03Y1JoJE+FcG/DFBkzmvAjH122w+tO+nKG2yV5eA4tWuivN7FbHigZLnMnvGMw04KEllvo7WohiAqmrFqmKmXnJjb4ih8QB7CVhEFHdWPJXs/WlDwPfukuwUqkhk8o9la9B6U/FcMhNHYm8p38HJxpi9wx1/OpoWI473rHBcafDgrMi4V1HPsmAJSmH4q6rCjfU895EgnMCOSF0C7SXw==" Mar 29 19:31:48 volumio go-librespot[7398]: time="2024-03-29T19:31:48+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 29 19:31:49 volumio go-librespot[7398]: time="2024-03-29T19:31:49+08:00" level=debug msg="completed keyexchange" Mar 29 19:31:49 volumio go-librespot[7398]: time="2024-03-29T19:31:49+08:00" level=debug msg="completed challenge" Mar 29 19:31:49 volumio go-librespot[7398]: time="2024-03-29T19:31:49+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: TravelRestriction" Mar 29 19:31:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 19:31:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 19:31:49 volumio volumio[919]: info: Initializing connection to go-librespot Websocket Mar 29 19:31:49 volumio volumio[919]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 19:31:49 volumio wpa_supplicant[755]: wlan0: Failed to initiate sched scan Mar 29 19:31:52 volumio volumio[919]: info: Initializing connection to go-librespot Websocket Mar 29 19:31:52 volumio volumio[919]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 19:31:52 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 19:31:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 278. Mar 29 19:31:52 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 19:31:52 volumio systemd[1]: Started go-librespot Daemon. Mar 29 19:31:52 volumio go-librespot[7417]: Librespot-go daemon starting... Mar 29 19:31:52 volumio go-librespot[7417]: time="2024-03-29T19:31:52+08:00" level=info msg="generated new device id: eda3130ba97d5fab1b934cd063a13480ef4f7b30" Mar 29 19:31:52 volumio go-librespot[7417]: time="2024-03-29T19:31:52+08:00" level=debug msg="stored credentials not found" Mar 29 19:31:54 volumio go-librespot[7417]: time="2024-03-29T19:31:54+08:00" level=debug msg="obtained new client token: AACt1pVEFnB6VFWuDFjXLk3noedHa9HD2uL8i/Hz5qCTMbbb6YvkdD8r6RhZAJfBNsEb7JQ5yTybqG5fHI2Ww6W2c79aOKBu/a3lXGFWU8/NWMNF76OtW+H5v/UqMR82baxEnoRuLKzsSjKvfdMH5JviOYXBuP/ZdhvmX+JrxQmJFcjZMGM4e93pDZ22narGgwQkgP1XkKyJ6xMS4Itbw+c4njXhNwlKfo/W/4M4gZwHlE+DyP/Ud60kzcj1xQ==" Mar 29 19:31:55 volumio volumio[919]: info: CALLMETHOD: miscellanea appearance setVolumio3UI [object Object] Mar 29 19:31:55 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: appearance , setVolumio3UI Mar 29 19:31:55 volumio go-librespot[7417]: time="2024-03-29T19:31:55+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 29 19:31:55 volumio go-librespot[7417]: time="2024-03-29T19:31:55+08:00" level=debug msg="completed keyexchange" Mar 29 19:31:55 volumio volumio[919]: info: Initializing connection to go-librespot Websocket Mar 29 19:31:55 volumio go-librespot[7417]: time="2024-03-29T19:31:55+08:00" level=debug msg="new websocket client" Mar 29 19:31:55 volumio volumio[919]: info: Connection to go-librespot Websocket established Mar 29 19:31:55 volumio wpa_supplicant[755]: wlan0: Failed to initiate sched scan Mar 29 19:31:56 volumio go-librespot[7417]: time="2024-03-29T19:31:56+08:00" level=debug msg="completed challenge" Mar 29 19:31:56 volumio go-librespot[7417]: time="2024-03-29T19:31:56+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: TravelRestriction" Mar 29 19:31:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 19:31:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 19:31:56 volumio volumio[919]: info: Connection to go-librespot Websocket closed Mar 29 19:31:57 volumio volumio[919]: info: CoreCommandRouter::Reload Ui Mar 29 19:31:58 volumio sudo[7443]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 29 19:31:58 volumio sudo[7443]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 29 19:31:58 volumio sudo[7443]: pam_unix(sudo:session): session closed for user root Mar 29 19:31:58 volumio sudo[7446]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 29 19:31:58 volumio sudo[7446]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 29 19:31:58 volumio sudo[7446]: pam_unix(sudo:session): session closed for user root Mar 29 19:31:58 volumio volumio[919]: verbose: New Socket.io Connection to 192.168.2.103 from 192.168.2.101 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/15.4 Safari/605.1.15 Total Clients: 9 Mar 29 19:31:58 volumio volumio[919]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 29 19:31:58 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Mar 29 19:31:58 volumio volumio[919]: info: CoreCommandRouter::volumioGetState Mar 29 19:31:58 volumio volumio[919]: info: CorePlayQueue::getTrack 14 Mar 29 19:31:58 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Mar 29 19:31:58 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 29 19:31:58 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 29 19:31:58 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 29 19:31:58 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Mar 29 19:31:58 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Mar 29 19:31:58 volumio volumio[919]: info: Getting Spotify volume Mar 29 19:31:58 volumio volumio[919]: (node:919) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 19:31:58 volumio volumio[919]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 29 19:31:58 volumio volumio[919]: (node:919) 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: 230) Mar 29 19:31:58 volumio volumio[919]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Mar 29 19:31:58 volumio volumio[919]: info: CoreCommandRouter::volumioGetState Mar 29 19:31:58 volumio volumio[919]: info: CorePlayQueue::getTrack 14 Mar 29 19:31:58 volumio volumio[919]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 29 19:31:58 volumio volumio[919]: SPOTIFY: SPOTIFY VOLUME 99 Mar 29 19:31:58 volumio volumio[919]: SPOTIFY: VOLUMIO VOLUME 100 Mar 29 19:31:58 volumio volumio[919]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 29 19:31:58 volumio volumio[919]: info: Received Get System Version Mar 29 19:31:58 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 29 19:31:59 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: appearance , getBackgrounds Mar 29 19:31:59 volumio volumio[919]: info: Initializing connection to go-librespot Websocket Mar 29 19:31:59 volumio volumio[919]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 19:31:59 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 19:31:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 279. Mar 29 19:31:59 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 19:31:59 volumio systemd[1]: Started go-librespot Daemon. Mar 29 19:31:59 volumio go-librespot[7464]: Librespot-go daemon starting... Mar 29 19:31:59 volumio go-librespot[7464]: time="2024-03-29T19:31:59+08:00" level=info msg="generated new device id: 5ea3c1837af76f6eaecd6a04a8932cd7e76b5ef6" Mar 29 19:31:59 volumio go-librespot[7464]: time="2024-03-29T19:31:59+08:00" level=debug msg="stored credentials not found" Mar 29 19:31:59 volumio volumio[919]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 29 19:32:00 volumio go-librespot[7464]: time="2024-03-29T19:32:00+08:00" level=debug msg="obtained new client token: AADUUctnZ9Nl+19Ezz9hiliR6oMZUZPPeXciAD753Fi3tIwdj5u3ir38xBtSaJdidPvysY9nwvP3J8WQx/t1Rst5O6d/G9PNiyvp6o96YFQYR8XWJlzNreh9gfHJ8dw6DcR30usJULBkfD/o5O2bi7B6/IKDRSw4YymWJA7eDBTP8sq6ov8tQPv28FbAu63DQuhnGA01LDzSZRNNeLZ+1FVWiLurEUbr6KV/JN39rQEBZanZkC6GOw87WD2Z7g==" Mar 29 19:32:01 volumio go-librespot[7464]: time="2024-03-29T19:32: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 29 19:32:01 volumio go-librespot[7464]: time="2024-03-29T19:32:01+08:00" level=debug msg="completed keyexchange" Mar 29 19:32:01 volumio go-librespot[7464]: time="2024-03-29T19:32:01+08:00" level=debug msg="completed challenge" Mar 29 19:32:01 volumio go-librespot[7464]: time="2024-03-29T19:32:01+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: TravelRestriction" Mar 29 19:32:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 19:32:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 19:32:01 volumio wpa_supplicant[755]: wlan0: Failed to initiate sched scan Mar 29 19:32:02 volumio volumio[919]: info: Initializing connection to go-librespot Websocket Mar 29 19:32:02 volumio volumio[919]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 19:32:04 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 19:32:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 280. Mar 29 19:32:04 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 19:32:04 volumio systemd[1]: Started go-librespot Daemon. Mar 29 19:32:04 volumio go-librespot[7482]: Librespot-go daemon starting... Mar 29 19:32:04 volumio go-librespot[7482]: time="2024-03-29T19:32:04+08:00" level=info msg="generated new device id: ce4b18adf5d344d9d4fd71755fd60b15e38d32ce" Mar 29 19:32:04 volumio go-librespot[7482]: time="2024-03-29T19:32:04+08:00" level=debug msg="stored credentials not found" Mar 29 19:32:05 volumio volumio[919]: info: Initializing connection to go-librespot Websocket Mar 29 19:32:05 volumio go-librespot[7482]: time="2024-03-29T19:32:05+08:00" level=debug msg="new websocket client" Mar 29 19:32:05 volumio volumio[919]: info: Connection to go-librespot Websocket established Mar 29 19:32:05 volumio go-librespot[7482]: time="2024-03-29T19:32:05+08:00" level=debug msg="obtained new client token: AADmmXOheckdHMgaVCBYa+ZjXl5Td6BneXCIy2F6LUiwRhMd4rAsys7ljlUrr/NwBKXtuuZyQiGl7+Wz/nRq9Z2+y0qq69M1RO97eCIuKTLDQ0jGf/OYbE8ra6pS73cErB4pZ6rN7fAL5iO7ZicovRec0QWnVPSeLhSeKGGvjYI39g797HVt1GWETIkmgQ4Y+kN4DQB96rD7DpYzLuHYydGzfRPZ+eoqGWAm+3SEzDgl8RhLFo3GaIhrCFTTnQ==" Mar 29 19:32:06 volumio go-librespot[7482]: time="2024-03-29T19:32: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-gew4.spotify.com:80]" Mar 29 19:32:06 volumio go-librespot[7482]: time="2024-03-29T19:32:06+08:00" level=debug msg="completed keyexchange" Mar 29 19:32:07 volumio go-librespot[7482]: time="2024-03-29T19:32:07+08:00" level=debug msg="completed challenge" Mar 29 19:32:07 volumio go-librespot[7482]: time="2024-03-29T19:32:07+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: TravelRestriction" Mar 29 19:32:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 19:32:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 19:32:07 volumio volumio[919]: info: Connection to go-librespot Websocket closed Mar 29 19:32:07 volumio wpa_supplicant[755]: wlan0: Failed to initiate sched scan Mar 29 19:32:08 volumio volumio[919]: info: Getting Spotify volume Mar 29 19:32:08 volumio volumio[919]: (node:919) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 19:32:08 volumio volumio[919]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 29 19:32:08 volumio volumio[919]: (node:919) 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: 231) Mar 29 19:32:08 volumio volumio[919]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Mar 29 19:32:08 volumio volumio[919]: info: CoreCommandRouter::volumioGetState Mar 29 19:32:08 volumio volumio[919]: info: CorePlayQueue::getTrack 14 Mar 29 19:32:08 volumio volumio[919]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 29 19:32:08 volumio volumio[919]: SPOTIFY: SPOTIFY VOLUME 99 Mar 29 19:32:08 volumio volumio[919]: SPOTIFY: VOLUMIO VOLUME 100 Mar 29 19:32:08 volumio volumio[919]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 29 19:32:10 volumio volumio[919]: info: Initializing connection to go-librespot Websocket Mar 29 19:32:10 volumio volumio[919]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 19:32:10 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 19:32:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 281. Mar 29 19:32:10 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 19:32:10 volumio systemd[1]: Started go-librespot Daemon. Mar 29 19:32:10 volumio go-librespot[7503]: Librespot-go daemon starting... Mar 29 19:32:10 volumio go-librespot[7503]: time="2024-03-29T19:32:10+08:00" level=info msg="generated new device id: c7162081b7d30a8daf086c6c1e9a5f00fb2e4e1f" Mar 29 19:32:10 volumio go-librespot[7503]: time="2024-03-29T19:32:10+08:00" level=debug msg="stored credentials not found" Mar 29 19:32:11 volumio go-librespot[7503]: time="2024-03-29T19:32:11+08:00" level=debug msg="obtained new client token: AADjL22cWwnWOJMXSyfb6SNDmgAYJatawc0HR5I8Ah8tKLSitYn0D2OAYdiUQ197ThW521RjoRkAXkaJ2oZ8nHJh95Q1C7AhMMdPtZYxQcZ44LKs4Ta52gmQKN/6OzwqwCWKR0T5FuVserPEeMIYnQHDYBY1IDLXAm5m7I3PvGtErWK3Uhz/hAjBagTT4v8UgUBus98eC4I2BxPfF0wItz5bCCa9EW+dVvRdOB9d9/mn3NY86xeP2vr7iBI=" Mar 29 19:32:11 volumio go-librespot[7503]: time="2024-03-29T19:32: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 29 19:32:12 volumio go-librespot[7503]: time="2024-03-29T19:32:12+08:00" level=debug msg="completed keyexchange" Mar 29 19:32:12 volumio go-librespot[7503]: time="2024-03-29T19:32:12+08:00" level=debug msg="completed challenge" Mar 29 19:32:12 volumio go-librespot[7503]: time="2024-03-29T19:32:12+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: TravelRestriction" Mar 29 19:32:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 19:32:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 19:32:13 volumio volumio[919]: info: Initializing connection to go-librespot Websocket Mar 29 19:32:13 volumio volumio[919]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 19:32:13 volumio wpa_supplicant[755]: wlan0: Failed to initiate sched scan Mar 29 19:32:15 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 19:32:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 282. Mar 29 19:32:15 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 19:32:15 volumio systemd[1]: Started go-librespot Daemon. Mar 29 19:32:15 volumio go-librespot[7524]: Librespot-go daemon starting... Mar 29 19:32:15 volumio go-librespot[7524]: time="2024-03-29T19:32:15+08:00" level=info msg="generated new device id: 54ab60cb5497a852c9521660929f26cac3583f10" Mar 29 19:32:15 volumio go-librespot[7524]: time="2024-03-29T19:32:15+08:00" level=debug msg="stored credentials not found" Mar 29 19:32:16 volumio volumio[919]: info: Initializing connection to go-librespot Websocket Mar 29 19:32:16 volumio go-librespot[7524]: time="2024-03-29T19:32:16+08:00" level=debug msg="new websocket client" Mar 29 19:32:16 volumio volumio[919]: info: Connection to go-librespot Websocket established Mar 29 19:32:16 volumio go-librespot[7524]: time="2024-03-29T19:32:16+08:00" level=debug msg="obtained new client token: AADNWpObQeGF0tBzfX4wViPBx0whQyiTsF114SkApFJF2xfdKPCWFFRgtA/I1q/3futElca3/0K2bczTxFx70lf9SU9kUiEfGMV01Q8ty53AN0WEt0D2tLNQdM55MzcyJHFsOsxp3OHQg5WIUISdrw6FqjphHEWa2VvRT+echxo/8G91qUo6AyZI7gLB0XFoF+YqPBTXIysspvv4Qtxm4B2PxDqunpeopU7odmyJD8p3TOCfoZtA6zotGGOhtw==" Mar 29 19:32:17 volumio go-librespot[7524]: time="2024-03-29T19:32:17+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 29 19:32:17 volumio go-librespot[7524]: time="2024-03-29T19:32:17+08:00" level=debug msg="completed keyexchange" Mar 29 19:32:18 volumio go-librespot[7524]: time="2024-03-29T19:32:18+08:00" level=debug msg="completed challenge" Mar 29 19:32:18 volumio go-librespot[7524]: time="2024-03-29T19:32:18+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: TravelRestriction" Mar 29 19:32:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 19:32:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 19:32:18 volumio volumio[919]: info: Connection to go-librespot Websocket closed Mar 29 19:32:19 volumio volumio[919]: info: Getting Spotify volume Mar 29 19:32:19 volumio volumio[919]: (node:919) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 19:32:19 volumio volumio[919]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 29 19:32:19 volumio volumio[919]: (node:919) 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: 232) Mar 29 19:32:19 volumio volumio[919]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Mar 29 19:32:19 volumio volumio[919]: info: CoreCommandRouter::volumioGetState Mar 29 19:32:19 volumio volumio[919]: info: CorePlayQueue::getTrack 14 Mar 29 19:32:19 volumio volumio[919]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 29 19:32:19 volumio volumio[919]: SPOTIFY: SPOTIFY VOLUME 99 Mar 29 19:32:19 volumio volumio[919]: SPOTIFY: VOLUMIO VOLUME 100 Mar 29 19:32:19 volumio volumio[919]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 29 19:32:19 volumio wpa_supplicant[755]: wlan0: Failed to initiate sched scan Mar 29 19:32:21 volumio volumio[919]: info: Initializing connection to go-librespot Websocket Mar 29 19:32:21 volumio volumio[919]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 19:32:21 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 19:32:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 283. Mar 29 19:32:21 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 19:32:21 volumio systemd[1]: Started go-librespot Daemon. Mar 29 19:32:21 volumio go-librespot[7542]: Librespot-go daemon starting... Mar 29 19:32:21 volumio go-librespot[7542]: time="2024-03-29T19:32:21+08:00" level=info msg="generated new device id: d45c0501e72a0baeb230afcf7b5a254d54a3e01c" Mar 29 19:32:21 volumio go-librespot[7542]: time="2024-03-29T19:32:21+08:00" level=debug msg="stored credentials not found" Mar 29 19:32:22 volumio go-librespot[7542]: time="2024-03-29T19:32:22+08:00" level=debug msg="obtained new client token: AACWJVcFNeXm7ttlcnaiZC0Bpzu7bP0HVM+YiiaQPN7RFbgxUU9pVjMfu7xs8CNYnFvj8sI5Jl89cx9xmYleEuZd6I6+GtfbuArYxBKSDIC4BKY658wlo5WPAIQP6Aaif28oGPTy4PHyEtlP5jktlbzA9UZ52ROX02uGbjpP+RdDGalS/kmlgDBJuuGAf9lESL6+e8z+hmrzEPMbuaPUNtvJF1X6WB2+zRw+ySZTcuD8DVGmidMcRdm0wEhNKw==" Mar 29 19:32:23 volumio go-librespot[7542]: time="2024-03-29T19:32: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 29 19:32:23 volumio go-librespot[7542]: time="2024-03-29T19:32:23+08:00" level=debug msg="completed keyexchange" Mar 29 19:32:23 volumio go-librespot[7542]: time="2024-03-29T19:32:23+08:00" level=debug msg="completed challenge" Mar 29 19:32:24 volumio go-librespot[7542]: time="2024-03-29T19:32:24+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: TravelRestriction" Mar 29 19:32:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 19:32:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 19:32:24 volumio volumio[919]: info: Initializing connection to go-librespot Websocket Mar 29 19:32:24 volumio volumio[919]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 19:32:25 volumio wpa_supplicant[755]: wlan0: Failed to initiate sched scan Mar 29 19:32:27 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 19:32:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 284. Mar 29 19:32:27 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 19:32:27 volumio systemd[1]: Started go-librespot Daemon. Mar 29 19:32:27 volumio go-librespot[7562]: Librespot-go daemon starting... Mar 29 19:32:27 volumio go-librespot[7562]: time="2024-03-29T19:32:27+08:00" level=info msg="generated new device id: 7392a57b48e99e20e3b8e8fe81c4b24b113ab880" Mar 29 19:32:27 volumio go-librespot[7562]: time="2024-03-29T19:32:27+08:00" level=debug msg="stored credentials not found" Mar 29 19:32:27 volumio volumio[919]: info: Initializing connection to go-librespot Websocket Mar 29 19:32:27 volumio go-librespot[7562]: time="2024-03-29T19:32:27+08:00" level=debug msg="new websocket client" Mar 29 19:32:27 volumio volumio[919]: info: Connection to go-librespot Websocket established Mar 29 19:32:28 volumio go-librespot[7562]: time="2024-03-29T19:32:28+08:00" level=debug msg="obtained new client token: AAAssT4OVoot684S4KhVvGtY+YCiuGAG4bFuAJTNy3KjU5WMSFpD6h7bF9V7KbimF+cfIxvDW79scFm2reORyUGAaXwaZVtVAFR2foVjQ/IDKtuo27PALfpN09q8psppp97JYAvnW9IdBSr06H0tZLwuXWg8NE6uH48msysn+TK/+lKQLkKSsswomobr5IlUF5TKPYuLHrz+Vzwa6KXza7IrZt1MTUj14BrBmbRpOxshVMV0Wvmk7pK/zbe0Ww==" Mar 29 19:32:28 volumio go-librespot[7562]: time="2024-03-29T19:32: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 29 19:32:29 volumio go-librespot[7562]: time="2024-03-29T19:32:29+08:00" level=debug msg="completed keyexchange" Mar 29 19:32:29 volumio go-librespot[7562]: time="2024-03-29T19:32:29+08:00" level=debug msg="completed challenge" Mar 29 19:32:29 volumio go-librespot[7562]: time="2024-03-29T19:32:29+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: TravelRestriction" Mar 29 19:32:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 19:32:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 19:32:29 volumio volumio[919]: info: Connection to go-librespot Websocket closed Mar 29 19:32:30 volumio volumio[919]: info: Getting Spotify volume Mar 29 19:32:30 volumio volumio[919]: (node:919) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 19:32:30 volumio volumio[919]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 29 19:32:30 volumio volumio[919]: (node:919) 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: 233) Mar 29 19:32:30 volumio volumio[919]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Mar 29 19:32:30 volumio volumio[919]: info: CoreCommandRouter::volumioGetState Mar 29 19:32:30 volumio volumio[919]: info: CorePlayQueue::getTrack 14 Mar 29 19:32:30 volumio volumio[919]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 29 19:32:30 volumio volumio[919]: SPOTIFY: SPOTIFY VOLUME 99 Mar 29 19:32:30 volumio volumio[919]: SPOTIFY: VOLUMIO VOLUME 100 Mar 29 19:32:30 volumio volumio[919]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 29 19:32:31 volumio volumio[919]: info: CorePlayQueue::getTrack 14 Mar 29 19:32:31 volumio volumio[919]: info: CorePlayQueue::getTrack 33 Mar 29 19:32:31 volumio volumio[919]: info: Prefetching next song Mar 29 19:32:31 volumio volumio[919]: info: DOING PREFETCH IN MPD Mar 29 19:32:31 volumio volumio[919]: verbose: ControllerMpd::sendMpdCommand add "USB/F852-27F4/06 沉默是金.wav" Mar 29 19:32:31 volumio volumio[919]: info: sendMpdCommand add "USB/F852-27F4/06 沉默是金.wav" took 4 milliseconds Mar 29 19:32:31 volumio volumio[919]: verbose: ControllerMpd::sendMpdCommand consume 1 Mar 29 19:32:31 volumio volumio[919]: info: Mar 29 19:32:31 volumio volumio[919]: ---------------------------- MPD announces system playlist update Mar 29 19:32:31 volumio volumio[919]: info: Ignoring MPD Status Update Mar 29 19:32:31 volumio volumio[919]: info: sendMpdCommand consume 1 took 4 milliseconds Mar 29 19:32:31 volumio volumio[919]: info: Mar 29 19:32:31 volumio volumio[919]: ---------------------------- MPD announces system playlist update Mar 29 19:32:31 volumio volumio[919]: info: Ignoring MPD Status Update Mar 29 19:32:31 volumio volumio[919]: info: Mar 29 19:32:31 volumio volumio[919]: ---------------------------- MPD announces system playlist update Mar 29 19:32:31 volumio volumio[919]: info: Ignoring MPD Status Update Mar 29 19:32:31 volumio volumio[919]: info: ------------------------------ 8ms Mar 29 19:32:31 volumio volumio[919]: info: ------------------------------ 5ms Mar 29 19:32:31 volumio volumio[919]: info: ------------------------------ 3ms Mar 29 19:32:31 volumio wpa_supplicant[755]: wlan0: Failed to initiate sched scan Mar 29 19:32:32 volumio volumio[919]: info: Initializing connection to go-librespot Websocket Mar 29 19:32:32 volumio volumio[919]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 19:32:32 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 19:32:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 285. Mar 29 19:32:32 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 19:32:32 volumio systemd[1]: Started go-librespot Daemon. Mar 29 19:32:32 volumio go-librespot[7624]: Librespot-go daemon starting... Mar 29 19:32:32 volumio go-librespot[7624]: time="2024-03-29T19:32:32+08:00" level=info msg="generated new device id: 1be0aea113bb4f6c422dbb9f7b858cb305c02fa3" Mar 29 19:32:32 volumio go-librespot[7624]: time="2024-03-29T19:32:32+08:00" level=debug msg="stored credentials not found" Mar 29 19:32:33 volumio go-librespot[7624]: time="2024-03-29T19:32:33+08:00" level=debug msg="obtained new client token: AAAIoZjNACxGeKdyuvcTjyG8k0nyVwH654zL/6Yrv+McQeD19JMBHsRdS+crs+X0b6IUDTHISYV9AGTvgVwjUoZ29rHuKfUsEYpLIknaW+6tkt4yRQgeFsYFItTlHnB+sy/CBWjzyBZNOprlpUC8Ug7iT09LmyN80CLp2gbmUpWnKA8xC+KjDjDH+9fO8yc2JFvNaLENtrGxfxZBywRH4fDc7xcDBCkYq9Z5iv/MbE+cCpC3GIsj/gp0sHOOrg==" Mar 29 19:32:34 volumio volumio[919]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 29 19:32:34 volumio volumio[919]: Error: connect ETIMEDOUT 98.159.108.57:80 Mar 29 19:32:34 volumio volumio[919]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) { Mar 29 19:32:34 volumio volumio[919]: errno: -110, Mar 29 19:32:34 volumio volumio[919]: code: 'ETIMEDOUT', Mar 29 19:32:34 volumio volumio[919]: syscall: 'connect', Mar 29 19:32:34 volumio volumio[919]: address: '98.159.108.57', Mar 29 19:32:34 volumio volumio[919]: port: 80 Mar 29 19:32:34 volumio volumio[919]: } Mar 29 19:32:34 volumio volumio[919]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 29 19:32:34 volumio go-librespot[7624]: time="2024-03-29T19:32:34+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 29 19:32:34 volumio go-librespot[7624]: time="2024-03-29T19:32:34+08:00" level=debug msg="completed keyexchange" Mar 29 19:32:35 volumio go-librespot[7624]: time="2024-03-29T19:32:35+08:00" level=debug msg="completed challenge" Mar 29 19:32:35 volumio go-librespot[7624]: time="2024-03-29T19:32:35+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: TravelRestriction" Mar 29 19:32:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 19:32:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 19:32:35 volumio sudo[7645]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-03-29 19:31 Mar 29 19:32:35 volumio sudo[7645]: 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="7f9f1bf001add7a8b19a4516e3c74ef598b2730d" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="512433c3e91cdaed7ecd2808b21adeffc2137d7f" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 21 Feb 2024 09:37:22 PM CET" VOLUMIO_VERSION="3.631" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fdd9dd1169c06c1ad0a30ddd24c91b6b"