-- Logs begin at Thu 2019-02-14 18:11:59 CST, end at Fri 2024-04-26 16:05:30 CST. -- Apr 26 16:04:00 volumio go-librespot[3455]: time="2024-04-26T16:04:00+08:00" level=debug msg="completed keyexchange" Apr 26 16:04:01 volumio go-librespot[3455]: time="2024-04-26T16:04:01+08:00" level=debug msg="completed challenge" Apr 26 16:04:01 volumio go-librespot[3455]: time="2024-04-26T16:04: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" Apr 26 16:04:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 26 16:04:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 26 16:04:01 volumio systemd[1]: Starting Cleanup of Temporary Directories... Apr 26 16:04:01 volumio systemd[1]: systemd-tmpfiles-clean.service: Succeeded. Apr 26 16:04:01 volumio systemd[1]: Started Cleanup of Temporary Directories. Apr 26 16:04:01 volumio volumio[868]: info: Initializing connection to go-librespot Websocket Apr 26 16:04:01 volumio volumio[868]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 26 16:04:04 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 26 16:04:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 112. Apr 26 16:04:04 volumio systemd[1]: Stopped go-librespot Daemon. Apr 26 16:04:04 volumio systemd[1]: Started go-librespot Daemon. Apr 26 16:04:04 volumio go-librespot[3469]: Librespot-go daemon starting... Apr 26 16:04:04 volumio go-librespot[3469]: time="2024-04-26T16:04:04+08:00" level=info msg="generated new device id: 0524b9aa43206431c07388465e462cfb6433bbdf" Apr 26 16:04:04 volumio go-librespot[3469]: time="2024-04-26T16:04:04+08:00" level=debug msg="stored credentials not found" Apr 26 16:04:04 volumio volumio[868]: info: Initializing connection to go-librespot Websocket Apr 26 16:04:04 volumio go-librespot[3469]: time="2024-04-26T16:04:04+08:00" level=debug msg="new websocket client" Apr 26 16:04:04 volumio volumio[868]: info: Connection to go-librespot Websocket established Apr 26 16:04:04 volumio go-librespot[3469]: time="2024-04-26T16:04:04+08:00" level=debug msg="obtained new client token: AAAIFHmq01F/zF+B4kMWII9JT/Sc8Bop2PHkwigOHCUyiGSn4dDpM4c7UrUrGaV/GUPJJeZKT4aq50W04sTDXI7VEK6W9NE4s/YdWCUrq7tnFYvaNJ9ZQPddIyJ8qiXpTzf8ENVJvE7okirifdG5Xv5SQLjC+minXJp/fDK/PJcomtL6mkF+BAixkT/mC982e9lqIbnP/AR3tkphkJ90P1+iSuD5zjkqTV4dPAl7SFVa4nCK3j10X78NVgIGmMdh" Apr 26 16:04:05 volumio go-librespot[3469]: time="2024-04-26T16:04:05+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 26 16:04:05 volumio go-librespot[3469]: time="2024-04-26T16:04:05+08:00" level=debug msg="completed keyexchange" Apr 26 16:04:06 volumio go-librespot[3469]: time="2024-04-26T16:04:06+08:00" level=debug msg="completed challenge" Apr 26 16:04:06 volumio go-librespot[3469]: time="2024-04-26T16:04:06+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" Apr 26 16:04:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 26 16:04:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 26 16:04:06 volumio volumio[868]: info: Connection to go-librespot Websocket closed Apr 26 16:04:07 volumio volumio[868]: info: Getting Spotify volume Apr 26 16:04:07 volumio volumio[868]: (node:868) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 26 16:04:07 volumio volumio[868]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 26 16:04:07 volumio volumio[868]: (node:868) 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: 60) Apr 26 16:04:07 volumio volumio[868]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Apr 26 16:04:07 volumio volumio[868]: info: CoreCommandRouter::volumioGetState Apr 26 16:04:07 volumio volumio[868]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Apr 26 16:04:09 volumio volumio[868]: info: Initializing connection to go-librespot Websocket Apr 26 16:04:09 volumio volumio[868]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 26 16:04:09 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 26 16:04:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 113. Apr 26 16:04:09 volumio systemd[1]: Stopped go-librespot Daemon. Apr 26 16:04:09 volumio systemd[1]: Started go-librespot Daemon. Apr 26 16:04:09 volumio go-librespot[3479]: Librespot-go daemon starting... Apr 26 16:04:09 volumio go-librespot[3479]: time="2024-04-26T16:04:09+08:00" level=info msg="generated new device id: ca5901377274f20ba6452e42680ca446219bdc2a" Apr 26 16:04:09 volumio go-librespot[3479]: time="2024-04-26T16:04:09+08:00" level=debug msg="stored credentials not found" Apr 26 16:04:09 volumio go-librespot[3479]: time="2024-04-26T16:04:09+08:00" level=debug msg="obtained new client token: AADInZ3PsBpsmLrib1QasN+e63HR7nWlvkwCYdykrso1T5xc6+FXyYm+jVFOP6oNEPa+lXTy2o7fPJrKyRSWOPw9bQhyFCRy0GBRLOZDdHCP+UXA0qG/5pS8dEAabcFNjXXJDedBfeQggEPe4paHIq71cMsr5ZaJNIH196KXQF35/rjs3lNgzo9Er+uPhj0j78mEwhhl6q8qBaXcst8bpyx87f9hOquV3H3OuvNpEId38L3ZTb/9hqFRKnDICSjF" Apr 26 16:04:10 volumio go-librespot[3479]: time="2024-04-26T16:04:10+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]" Apr 26 16:04:10 volumio go-librespot[3479]: time="2024-04-26T16:04:10+08:00" level=debug msg="completed keyexchange" Apr 26 16:04:11 volumio go-librespot[3479]: time="2024-04-26T16:04:11+08:00" level=debug msg="completed challenge" Apr 26 16:04:11 volumio go-librespot[3479]: time="2024-04-26T16:04:11+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" Apr 26 16:04:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 26 16:04:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 26 16:04:12 volumio volumio[868]: info: Initializing connection to go-librespot Websocket Apr 26 16:04:12 volumio volumio[868]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 26 16:04:14 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 26 16:04:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 114. Apr 26 16:04:14 volumio systemd[1]: Stopped go-librespot Daemon. Apr 26 16:04:14 volumio systemd[1]: Started go-librespot Daemon. Apr 26 16:04:14 volumio go-librespot[3488]: Librespot-go daemon starting... Apr 26 16:04:14 volumio go-librespot[3488]: time="2024-04-26T16:04:14+08:00" level=info msg="generated new device id: 9961bbf548983252802ea8eca4672fe770381728" Apr 26 16:04:14 volumio go-librespot[3488]: time="2024-04-26T16:04:14+08:00" level=debug msg="stored credentials not found" Apr 26 16:04:14 volumio go-librespot[3488]: time="2024-04-26T16:04:14+08:00" level=debug msg="obtained new client token: AADxEDiA8D18QCwe2b9sYNcRUY/odBx7K3jUKdsXmxSx2EbGWVXLPnAhA1G2hGuDAKj8QqOt+kahIprkYBrk2P10AGLu1LAb1fpwoNdBC2LYwm8kDRe+u4Zj+dHOAcRImsErcsUBUqNKAZFzd9E8tJECuD/poc2hxJYS8x3mHrGAtn9vnGpCKHxZtBWo+mu4Vnf2Hq4R15naPk1aOkK6pzaKDJJ5xq9DjCTQQ1gJZ8wT6ih/CQlFNLOVQkOiuDQP" Apr 26 16:04:15 volumio volumio[868]: info: Initializing connection to go-librespot Websocket Apr 26 16:04:15 volumio go-librespot[3488]: time="2024-04-26T16:04:15+08:00" level=debug msg="new websocket client" Apr 26 16:04:15 volumio volumio[868]: info: Connection to go-librespot Websocket established Apr 26 16:04:15 volumio go-librespot[3488]: time="2024-04-26T16:04:15+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]" Apr 26 16:04:15 volumio go-librespot[3488]: time="2024-04-26T16:04:15+08:00" level=debug msg="completed keyexchange" Apr 26 16:04:16 volumio go-librespot[3488]: time="2024-04-26T16:04:16+08:00" level=debug msg="completed challenge" Apr 26 16:04:16 volumio go-librespot[3488]: time="2024-04-26T16:04:16+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" Apr 26 16:04:16 volumio volumio[868]: info: Connection to go-librespot Websocket closed Apr 26 16:04:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 26 16:04:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 26 16:04:18 volumio volumio[868]: info: Getting Spotify volume Apr 26 16:04:18 volumio volumio[868]: (node:868) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 26 16:04:18 volumio volumio[868]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 26 16:04:18 volumio volumio[868]: (node:868) 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: 61) Apr 26 16:04:18 volumio volumio[868]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Apr 26 16:04:18 volumio volumio[868]: info: CoreCommandRouter::volumioGetState Apr 26 16:04:18 volumio volumio[868]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Apr 26 16:04:19 volumio volumio[868]: info: Initializing connection to go-librespot Websocket Apr 26 16:04:19 volumio volumio[868]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 26 16:04:19 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 26 16:04:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 115. Apr 26 16:04:19 volumio systemd[1]: Stopped go-librespot Daemon. Apr 26 16:04:19 volumio systemd[1]: Started go-librespot Daemon. Apr 26 16:04:19 volumio go-librespot[3537]: Librespot-go daemon starting... Apr 26 16:04:19 volumio go-librespot[3537]: time="2024-04-26T16:04:19+08:00" level=info msg="generated new device id: 196c6fc3893ffa4909c79ebc7974f497fcdb6092" Apr 26 16:04:19 volumio go-librespot[3537]: time="2024-04-26T16:04:19+08:00" level=debug msg="stored credentials not found" Apr 26 16:04:20 volumio go-librespot[3537]: time="2024-04-26T16:04:20+08:00" level=debug msg="obtained new client token: AAAVhpCYCbFjUZGxZ8yhMFfeb3xz2U+wMO8ZjabFN5vkymdTjX2lMiMibU+xXKN/dfhfoFRWCC388fGMbfLvajHb9ng0+z4pewtBkzQ6K5WwT0zz4Y/JlLf79eo/nQXfXgSuUz0+cuBDNlH/hEY1tyYMT542qMFirt9t2TbUQIM86pgw/dt+W9fWoWW8X28/2mVIFAZMataHsGlNdAhx5LL5JFn4pNG4Z7a4CLMd2Yernkiq+hsKkNwe8S8AmA==" Apr 26 16:04:20 volumio go-librespot[3537]: time="2024-04-26T16:04: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Apr 26 16:04:20 volumio go-librespot[3537]: time="2024-04-26T16:04:20+08:00" level=debug msg="completed keyexchange" Apr 26 16:04:21 volumio go-librespot[3537]: time="2024-04-26T16:04:21+08:00" level=debug msg="completed challenge" Apr 26 16:04:21 volumio go-librespot[3537]: time="2024-04-26T16:04: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" Apr 26 16:04:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 26 16:04:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 26 16:04:22 volumio volumio[868]: info: Initializing connection to go-librespot Websocket Apr 26 16:04:22 volumio volumio[868]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 26 16:04:24 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 26 16:04:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 116. Apr 26 16:04:24 volumio systemd[1]: Stopped go-librespot Daemon. Apr 26 16:04:24 volumio systemd[1]: Started go-librespot Daemon. Apr 26 16:04:24 volumio go-librespot[3545]: Librespot-go daemon starting... Apr 26 16:04:24 volumio go-librespot[3545]: time="2024-04-26T16:04:24+08:00" level=info msg="generated new device id: 96ef89b85ff5328f0dd9671b86e05c0a5a04f069" Apr 26 16:04:24 volumio go-librespot[3545]: time="2024-04-26T16:04:24+08:00" level=debug msg="stored credentials not found" Apr 26 16:04:25 volumio go-librespot[3545]: time="2024-04-26T16:04:25+08:00" level=debug msg="obtained new client token: AAAYBj2gnhITN7tTPwSw/UepQhkWsA95mse15/5gA5ZDKbYR+jNxy6kmq4gxOMR5G/4Sbtz1aCRHQNMXfoeuVcbgm1/RTbj8xrRH/cIqlZHdmfOa4kaQel6UfbuJiyDnSzausTsRkVczERXt7TzXo8U4r7Ebk/nIXBytGyiq/K+FJpuo2p2Pc2Fm42DkkWVcxPp79AX8U46udZ5qUcG8TPXwAv8Wt1Pp8ICHzegQxwEkRd/f5lTSn7UAtaHUSA==" Apr 26 16:04:25 volumio volumio[868]: info: Initializing connection to go-librespot Websocket Apr 26 16:04:25 volumio volumio[868]: info: Connection to go-librespot Websocket established Apr 26 16:04:25 volumio go-librespot[3545]: time="2024-04-26T16:04:25+08:00" level=debug msg="new websocket client" Apr 26 16:04:25 volumio go-librespot[3545]: time="2024-04-26T16:04:25+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]" Apr 26 16:04:25 volumio go-librespot[3545]: time="2024-04-26T16:04:25+08:00" level=debug msg="completed keyexchange" Apr 26 16:04:26 volumio go-librespot[3545]: time="2024-04-26T16:04:26+08:00" level=debug msg="completed challenge" Apr 26 16:04:26 volumio go-librespot[3545]: time="2024-04-26T16:04: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" Apr 26 16:04:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 26 16:04:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 26 16:04:26 volumio volumio[868]: info: Connection to go-librespot Websocket closed Apr 26 16:04:28 volumio volumio[868]: info: Getting Spotify volume Apr 26 16:04:28 volumio volumio[868]: (node:868) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 26 16:04:28 volumio volumio[868]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 26 16:04:28 volumio volumio[868]: (node:868) 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: 62) Apr 26 16:04:28 volumio volumio[868]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Apr 26 16:04:28 volumio volumio[868]: info: CoreCommandRouter::volumioGetState Apr 26 16:04:28 volumio volumio[868]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Apr 26 16:04:29 volumio volumio[868]: info: Initializing connection to go-librespot Websocket Apr 26 16:04:29 volumio volumio[868]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 26 16:04:29 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 26 16:04:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 117. Apr 26 16:04:29 volumio systemd[1]: Stopped go-librespot Daemon. Apr 26 16:04:29 volumio systemd[1]: Started go-librespot Daemon. Apr 26 16:04:29 volumio go-librespot[3559]: Librespot-go daemon starting... Apr 26 16:04:29 volumio go-librespot[3559]: time="2024-04-26T16:04:29+08:00" level=info msg="generated new device id: ef056fed74681c0c2987f93a63d8d96013a34828" Apr 26 16:04:29 volumio go-librespot[3559]: time="2024-04-26T16:04:29+08:00" level=debug msg="stored credentials not found" Apr 26 16:04:30 volumio go-librespot[3559]: time="2024-04-26T16:04:30+08:00" level=debug msg="obtained new client token: AADi6KesqWVZ01tas0mjnRKLs+QEf1RmcptaPUBTMemCbPiJv1eJDAxKEXLoQkgFO781siWzlS5cHo/76/DoeOGjQjBs0Houdg7itvfyVMZSl0UWhLPEgpvFJM54Py4LJjzYN1O914dkjJfOAOop02aRrr5+6DKp1oe7LcWnClRyYVkEk8OMg9jF6ro3tOqopbJKzob7ybUdTbp7dT2piz/swoI4Fe87o7Ew3AxnkKp2a+sCgtYwbvdvDIWlbw==" Apr 26 16:04:30 volumio go-librespot[3559]: time="2024-04-26T16:04:30+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 26 16:04:30 volumio go-librespot[3559]: time="2024-04-26T16:04:30+08:00" level=debug msg="completed keyexchange" Apr 26 16:04:31 volumio go-librespot[3559]: time="2024-04-26T16:04:31+08:00" level=debug msg="completed challenge" Apr 26 16:04:31 volumio go-librespot[3559]: time="2024-04-26T16:04:31+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" Apr 26 16:04:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 26 16:04:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 26 16:04:32 volumio volumio[868]: info: Initializing connection to go-librespot Websocket Apr 26 16:04:32 volumio volumio[868]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 26 16:04:34 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 26 16:04:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 118. Apr 26 16:04:34 volumio systemd[1]: Stopped go-librespot Daemon. Apr 26 16:04:34 volumio systemd[1]: Started go-librespot Daemon. Apr 26 16:04:34 volumio go-librespot[3567]: Librespot-go daemon starting... Apr 26 16:04:34 volumio go-librespot[3567]: time="2024-04-26T16:04:34+08:00" level=info msg="generated new device id: be03b5b424e4fc249319c1fa4725bcaccc93382a" Apr 26 16:04:34 volumio go-librespot[3567]: time="2024-04-26T16:04:34+08:00" level=debug msg="stored credentials not found" Apr 26 16:04:35 volumio volumio[868]: info: Initializing connection to go-librespot Websocket Apr 26 16:04:35 volumio go-librespot[3567]: time="2024-04-26T16:04:35+08:00" level=debug msg="new websocket client" Apr 26 16:04:35 volumio volumio[868]: info: Connection to go-librespot Websocket established Apr 26 16:04:35 volumio go-librespot[3567]: time="2024-04-26T16:04:35+08:00" level=debug msg="obtained new client token: AAA/DCuxCeap1eeEXcEKKQZcyZ1PJxjwfv43/1lKc43ZlhsGLtjhFterd0E2QTpCLpeWS+KjRcv4u0fjgQ54qiTP7cULsimmfAOgIOqn32qqbt1BtqkZNBhwuI0J4fGI9XRUGVbNmPQ2xI7kjdPYTbOa8YEPSYGAq42h3TLMxMKYN83XTxRQbt1awwep/5dthe1tALfJiKeBUmgRFuJm6EEEaxl5wk5HMcGwuppyda/eFykfPq/n/uknIFXPg7+P" Apr 26 16:04:36 volumio go-librespot[3567]: time="2024-04-26T16:04:36+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]" Apr 26 16:04:36 volumio go-librespot[3567]: time="2024-04-26T16:04:36+08:00" level=debug msg="completed keyexchange" Apr 26 16:04:36 volumio go-librespot[3567]: time="2024-04-26T16:04:36+08:00" level=debug msg="completed challenge" Apr 26 16:04:36 volumio go-librespot[3567]: time="2024-04-26T16:04:36+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" Apr 26 16:04:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 26 16:04:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 26 16:04:36 volumio volumio[868]: info: Connection to go-librespot Websocket closed Apr 26 16:04:38 volumio volumio[868]: info: Getting Spotify volume Apr 26 16:04:38 volumio volumio[868]: (node:868) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 26 16:04:38 volumio volumio[868]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 26 16:04:38 volumio volumio[868]: (node:868) 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: 63) Apr 26 16:04:38 volumio volumio[868]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Apr 26 16:04:38 volumio volumio[868]: info: CoreCommandRouter::volumioGetState Apr 26 16:04:38 volumio volumio[868]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Apr 26 16:04:39 volumio volumio[868]: info: Initializing connection to go-librespot Websocket Apr 26 16:04:39 volumio volumio[868]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 26 16:04:39 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 26 16:04:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 119. Apr 26 16:04:39 volumio systemd[1]: Stopped go-librespot Daemon. Apr 26 16:04:39 volumio systemd[1]: Started go-librespot Daemon. Apr 26 16:04:39 volumio go-librespot[3577]: Librespot-go daemon starting... Apr 26 16:04:39 volumio go-librespot[3577]: time="2024-04-26T16:04:39+08:00" level=info msg="generated new device id: baf32b0ec909e8a793ec60080a4b360b2d74f787" Apr 26 16:04:39 volumio go-librespot[3577]: time="2024-04-26T16:04:39+08:00" level=debug msg="stored credentials not found" Apr 26 16:04:40 volumio go-librespot[3577]: time="2024-04-26T16:04:40+08:00" level=debug msg="obtained new client token: AACVG6e4b+RdqnJD4e8H9Nb6slNRR/W3ooQwGVAYzOYeMCicUokhjn+8Co7lQDn0Phu5XYGqQc45LaMkcowOzM5ksv8QyXsMwUamNi7N+IYP02co3S7UfFF4bNDt4MDKY5v4FknaQL5wc9HwG2qE9u1v6We1TSrLLQjkYW7lUJRm93dkSxON96UNouNaoYf8/HYY3FIjGk/t7IXYhu2GJWrLG7XMAxnqwmBU7BrbOCJ/+e3cfHX/QsOg8UcBjyaf" Apr 26 16:04:41 volumio go-librespot[3577]: time="2024-04-26T16:04:41+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]" Apr 26 16:04:41 volumio go-librespot[3577]: time="2024-04-26T16:04:41+08:00" level=debug msg="completed keyexchange" Apr 26 16:04:41 volumio go-librespot[3577]: time="2024-04-26T16:04:41+08:00" level=debug msg="completed challenge" Apr 26 16:04:41 volumio go-librespot[3577]: time="2024-04-26T16:04:41+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" Apr 26 16:04:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 26 16:04:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 26 16:04:42 volumio volumio[868]: info: Initializing connection to go-librespot Websocket Apr 26 16:04:42 volumio volumio[868]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 26 16:04:45 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 26 16:04:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 120. Apr 26 16:04:45 volumio systemd[1]: Stopped go-librespot Daemon. Apr 26 16:04:45 volumio systemd[1]: Started go-librespot Daemon. Apr 26 16:04:45 volumio go-librespot[3585]: Librespot-go daemon starting... Apr 26 16:04:45 volumio go-librespot[3585]: time="2024-04-26T16:04:45+08:00" level=info msg="generated new device id: f59141e317ae64a6b09a762e6a31adf23fddf011" Apr 26 16:04:45 volumio go-librespot[3585]: time="2024-04-26T16:04:45+08:00" level=debug msg="stored credentials not found" Apr 26 16:04:45 volumio go-librespot[3585]: time="2024-04-26T16:04:45+08:00" level=debug msg="obtained new client token: AACbonNsuS5QdnPypdszPHP8TiIftTeXrMbB2J8f4zmsmSA35UJi7a2kC8xaKoYD4JORmGrjZn6snsS77d1JwaiHTX6ElzJELiCMsCTsrlSqEKg+8HgYGstjG9YH60W4fphnzmTqmDlHUnghM9BM5jjc4vJy/2slDJvtsBhl3AwRDX+vMMyTg4ePwqJPH7plcZ0k+Sxaxh8P4opIhjDuO26DZVExpNtL4+WGaKjbwbbFhx+t07GSgifpdwZxgFXX" Apr 26 16:04:45 volumio volumio[868]: info: Initializing connection to go-librespot Websocket Apr 26 16:04:45 volumio go-librespot[3585]: time="2024-04-26T16:04:45+08:00" level=debug msg="new websocket client" Apr 26 16:04:45 volumio volumio[868]: info: Connection to go-librespot Websocket established Apr 26 16:04:46 volumio go-librespot[3585]: time="2024-04-26T16:04:46+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]" Apr 26 16:04:46 volumio go-librespot[3585]: time="2024-04-26T16:04:46+08:00" level=debug msg="completed keyexchange" Apr 26 16:04:46 volumio go-librespot[3585]: time="2024-04-26T16:04:46+08:00" level=debug msg="completed challenge" Apr 26 16:04:47 volumio go-librespot[3585]: time="2024-04-26T16:04:47+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" Apr 26 16:04:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 26 16:04:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 26 16:04:47 volumio volumio[868]: info: Connection to go-librespot Websocket closed Apr 26 16:04:48 volumio volumio[868]: info: Getting Spotify volume Apr 26 16:04:48 volumio volumio[868]: (node:868) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 26 16:04:48 volumio volumio[868]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 26 16:04:48 volumio volumio[868]: (node:868) 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: 64) Apr 26 16:04:48 volumio volumio[868]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Apr 26 16:04:48 volumio volumio[868]: info: CoreCommandRouter::volumioGetState Apr 26 16:04:48 volumio volumio[868]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Apr 26 16:04:50 volumio volumio[868]: info: Initializing connection to go-librespot Websocket Apr 26 16:04:50 volumio volumio[868]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 26 16:04:50 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 26 16:04:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 121. Apr 26 16:04:50 volumio systemd[1]: Stopped go-librespot Daemon. Apr 26 16:04:50 volumio systemd[1]: Started go-librespot Daemon. Apr 26 16:04:50 volumio go-librespot[3593]: Librespot-go daemon starting... Apr 26 16:04:50 volumio go-librespot[3593]: time="2024-04-26T16:04:50+08:00" level=info msg="generated new device id: 52502176c1b06a048afc2e5ebabe48b408c12494" Apr 26 16:04:50 volumio go-librespot[3593]: time="2024-04-26T16:04:50+08:00" level=debug msg="stored credentials not found" Apr 26 16:04:50 volumio go-librespot[3593]: time="2024-04-26T16:04:50+08:00" level=debug msg="obtained new client token: AAAopNI659sj8hoj4gDs42XV1sW9RvIQg9aGduJIDRIi8HBBg6KhZbJIc8EeuBDrdKp+EUHZbTpH9JZgteXyJnae6+v8IOK4pLAh3/U1RyJ5vuEhZ/HNAQilpzfTSK4IWD+oSXZW2Bg5k4BdwLvKHv43t17QwKxN3dmK3bm5iF8znNZzl2tXNfcEUcl4lSvu4x3oM3aHRu8knOfE4Z9TFHJPM2BHMEDxoejsv5BYZHZ+xNc/yGcgRKTsCVj2jC9Z" Apr 26 16:04:51 volumio go-librespot[3593]: time="2024-04-26T16:04:51+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]" Apr 26 16:04:51 volumio go-librespot[3593]: time="2024-04-26T16:04:51+08:00" level=debug msg="completed keyexchange" Apr 26 16:04:52 volumio go-librespot[3593]: time="2024-04-26T16:04:52+08:00" level=debug msg="completed challenge" Apr 26 16:04:52 volumio go-librespot[3593]: time="2024-04-26T16:04:52+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" Apr 26 16:04:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 26 16:04:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 26 16:04:53 volumio volumio[868]: info: Initializing connection to go-librespot Websocket Apr 26 16:04:53 volumio volumio[868]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 26 16:04:55 volumio volumio[868]: info: CorePlayQueue::getTrack 40 Apr 26 16:04:55 volumio volumio[868]: info: CorePlayQueue::getTrack 30 Apr 26 16:04:55 volumio volumio[868]: info: Prefetching next song Apr 26 16:04:55 volumio volumio[868]: info: DOING PREFETCH IN MPD Apr 26 16:04:55 volumio volumio[868]: verbose: ControllerMpd::sendMpdCommand add "USB/080C-B523/WAV/WAV格式音乐/05.情凭谁来定错对.wav" Apr 26 16:04:55 volumio volumio[868]: info: sendMpdCommand add "USB/080C-B523/WAV/WAV格式音乐/05.情凭谁来定错对.wav" took 1 milliseconds Apr 26 16:04:55 volumio volumio[868]: verbose: ControllerMpd::sendMpdCommand consume 1 Apr 26 16:04:55 volumio volumio[868]: info: Apr 26 16:04:55 volumio volumio[868]: ---------------------------- MPD announces system playlist update Apr 26 16:04:55 volumio volumio[868]: info: Ignoring MPD Status Update Apr 26 16:04:55 volumio volumio[868]: info: sendMpdCommand consume 1 took 3 milliseconds Apr 26 16:04:55 volumio volumio[868]: info: Apr 26 16:04:55 volumio volumio[868]: ---------------------------- MPD announces system playlist update Apr 26 16:04:55 volumio volumio[868]: info: Ignoring MPD Status Update Apr 26 16:04:55 volumio volumio[868]: info: Apr 26 16:04:55 volumio volumio[868]: ---------------------------- MPD announces system playlist update Apr 26 16:04:55 volumio volumio[868]: info: Ignoring MPD Status Update Apr 26 16:04:55 volumio volumio[868]: info: ------------------------------ 5ms Apr 26 16:04:55 volumio volumio[868]: info: ------------------------------ 2ms Apr 26 16:04:55 volumio volumio[868]: info: ------------------------------ 2ms Apr 26 16:04:55 volumio volumio[868]: error: Upnp client error: Error: This socket has been ended by the other party Apr 26 16:04:56 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 26 16:04:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 122. Apr 26 16:04:56 volumio systemd[1]: Stopped go-librespot Daemon. Apr 26 16:04:56 volumio systemd[1]: Started go-librespot Daemon. Apr 26 16:04:56 volumio go-librespot[3601]: Librespot-go daemon starting... Apr 26 16:04:56 volumio go-librespot[3601]: time="2024-04-26T16:04:56+08:00" level=info msg="generated new device id: 828d49812c290c09d2313c3610e9e5b0076b8b58" Apr 26 16:04:56 volumio go-librespot[3601]: time="2024-04-26T16:04:56+08:00" level=debug msg="stored credentials not found" Apr 26 16:04:56 volumio volumio[868]: info: Initializing connection to go-librespot Websocket Apr 26 16:04:56 volumio go-librespot[3601]: time="2024-04-26T16:04:56+08:00" level=debug msg="new websocket client" Apr 26 16:04:56 volumio volumio[868]: info: Connection to go-librespot Websocket established Apr 26 16:04:56 volumio go-librespot[3601]: time="2024-04-26T16:04:56+08:00" level=debug msg="obtained new client token: AABKVc4pv4Tmrbv+38vbcv1WTWhh1jll7Wf9CJvquxAL6WuyLeuvj4rC0vewNAJtYX3HiqrbTphklxQDBFltvGjPHj0NO87sXPFP1jE5F2iM36tu+3wC/zeewtinYoJlab8ME8FSCmDoK1ELduRmwXwuWPAqpQj9etsJ8r/fHeWlUfKPVQLLHBwBzCqF3oKk6JJRZlosfr9bGZr2Xueqqj67RLeF4szldcQVonKW8LD0VmNjN7J039o5EHu8txRC" Apr 26 16:04:57 volumio go-librespot[3601]: time="2024-04-26T16:04:57+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]" Apr 26 16:04:57 volumio go-librespot[3601]: time="2024-04-26T16:04:57+08:00" level=debug msg="completed keyexchange" Apr 26 16:04:57 volumio go-librespot[3601]: time="2024-04-26T16:04:57+08:00" level=debug msg="completed challenge" Apr 26 16:04:57 volumio go-librespot[3601]: time="2024-04-26T16:04:57+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" Apr 26 16:04:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 26 16:04:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 26 16:04:57 volumio volumio[868]: info: Connection to go-librespot Websocket closed Apr 26 16:04:59 volumio volumio[868]: info: Getting Spotify volume Apr 26 16:04:59 volumio volumio[868]: (node:868) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 26 16:04:59 volumio volumio[868]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 26 16:04:59 volumio volumio[868]: (node:868) 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: 65) Apr 26 16:04:59 volumio volumio[868]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Apr 26 16:04:59 volumio volumio[868]: info: CoreCommandRouter::volumioGetState Apr 26 16:04:59 volumio volumio[868]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Apr 26 16:04:59 volumio volumio[868]: info: CoreStateMachine::startPlaybackTimer Apr 26 16:04:59 volumio volumio[868]: info: CorePlayQueue::getTrack 30 Apr 26 16:05:00 volumio volumio[868]: info: CoreStateMachine::pushState Apr 26 16:05:00 volumio volumio[868]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 26 16:05:00 volumio volumio[868]: info: CoreCommandRouter::volumioPushState Apr 26 16:05:00 volumio volumio[868]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Apr 26 16:05:00 volumio volumio[868]: info: Initializing connection to go-librespot Websocket Apr 26 16:05:00 volumio volumio[868]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 26 16:05:01 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 26 16:05:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 123. Apr 26 16:05:01 volumio systemd[1]: Stopped go-librespot Daemon. Apr 26 16:05:01 volumio systemd[1]: Started go-librespot Daemon. Apr 26 16:05:01 volumio go-librespot[3615]: Librespot-go daemon starting... Apr 26 16:05:01 volumio go-librespot[3615]: time="2024-04-26T16:05:01+08:00" level=info msg="generated new device id: 0a4031f3dfa90bc94b54f735b6600b65f84d236e" Apr 26 16:05:01 volumio go-librespot[3615]: time="2024-04-26T16:05:01+08:00" level=debug msg="stored credentials not found" Apr 26 16:05:01 volumio go-librespot[3615]: time="2024-04-26T16:05:01+08:00" level=debug msg="obtained new client token: AACh7bvXmqqZ+1GBcl5lgKb1KzKXxeP4dL/IYT7EasFtOTDiS3UUTL+09BrZARMlElwir2G4rech2/gup3pkf1RJmGHicVlEhOPikzWCd51v73sjvWJCZkf44tZiwzIkZCgYQfIYHwBdJuHq0oyLNLDeK3ndYKn5/DHW4Ag3D9KoYijNz195PCNzd6Lh2CqeC9yWIjbAZWM9g110PQPsnvm0Nm5aY4QlbCrQFf22JsQ3RkyMJJAVAIJH0GBVCG3k" Apr 26 16:05:02 volumio go-librespot[3615]: time="2024-04-26T16:05:02+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]" Apr 26 16:05:02 volumio go-librespot[3615]: time="2024-04-26T16:05:02+08:00" level=debug msg="completed keyexchange" Apr 26 16:05:02 volumio go-librespot[3615]: time="2024-04-26T16:05:02+08:00" level=debug msg="completed challenge" Apr 26 16:05:02 volumio go-librespot[3615]: time="2024-04-26T16:05:02+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" Apr 26 16:05:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 26 16:05:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 26 16:05:03 volumio volumio[868]: info: Initializing connection to go-librespot Websocket Apr 26 16:05:03 volumio volumio[868]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 26 16:05:06 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 26 16:05:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 124. Apr 26 16:05:06 volumio systemd[1]: Stopped go-librespot Daemon. Apr 26 16:05:06 volumio systemd[1]: Started go-librespot Daemon. Apr 26 16:05:06 volumio go-librespot[3624]: Librespot-go daemon starting... Apr 26 16:05:06 volumio go-librespot[3624]: time="2024-04-26T16:05:06+08:00" level=info msg="generated new device id: fe103827244949064b626e5cb48e7589c7fb435b" Apr 26 16:05:06 volumio go-librespot[3624]: time="2024-04-26T16:05:06+08:00" level=debug msg="stored credentials not found" Apr 26 16:05:06 volumio go-librespot[3624]: time="2024-04-26T16:05:06+08:00" level=debug msg="obtained new client token: AADls0/HSBnlL/fzHcRnzz/lR45NR85WsHasaoV9MzsKlCpuRdrxPQcIF8QA4nXkl3R8NcE94BEOksK88s/xpmK8cz+EpS5qrV4QmXmIRe2Njj7/Nji3GY3arUaGSsRdLmOyX7YBrrNnRaFMyhK5FnNGPfSV5JLXXoVxZBSViXQe3MjaQClS2fRC/drnnGgqSwul95CQxsfQVapWzp93J95Hnwf+UIIrpWF0t2KaRIKAmGeA4svWo7TR78MMFhVo" Apr 26 16:05:06 volumio volumio[868]: info: Initializing connection to go-librespot Websocket Apr 26 16:05:06 volumio go-librespot[3624]: time="2024-04-26T16:05:06+08:00" level=debug msg="new websocket client" Apr 26 16:05:06 volumio volumio[868]: info: Connection to go-librespot Websocket established Apr 26 16:05:07 volumio go-librespot[3624]: time="2024-04-26T16:05:07+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]" Apr 26 16:05:07 volumio go-librespot[3624]: time="2024-04-26T16:05:07+08:00" level=debug msg="completed keyexchange" Apr 26 16:05:07 volumio go-librespot[3624]: time="2024-04-26T16:05:07+08:00" level=debug msg="completed challenge" Apr 26 16:05:07 volumio go-librespot[3624]: time="2024-04-26T16:05: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" Apr 26 16:05:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 26 16:05:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 26 16:05:07 volumio volumio[868]: info: Connection to go-librespot Websocket closed Apr 26 16:05:09 volumio volumio[868]: info: Getting Spotify volume Apr 26 16:05:09 volumio volumio[868]: (node:868) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 26 16:05:09 volumio volumio[868]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 26 16:05:09 volumio volumio[868]: (node:868) 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: 66) Apr 26 16:05:09 volumio volumio[868]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Apr 26 16:05:09 volumio volumio[868]: info: CoreCommandRouter::volumioGetState Apr 26 16:05:09 volumio volumio[868]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Apr 26 16:05:10 volumio volumio[868]: info: Initializing connection to go-librespot Websocket Apr 26 16:05:10 volumio volumio[868]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 26 16:05:11 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 26 16:05:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 125. Apr 26 16:05:11 volumio systemd[1]: Stopped go-librespot Daemon. Apr 26 16:05:11 volumio systemd[1]: Started go-librespot Daemon. Apr 26 16:05:11 volumio go-librespot[3632]: Librespot-go daemon starting... Apr 26 16:05:11 volumio go-librespot[3632]: time="2024-04-26T16:05:11+08:00" level=info msg="generated new device id: b80790664e6af994f0c08506599887a2c50ac68a" Apr 26 16:05:11 volumio go-librespot[3632]: time="2024-04-26T16:05:11+08:00" level=debug msg="stored credentials not found" Apr 26 16:05:11 volumio go-librespot[3632]: time="2024-04-26T16:05:11+08:00" level=debug msg="obtained new client token: AAAB7lbi3bFVld+Ss41J04/l+SkAadFQvrpOoM55FV3wQpWiGmVVNNbs+xXQexBhLkMbfDi+OTsfLmHhrqEvX7/VFz1gVlaZ9KBmtqeCC6hcduZZKaVsfldfjBqFEOF502NbRteCr+gNzWOBx/fF9/l81VXTF2MTN7W+9BoK8lg5uSAa0H9kcvELlSSfEnx7iVTBzeRIuUr6ncOe/Ai+rP/0jYvxcDKRsSBrAIokIuNEqIUVbjUMrIroQ/tTMhsH" Apr 26 16:05:12 volumio go-librespot[3632]: time="2024-04-26T16:05:12+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Apr 26 16:05:12 volumio go-librespot[3632]: time="2024-04-26T16:05:12+08:00" level=debug msg="completed keyexchange" Apr 26 16:05:12 volumio go-librespot[3632]: time="2024-04-26T16:05:12+08:00" level=debug msg="completed challenge" Apr 26 16:05:12 volumio go-librespot[3632]: time="2024-04-26T16:05: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" Apr 26 16:05:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 26 16:05:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 26 16:05:13 volumio volumio[868]: info: Initializing connection to go-librespot Websocket Apr 26 16:05:13 volumio volumio[868]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 26 16:05:16 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 26 16:05:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 126. Apr 26 16:05:16 volumio systemd[1]: Stopped go-librespot Daemon. Apr 26 16:05:16 volumio systemd[1]: Started go-librespot Daemon. Apr 26 16:05:16 volumio go-librespot[3640]: Librespot-go daemon starting... Apr 26 16:05:16 volumio go-librespot[3640]: time="2024-04-26T16:05:16+08:00" level=info msg="generated new device id: 47daf75ea6dc3a215b0ccfa5d00817c1920f3f15" Apr 26 16:05:16 volumio go-librespot[3640]: time="2024-04-26T16:05:16+08:00" level=debug msg="stored credentials not found" Apr 26 16:05:16 volumio go-librespot[3640]: time="2024-04-26T16:05:16+08:00" level=debug msg="obtained new client token: AAC7MpxrLIHI3TOU3dT7BpGy652+jjtcxlOq6Gl9grez1tuAdMY/NZbxMZOl1EVD7t0gX81mMnh21OqaR2VK/dN21swncrRmm1RZXrz/ZClqCnFYroYpZoK/F1TppFtXIh4ZrXOcJmGMpm9bMA1ihS9aMc6Vu4fAiifHi3c9N/AlEoRTjTU4Go7ponzSYuLLUHCSt3nnw+N6zxfxk2bdSCfUeO8h72h/7kPPXxg3MaI2V+Qf+RuPeOr2trIBVX9l" Apr 26 16:05:16 volumio volumio[868]: info: Initializing connection to go-librespot Websocket Apr 26 16:05:16 volumio go-librespot[3640]: time="2024-04-26T16:05:16+08:00" level=debug msg="new websocket client" Apr 26 16:05:16 volumio volumio[868]: info: Connection to go-librespot Websocket established Apr 26 16:05:17 volumio go-librespot[3640]: time="2024-04-26T16:05: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 26 16:05:18 volumio go-librespot[3640]: time="2024-04-26T16:05:18+08:00" level=debug msg="completed keyexchange" Apr 26 16:05:18 volumio go-librespot[3640]: time="2024-04-26T16:05:18+08:00" level=debug msg="completed challenge" Apr 26 16:05:18 volumio go-librespot[3640]: time="2024-04-26T16:05: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" Apr 26 16:05:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 26 16:05:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 26 16:05:18 volumio volumio[868]: info: Connection to go-librespot Websocket closed Apr 26 16:05:19 volumio volumio[868]: info: Getting Spotify volume Apr 26 16:05:19 volumio volumio[868]: (node:868) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 26 16:05:19 volumio volumio[868]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 26 16:05:19 volumio volumio[868]: (node:868) 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: 67) Apr 26 16:05:19 volumio volumio[868]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Apr 26 16:05:20 volumio volumio[868]: info: CoreCommandRouter::volumioGetState Apr 26 16:05:20 volumio volumio[868]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Apr 26 16:05:21 volumio volumio[868]: info: Initializing connection to go-librespot Websocket Apr 26 16:05:21 volumio volumio[868]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 26 16:05:22 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 26 16:05:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 127. Apr 26 16:05:22 volumio systemd[1]: Stopped go-librespot Daemon. Apr 26 16:05:22 volumio systemd[1]: Started go-librespot Daemon. Apr 26 16:05:22 volumio go-librespot[3692]: Librespot-go daemon starting... Apr 26 16:05:22 volumio go-librespot[3692]: time="2024-04-26T16:05:22+08:00" level=info msg="generated new device id: 62c8aa8968865a0c8894d90bfdf34cfa337e0195" Apr 26 16:05:22 volumio go-librespot[3692]: time="2024-04-26T16:05:22+08:00" level=debug msg="stored credentials not found" Apr 26 16:05:22 volumio go-librespot[3692]: time="2024-04-26T16:05:22+08:00" level=debug msg="obtained new client token: AAAG3aLZsORBv29/XWYusCNcZdWOAfrVg2T9dCELmbGyUhY3f9EV6sqv+5EazJKid3bT3hcObFUj/VMBXUdacbunjc3ne+O8UAUjEqZPAcXJv5O4k0pVGFwKrV5rg6+2gKdr6l2oENm0tTflUQMzXoU401owPcB2u5qalY0LOFY1Xe4l7ikBWDlGNvW/sylX5VDIXI9kATRJIUBC9jk92i5wlo4lhOG0NMZSRIN/cJ4IbQqXNFcAH2ng0qFelU+V" Apr 26 16:05:23 volumio go-librespot[3692]: time="2024-04-26T16:05: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 26 16:05:23 volumio go-librespot[3692]: time="2024-04-26T16:05:23+08:00" level=debug msg="completed keyexchange" Apr 26 16:05:23 volumio go-librespot[3692]: time="2024-04-26T16:05:23+08:00" level=debug msg="completed challenge" Apr 26 16:05:24 volumio go-librespot[3692]: time="2024-04-26T16:05: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" Apr 26 16:05:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 26 16:05:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 26 16:05:24 volumio volumio[868]: info: Initializing connection to go-librespot Websocket Apr 26 16:05:24 volumio volumio[868]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 26 16:05:27 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 26 16:05:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 128. Apr 26 16:05:27 volumio systemd[1]: Stopped go-librespot Daemon. Apr 26 16:05:27 volumio systemd[1]: Started go-librespot Daemon. Apr 26 16:05:27 volumio go-librespot[3700]: Librespot-go daemon starting... Apr 26 16:05:27 volumio go-librespot[3700]: time="2024-04-26T16:05:27+08:00" level=info msg="generated new device id: cc73fe4083627e55807f558d48a7e686d0fa9830" Apr 26 16:05:27 volumio go-librespot[3700]: time="2024-04-26T16:05:27+08:00" level=debug msg="stored credentials not found" Apr 26 16:05:27 volumio go-librespot[3700]: time="2024-04-26T16:05:27+08:00" level=debug msg="obtained new client token: AABo2eZL2mTk7aoulJAPa8pRNEXAdBn7Jd4KCjluQI4H4i6rEt52Ttqoe1daK9z0xTQ1/vO0sWSR5S8zybk2XxWtAm5clI+iPRyMyYPAC+WtdruB/bzVYkxIfS4P7qWpJ+B1ccZGmLnvkG030rk4AZAZZy/2lZ4xZyG/cSMm3flFQRi/B8vZgF6zQXXWrEN/ctNXEZtwoUPfilkKvSX00SBUw0eNRlXutgnslIjfYjpf7E6sQ8XfgFXA4Xgcbs2n" Apr 26 16:05:27 volumio volumio[868]: info: Initializing connection to go-librespot Websocket Apr 26 16:05:27 volumio go-librespot[3700]: time="2024-04-26T16:05:27+08:00" level=debug msg="new websocket client" Apr 26 16:05:27 volumio volumio[868]: info: Connection to go-librespot Websocket established Apr 26 16:05:28 volumio go-librespot[3700]: time="2024-04-26T16:05: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]" Apr 26 16:05:28 volumio go-librespot[3700]: time="2024-04-26T16:05:28+08:00" level=debug msg="completed keyexchange" Apr 26 16:05:29 volumio go-librespot[3700]: time="2024-04-26T16:05:29+08:00" level=debug msg="completed challenge" Apr 26 16:05:29 volumio go-librespot[3700]: time="2024-04-26T16:05: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" Apr 26 16:05:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 26 16:05:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 26 16:05:29 volumio volumio[868]: info: Connection to go-librespot Websocket closed Apr 26 16:05:30 volumio volumio[868]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 26 16:05:30 volumio volumio[868]: Error: connect ETIMEDOUT 69.63.184.142:80 Apr 26 16:05:30 volumio volumio[868]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) { Apr 26 16:05:30 volumio volumio[868]: errno: -110, Apr 26 16:05:30 volumio volumio[868]: code: 'ETIMEDOUT', Apr 26 16:05:30 volumio volumio[868]: syscall: 'connect', Apr 26 16:05:30 volumio volumio[868]: address: '69.63.184.142', Apr 26 16:05:30 volumio volumio[868]: port: 80 Apr 26 16:05:30 volumio volumio[868]: } Apr 26 16:05:30 volumio volumio[868]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 26 16:05:30 volumio sudo[3719]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-26 16:04 Apr 26 16:05:30 volumio sudo[3719]: 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"