-- 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"