-- Logs begin at Thu 2019-02-14 18:11:59 CST, end at Mon 2024-04-15 19:17:34 CST. -- Apr 15 19:16:00 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 19:16:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 49. Apr 15 19:16:00 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 19:16:00 volumio systemd[1]: Started go-librespot Daemon. Apr 15 19:16:00 volumio go-librespot[2344]: Librespot-go daemon starting... Apr 15 19:16:00 volumio go-librespot[2344]: time="2024-04-15T19:16:00+08:00" level=info msg="generated new device id: aaa97c481d663e3dfd1ffb065b91e6aa95386fb6" Apr 15 19:16:00 volumio go-librespot[2344]: time="2024-04-15T19:16:00+08:00" level=debug msg="stored credentials not found" Apr 15 19:16:00 volumio go-librespot[2344]: time="2024-04-15T19:16:00+08:00" level=debug msg="obtained new client token: AACjsSq0BBeATy1uJKvOS/uJKeqpU5BqNfqw7ewzTuUT8GCui1z5g7F5G/6EYZG0nMwZpGlP3CjSrugE6CG6cGTgXhGwcxtraMCTQWGMEmNWCAOfrMHTRKGoN8V6cjtRX4ZwsaRVYOvjAOJvFkPyKS9lsDaxCPD98zlFf0fySEU/yigPrUuMQfDMX51Li9ffXdNCmCxcZhhg9PER3D1GRxYBfSkjLWks8WciSOtj+G7DdPS1r+dMjAmqlFABMC4+dQ==" Apr 15 19:16:00 volumio go-librespot[2344]: time="2024-04-15T19:16:00+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 15 19:16:01 volumio go-librespot[2344]: time="2024-04-15T19:16:01+08:00" level=debug msg="completed keyexchange" Apr 15 19:16:01 volumio go-librespot[2344]: time="2024-04-15T19:16:01+08:00" level=debug msg="completed challenge" Apr 15 19:16:01 volumio volumio[859]: info: Initializing connection to go-librespot Websocket Apr 15 19:16:01 volumio go-librespot[2344]: time="2024-04-15T19:16:01+08:00" level=debug msg="new websocket client" Apr 15 19:16:01 volumio volumio[859]: info: Connection to go-librespot Websocket established Apr 15 19:16:01 volumio go-librespot[2344]: time="2024-04-15T19:16: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 15 19:16:01 volumio volumio[859]: info: Connection to go-librespot Websocket closed Apr 15 19:16:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 19:16:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 19:16:04 volumio volumio[859]: info: Getting Spotify volume Apr 15 19:16:04 volumio volumio[859]: (node:859) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 19:16:04 volumio volumio[859]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 15 19:16:04 volumio volumio[859]: (node:859) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 21) Apr 15 19:16:04 volumio volumio[859]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Apr 15 19:16:04 volumio volumio[859]: info: CoreCommandRouter::volumioGetState Apr 15 19:16:04 volumio volumio[859]: info: CorePlayQueue::getTrack 0 Apr 15 19:16:04 volumio volumio[859]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Apr 15 19:16:04 volumio volumio[859]: info: Initializing connection to go-librespot Websocket Apr 15 19:16:04 volumio volumio[859]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 19:16:04 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 19:16:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50. Apr 15 19:16:04 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 19:16:04 volumio systemd[1]: Started go-librespot Daemon. Apr 15 19:16:04 volumio go-librespot[2357]: Librespot-go daemon starting... Apr 15 19:16:05 volumio go-librespot[2357]: time="2024-04-15T19:16:05+08:00" level=info msg="generated new device id: 7180a6cd053da8fae194442aa1c08f0df7f39393" Apr 15 19:16:05 volumio go-librespot[2357]: time="2024-04-15T19:16:05+08:00" level=debug msg="stored credentials not found" Apr 15 19:16:05 volumio go-librespot[2357]: time="2024-04-15T19:16:05+08:00" level=debug msg="obtained new client token: AACVUZyiMMBQfRs6Ilxmc1h8OjwisznfX9NzASLzJVpYay2UZKvS93lyY6k+t41aFB+z63z1raeaq79/+2ZpUrU+qlGIljdTs4zQWRYvxoOLfY7ZuDSRjeOMDVnLYPTvK3pHRJy7cvapwWNRsMpNSVINg4lkA2nLyDLGosVbHYzsxc0VxQMut7vsrmgIY8B93Q4QmshnK8qZNNYzkcm3G5ZtE8n2SyTyXK8YhWw0ENkBx+oh+sz7AHxi1Hh9YHw=" Apr 15 19:16:05 volumio go-librespot[2357]: time="2024-04-15T19:16: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 15 19:16:05 volumio go-librespot[2357]: time="2024-04-15T19:16:05+08:00" level=debug msg="completed keyexchange" Apr 15 19:16:06 volumio go-librespot[2357]: time="2024-04-15T19:16:06+08:00" level=debug msg="completed challenge" Apr 15 19:16:06 volumio go-librespot[2357]: time="2024-04-15T19:16: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 15 19:16:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 19:16:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 19:16:07 volumio volumio[859]: info: Initializing connection to go-librespot Websocket Apr 15 19:16:07 volumio volumio[859]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 19:16:09 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 19:16:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 51. Apr 15 19:16:09 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 19:16:09 volumio systemd[1]: Started go-librespot Daemon. Apr 15 19:16:09 volumio go-librespot[2367]: Librespot-go daemon starting... Apr 15 19:16:09 volumio go-librespot[2367]: time="2024-04-15T19:16:09+08:00" level=info msg="generated new device id: 0c622ac7d021286e67f3b54a0a272d736b75a960" Apr 15 19:16:09 volumio go-librespot[2367]: time="2024-04-15T19:16:09+08:00" level=debug msg="stored credentials not found" Apr 15 19:16:09 volumio go-librespot[2367]: time="2024-04-15T19:16:09+08:00" level=debug msg="obtained new client token: AADgqxs+lICVmaOQcyO1Y2DVh6aCVfEljLkMey167ANTuDZKnef7orGVbHOf45zDcDAUpIxTA0M9iadY33+bVvSEa1x+KYKTCRWyU+iZJXKYAipeuKe3gBo90y+hh95t8B5/NU4pC9nZb8fLo3PfL/A2cOZnLzWTPDkapTcWe4mo4zPsfnU0R5rfmA25iLqhHa35eMD5WuIRZ2t/BMY3DlF3eq+HWlBIODY1LWUVd9zeNN/FkLMtS0A58V6HiBmEpA==" Apr 15 19:16:09 volumio go-librespot[2367]: time="2024-04-15T19:16:09+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 15 19:16:09 volumio go-librespot[2367]: time="2024-04-15T19:16:09+08:00" level=debug msg="completed keyexchange" Apr 15 19:16:10 volumio go-librespot[2367]: time="2024-04-15T19:16:10+08:00" level=debug msg="completed challenge" Apr 15 19:16:10 volumio go-librespot[2367]: time="2024-04-15T19:16:10+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 15 19:16:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 19:16:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 19:16:10 volumio volumio[859]: info: Initializing connection to go-librespot Websocket Apr 15 19:16:10 volumio volumio[859]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 19:16:13 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 19:16:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 52. Apr 15 19:16:13 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 19:16:13 volumio systemd[1]: Started go-librespot Daemon. Apr 15 19:16:13 volumio go-librespot[2377]: Librespot-go daemon starting... Apr 15 19:16:13 volumio go-librespot[2377]: time="2024-04-15T19:16:13+08:00" level=info msg="generated new device id: 0dfb7798637d5845de620c850ad3a890eaf0036f" Apr 15 19:16:13 volumio go-librespot[2377]: time="2024-04-15T19:16:13+08:00" level=debug msg="stored credentials not found" Apr 15 19:16:13 volumio go-librespot[2377]: time="2024-04-15T19:16:13+08:00" level=debug msg="obtained new client token: AADgyMs2oKoQ8fWjmuDgocHaNsGcDIR8VpKjtrqVfEtPVI/W4TOPGtqWVndDNFHPtGdVZ7B6l3ImUDEz4vt6fc4QZttltWIqA3+VKkoRLHm98B2BK/cMat35gp6CMnwEQKKSFjdkVhG8i7RXpTR6fixVb05mYVzynVoxs5WD+y/97wtJGsP0gyuvRvqmmup/DzLZA+XY7QJN6yaPhKOtArpfoHAa5svTeyvbiJlHcfRdklmFEb+LgQ8S+WaTert49w==" Apr 15 19:16:13 volumio volumio[859]: info: Initializing connection to go-librespot Websocket Apr 15 19:16:13 volumio go-librespot[2377]: time="2024-04-15T19:16:13+08:00" level=debug msg="new websocket client" Apr 15 19:16:13 volumio volumio[859]: info: Connection to go-librespot Websocket established Apr 15 19:16:13 volumio go-librespot[2377]: time="2024-04-15T19:16:13+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 15 19:16:14 volumio go-librespot[2377]: time="2024-04-15T19:16:14+08:00" level=debug msg="completed keyexchange" Apr 15 19:16:14 volumio go-librespot[2377]: time="2024-04-15T19:16:14+08:00" level=debug msg="completed challenge" Apr 15 19:16:15 volumio go-librespot[2377]: time="2024-04-15T19:16: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" Apr 15 19:16:15 volumio volumio[859]: info: Connection to go-librespot Websocket closed Apr 15 19:16:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 19:16:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 19:16:16 volumio volumio[859]: info: Getting Spotify volume Apr 15 19:16:16 volumio volumio[859]: (node:859) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 19:16:16 volumio volumio[859]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 15 19:16:16 volumio volumio[859]: (node:859) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 22) Apr 15 19:16:16 volumio volumio[859]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Apr 15 19:16:16 volumio volumio[859]: info: CoreCommandRouter::volumioGetState Apr 15 19:16:16 volumio volumio[859]: info: CorePlayQueue::getTrack 0 Apr 15 19:16:16 volumio volumio[859]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Apr 15 19:16:18 volumio volumio[859]: info: Initializing connection to go-librespot Websocket Apr 15 19:16:18 volumio volumio[859]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 19:16:18 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 19:16:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 53. Apr 15 19:16:18 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 19:16:18 volumio systemd[1]: Started go-librespot Daemon. Apr 15 19:16:18 volumio go-librespot[2428]: Librespot-go daemon starting... Apr 15 19:16:18 volumio go-librespot[2428]: time="2024-04-15T19:16:18+08:00" level=info msg="generated new device id: 7850b694b808a2c6c8e2e83babd0663e715e996a" Apr 15 19:16:18 volumio go-librespot[2428]: time="2024-04-15T19:16:18+08:00" level=debug msg="stored credentials not found" Apr 15 19:16:18 volumio go-librespot[2428]: time="2024-04-15T19:16:18+08:00" level=debug msg="obtained new client token: AADnDQLQAX6Kd7XFGZL/qOvJh7Q9a0agOJXyvEasOtfXrEIwsHNR9aRcaalguCnOj+QIeSvyVXJd9rLj2fivRxYYCqM4YZIjr99OLbUJ1ACzHAmfjHlJjXIGA/cbXHz5Z/aoENzegSJYYesvCVLMtjqAISvb9njLjU1q5YgRF1oaucQp3IAGpDQOUk0qa1/FWl+twZdZe/DcUayrdpL3Vdh26+i11qzfoDIU0f9ubRpC3iheGCnrCWiyAuXuj6gyEQ==" Apr 15 19:16:18 volumio go-librespot[2428]: time="2024-04-15T19:16:18+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 15 19:16:19 volumio go-librespot[2428]: time="2024-04-15T19:16:19+08:00" level=debug msg="completed keyexchange" Apr 15 19:16:19 volumio go-librespot[2428]: time="2024-04-15T19:16:19+08:00" level=debug msg="completed challenge" Apr 15 19:16:20 volumio go-librespot[2428]: time="2024-04-15T19:16:20+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 15 19:16:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 19:16:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 19:16:21 volumio volumio[859]: info: Initializing connection to go-librespot Websocket Apr 15 19:16:21 volumio volumio[859]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 19:16:23 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 19:16:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 54. Apr 15 19:16:23 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 19:16:23 volumio systemd[1]: Started go-librespot Daemon. Apr 15 19:16:23 volumio go-librespot[2438]: Librespot-go daemon starting... Apr 15 19:16:23 volumio go-librespot[2438]: time="2024-04-15T19:16:23+08:00" level=info msg="generated new device id: 6ba30a250f6ae82ff2f610681132f67fee8c8df4" Apr 15 19:16:23 volumio go-librespot[2438]: time="2024-04-15T19:16:23+08:00" level=debug msg="stored credentials not found" Apr 15 19:16:23 volumio go-librespot[2438]: time="2024-04-15T19:16:23+08:00" level=debug msg="obtained new client token: AABYI9Sz81iEiNxMcQBudpFUMG9h+w2ySU79pJsTf5LzB81k5e3+TaWXYVVAWp1/DTCE+xDzB2aAyaDh24bfYLpEOPu81+w/8ZHU2bFl4qHPHQPrBnxCkb1vhwi/VWXJNl+n7jBPqvp6+WNTXPV2BobYkLAeQjwmjFA6GzODJOxcOfeGswOtNuR1FzIoBGV1DtDU+kUZyF5kqwX+Bp7EoiWRMsx/Zv+ldsP/vZjnOCIQFYgaoUIDPLl5GPcpvEJD2g==" Apr 15 19:16:23 volumio go-librespot[2438]: time="2024-04-15T19:16: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]" Apr 15 19:16:24 volumio volumio[859]: info: Initializing connection to go-librespot Websocket Apr 15 19:16:24 volumio volumio[859]: info: Connection to go-librespot Websocket established Apr 15 19:16:24 volumio go-librespot[2438]: time="2024-04-15T19:16:24+08:00" level=debug msg="new websocket client" Apr 15 19:16:24 volumio go-librespot[2438]: time="2024-04-15T19:16:24+08:00" level=debug msg="completed keyexchange" Apr 15 19:16:24 volumio go-librespot[2438]: time="2024-04-15T19:16:24+08:00" level=debug msg="completed challenge" Apr 15 19:16:25 volumio go-librespot[2438]: time="2024-04-15T19:16:25+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 15 19:16:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 19:16:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 19:16:25 volumio volumio[859]: info: Connection to go-librespot Websocket closed Apr 15 19:16:26 volumio volumio[859]: info: CoreCommandRouter::volumioToggle Apr 15 19:16:26 volumio volumio[859]: info: CorePlayQueue::getTrack 0 Apr 15 19:16:26 volumio volumio[859]: info: CoreStateMachine::play index undefined Apr 15 19:16:26 volumio volumio[859]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 15 19:16:26 volumio volumio[859]: info: CorePlayQueue::getTrack 0 Apr 15 19:16:27 volumio volumio[859]: info: Getting Spotify volume Apr 15 19:16:27 volumio volumio[859]: (node:859) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 19:16:27 volumio volumio[859]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 15 19:16:27 volumio volumio[859]: (node:859) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 23) Apr 15 19:16:27 volumio volumio[859]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Apr 15 19:16:27 volumio volumio[859]: info: CoreCommandRouter::volumioGetState Apr 15 19:16:27 volumio volumio[859]: info: CorePlayQueue::getTrack 0 Apr 15 19:16:27 volumio volumio[859]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Apr 15 19:16:28 volumio volumio[859]: info: Initializing connection to go-librespot Websocket Apr 15 19:16:28 volumio volumio[859]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 19:16:28 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 19:16:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 55. Apr 15 19:16:28 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 19:16:28 volumio systemd[1]: Started go-librespot Daemon. Apr 15 19:16:28 volumio go-librespot[2448]: Librespot-go daemon starting... Apr 15 19:16:28 volumio go-librespot[2448]: time="2024-04-15T19:16:28+08:00" level=info msg="generated new device id: 6f4985556e193150a83f6b1f46476aca4bff0090" Apr 15 19:16:28 volumio go-librespot[2448]: time="2024-04-15T19:16:28+08:00" level=debug msg="stored credentials not found" Apr 15 19:16:28 volumio go-librespot[2448]: time="2024-04-15T19:16:28+08:00" level=debug msg="obtained new client token: AABupTQvlHJPtVTfiYVDmjastOq4v2kIBdDvMJPu5fzpDnbTw/QenFNRr0W6RJbjob5Fy3xTEplW5DX0iuTiXxOtSC3NGPOy4e4pyWrXL1ZUWbrGEl3FuZX9o57xhJzBDq7o4VmPQ45Bydao1RxKyZCtxtbJRXdM4Mza3mjNd9K1kN0iKSWDAwY6DeJ9XwVVdFLAnr4P0F+lBAHEwV+g+hURrq8yu7ipkXFsV2Dqdz4NVfntLXRkx615xjhEG+a6Dw==" Apr 15 19:16:28 volumio go-librespot[2448]: time="2024-04-15T19:16: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 15 19:16:28 volumio go-librespot[2448]: time="2024-04-15T19:16:28+08:00" level=debug msg="completed keyexchange" Apr 15 19:16:29 volumio go-librespot[2448]: time="2024-04-15T19:16:29+08:00" level=debug msg="completed challenge" Apr 15 19:16:29 volumio go-librespot[2448]: time="2024-04-15T19:16: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 15 19:16:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 19:16:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 19:16:31 volumio volumio[859]: info: Initializing connection to go-librespot Websocket Apr 15 19:16:31 volumio volumio[859]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 19:16:31 volumio volumio[859]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 15 19:16:31 volumio volumio[859]: info: CURURI: playlists Apr 15 19:16:31 volumio volumio[859]: info: Listing playlists Apr 15 19:16:31 volumio volumio[859]: info: Preload queue cleared Apr 15 19:16:32 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 19:16:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 56. Apr 15 19:16:32 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 19:16:32 volumio systemd[1]: Started go-librespot Daemon. Apr 15 19:16:32 volumio go-librespot[2460]: Librespot-go daemon starting... Apr 15 19:16:32 volumio go-librespot[2460]: time="2024-04-15T19:16:32+08:00" level=info msg="generated new device id: cbf8adf410e85963afccd20b5b0d8f6a88391f74" Apr 15 19:16:32 volumio go-librespot[2460]: time="2024-04-15T19:16:32+08:00" level=debug msg="stored credentials not found" Apr 15 19:16:32 volumio volumio[859]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 15 19:16:32 volumio volumio[859]: info: CURURI: playlists/童丽 Apr 15 19:16:32 volumio go-librespot[2460]: time="2024-04-15T19:16:32+08:00" level=debug msg="obtained new client token: AAAJCh30wdGajXktD45rWV+6IgJ0kWDAlYq6WUysQc0slYi/+e5fy3E80FEWiIZSQdFWCKqyp7irSG99p8QIKWsgE8KZ1K0KxXSYAgpPbq3XwvmpfIB1LVLFXV+Q3i/Ab3WKIb95cL22hz7GDPosm6hNuSP5wMLobioA8dHtvCgpRWJIDSTZiFYHkv7MiJu4yLe6YcvHhV+P7KMvAFtD8u2yZXMNdRMmxuXjNMthpXpXmuEYFbv/n3icrUx8/DmxDw==" Apr 15 19:16:32 volumio volumio[859]: info: Preload queue cleared Apr 15 19:16:32 volumio volumio[859]: info: Preloading song: upnp/folder/http://192.168.3.100:50001/ContentDirectory/control@22$473 Apr 15 19:16:32 volumio volumio[859]: info: Exploding uri upnp/folder/http://192.168.3.100:50001/ContentDirectory/control@22$473 in service upnp_browser Apr 15 19:16:32 volumio go-librespot[2460]: time="2024-04-15T19:16:32+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 15 19:16:33 volumio go-librespot[2460]: time="2024-04-15T19:16:33+08:00" level=debug msg="completed keyexchange" Apr 15 19:16:33 volumio go-librespot[2460]: time="2024-04-15T19:16:33+08:00" level=debug msg="completed challenge" Apr 15 19:16:33 volumio go-librespot[2460]: time="2024-04-15T19:16:33+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 15 19:16:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 19:16:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 19:16:34 volumio volumio[859]: info: Initializing connection to go-librespot Websocket Apr 15 19:16:34 volumio volumio[859]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 19:16:35 volumio volumio[859]: info: Preload queue cleared Apr 15 19:16:35 volumio volumio[859]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 15 19:16:35 volumio volumio[859]: info: CoreStateMachine::ClearQueue Apr 15 19:16:35 volumio volumio[859]: info: CoreStateMachine::stop Apr 15 19:16:35 volumio volumio[859]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 15 19:16:35 volumio volumio[859]: info: CorePlayQueue::clearPlayQueue Apr 15 19:16:35 volumio volumio[859]: info: CorePlayQueue::saveQueue Apr 15 19:16:35 volumio volumio[859]: info: CoreCommandRouter::volumioPushQueue Apr 15 19:16:35 volumio volumio[859]: info: CoreStateMachine::addQueueItems Apr 15 19:16:35 volumio volumio[859]: info: CorePlayQueue::addQueueItems Apr 15 19:16:35 volumio volumio[859]: info: Preload queue cleared Apr 15 19:16:35 volumio volumio[859]: info: Adding Item to queue: upnp/folder/http://192.168.3.100:50001/ContentDirectory/control@22$473 Apr 15 19:16:35 volumio volumio[859]: info: Exploding uri upnp/folder/http://192.168.3.100:50001/ContentDirectory/control@22$473 in service upnp_browser Apr 15 19:16:35 volumio volumio[859]: error: connect EHOSTUNREACH 192.168.3.100:50001 {"errno":-113,"code":"EHOSTUNREACH","syscall":"connect","address":"192.168.3.100","port":50001} Apr 15 19:16:35 volumio volumio[859]: error: connect EHOSTUNREACH 192.168.3.100:50001 {"errno":-113,"code":"EHOSTUNREACH","syscall":"connect","address":"192.168.3.100","port":50001} Apr 15 19:16:36 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 19:16:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 57. Apr 15 19:16:36 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 19:16:36 volumio systemd[1]: Started go-librespot Daemon. Apr 15 19:16:36 volumio go-librespot[2469]: Librespot-go daemon starting... Apr 15 19:16:36 volumio go-librespot[2469]: time="2024-04-15T19:16:36+08:00" level=info msg="generated new device id: 2f7113a7c752bda4244d1af5ab5aec48bb1a79cb" Apr 15 19:16:36 volumio go-librespot[2469]: time="2024-04-15T19:16:36+08:00" level=debug msg="stored credentials not found" Apr 15 19:16:37 volumio go-librespot[2469]: time="2024-04-15T19:16:37+08:00" level=debug msg="obtained new client token: AACu0OKcRVtHT9BsU0FbXFvrtG5t5Ux94KysqBsUl9ysYuUCfSNaQMmjSt3s7RpxKoWh+QTKJ4mZHb7kzdFrmRCqj7eRZ2x362c4NJW3Hxp1Sx/t0hvidOh+g27dbWMddAvhPez7z3D7WznHMZxb00RcCKhp8ZaM4rTabjc8b7fN+/vOfgqCQ/tVj2olsFg8rf+hSrARtiVVx8xKURnrZrf6jrqLO2SQvm+XWzMEye3Zk/xkOgALZHtb+kbj0LH4Pg==" Apr 15 19:16:37 volumio volumio[859]: info: Initializing connection to go-librespot Websocket Apr 15 19:16:37 volumio go-librespot[2469]: time="2024-04-15T19:16:37+08:00" level=debug msg="new websocket client" Apr 15 19:16:37 volumio volumio[859]: info: Connection to go-librespot Websocket established Apr 15 19:16:37 volumio go-librespot[2469]: time="2024-04-15T19:16: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 15 19:16:37 volumio go-librespot[2469]: time="2024-04-15T19:16:37+08:00" level=debug msg="completed keyexchange" Apr 15 19:16:37 volumio go-librespot[2469]: time="2024-04-15T19:16:37+08:00" level=debug msg="completed challenge" Apr 15 19:16:37 volumio go-librespot[2469]: time="2024-04-15T19:16:37+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 15 19:16:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 19:16:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 19:16:37 volumio volumio[859]: info: Connection to go-librespot Websocket closed Apr 15 19:16:40 volumio volumio[859]: info: Getting Spotify volume Apr 15 19:16:40 volumio volumio[859]: (node:859) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 19:16:40 volumio volumio[859]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 15 19:16:40 volumio volumio[859]: (node:859) 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: 24) Apr 15 19:16:40 volumio volumio[859]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Apr 15 19:16:40 volumio volumio[859]: info: CoreCommandRouter::volumioGetState Apr 15 19:16:40 volumio volumio[859]: info: CorePlayQueue::getTrack 0 Apr 15 19:16:40 volumio volumio[859]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Apr 15 19:16:40 volumio volumio[859]: info: Initializing connection to go-librespot Websocket Apr 15 19:16:40 volumio volumio[859]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 19:16:40 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 19:16:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 58. Apr 15 19:16:40 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 19:16:40 volumio systemd[1]: Started go-librespot Daemon. Apr 15 19:16:40 volumio go-librespot[2481]: Librespot-go daemon starting... Apr 15 19:16:41 volumio go-librespot[2481]: time="2024-04-15T19:16:41+08:00" level=info msg="generated new device id: e7c75eeafe48d2ef6fe4256543a0b4a27fe71202" Apr 15 19:16:41 volumio go-librespot[2481]: time="2024-04-15T19:16:41+08:00" level=debug msg="stored credentials not found" Apr 15 19:16:41 volumio go-librespot[2481]: time="2024-04-15T19:16:41+08:00" level=debug msg="obtained new client token: AABgyz9zwsAGxp5L/cSMvJJr6KkzcVx68xneVW9niVD8VWIXLEaRVZUdm9DlynH/v8by9p5LyHk73JtNWDS3mu1wmS5PxklXQ2/KvQkHo3An9i7p3AMoxDYULe2TEIr2UrGYnz66cHOXAsxJ06g3ysn14tNbA2CynOU45i69S4Z9+Siz7sVnc6W+YMaGezsi8QMcp2kfMq76Pdwh4Iio8Km3uQK82KL2/dGBEcwzB8U3cX7bn1ojTDMWbSh24AQ=" Apr 15 19:16:41 volumio go-librespot[2481]: time="2024-04-15T19:16: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 15 19:16:41 volumio go-librespot[2481]: time="2024-04-15T19:16:41+08:00" level=debug msg="completed keyexchange" Apr 15 19:16:42 volumio go-librespot[2481]: time="2024-04-15T19:16:42+08:00" level=debug msg="completed challenge" Apr 15 19:16:42 volumio go-librespot[2481]: time="2024-04-15T19:16:42+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 15 19:16:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 19:16:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 19:16:43 volumio volumio[859]: info: Initializing connection to go-librespot Websocket Apr 15 19:16:43 volumio volumio[859]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 19:16:45 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 19:16:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 59. Apr 15 19:16:45 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 19:16:45 volumio systemd[1]: Started go-librespot Daemon. Apr 15 19:16:45 volumio go-librespot[2490]: Librespot-go daemon starting... Apr 15 19:16:45 volumio go-librespot[2490]: time="2024-04-15T19:16:45+08:00" level=info msg="generated new device id: 10a5bcb9e05ce61cebc499ebbd54d6d271bf8bda" Apr 15 19:16:45 volumio go-librespot[2490]: time="2024-04-15T19:16:45+08:00" level=debug msg="stored credentials not found" Apr 15 19:16:45 volumio go-librespot[2490]: time="2024-04-15T19:16:45+08:00" level=debug msg="obtained new client token: AABiwOlwRSQOTQxybHsj4pz9m5W2+8Y06BnKslgAYS4mev2yIEZxx6lane7ay8+lkdb+eZ6oQmlwHW349N7asyaJ0TArbpU6Un2PjzhrMCzvwaKvrS2IcZKQEKb/Vqnh1Kou6vIRnRrUqEklnnIBgufMzcQW8Nq1MuRvO2METAvcsrvEHfVdfrSs3BubGhDyBUjHjCiHFB0M5o7MLdEJheHB5z4fY8C4hA8oC5zWZJrhvv/5/N5kGMEORF/Ui93l/w==" Apr 15 19:16:45 volumio go-librespot[2490]: time="2024-04-15T19:16:45+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 15 19:16:45 volumio go-librespot[2490]: time="2024-04-15T19:16:45+08:00" level=debug msg="completed keyexchange" Apr 15 19:16:46 volumio go-librespot[2490]: time="2024-04-15T19:16:46+08:00" level=debug msg="completed challenge" Apr 15 19:16:46 volumio go-librespot[2490]: time="2024-04-15T19:16:46+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 15 19:16:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 19:16:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 19:16:46 volumio volumio[859]: info: Initializing connection to go-librespot Websocket Apr 15 19:16:46 volumio volumio[859]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 19:16:47 volumio volumio[859]: info: CoreCommandRouter::volumioPlay Apr 15 19:16:47 volumio volumio[859]: info: CoreStateMachine::play index undefined Apr 15 19:16:47 volumio volumio[859]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 15 19:16:47 volumio volumio[859]: info: CorePlayQueue::getTrack 0 Apr 15 19:16:49 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 19:16:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 60. Apr 15 19:16:49 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 19:16:49 volumio systemd[1]: Started go-librespot Daemon. Apr 15 19:16:49 volumio go-librespot[2499]: Librespot-go daemon starting... Apr 15 19:16:49 volumio go-librespot[2499]: time="2024-04-15T19:16:49+08:00" level=info msg="generated new device id: 926e18bedb81bc61bf91e5f5efae521f3b17d1a7" Apr 15 19:16:49 volumio go-librespot[2499]: time="2024-04-15T19:16:49+08:00" level=debug msg="stored credentials not found" Apr 15 19:16:49 volumio go-librespot[2499]: time="2024-04-15T19:16:49+08:00" level=debug msg="obtained new client token: AACv6+NCtYtYIlBAbfCQKSpObsSUxvnEDpf8VDYSXKTyRodbwvirK+BHTLd0lUR7pU28a50jas4MCYybrDzp0wooM7oblYjLNUSYrglp+bZT5FVIdeApDw6NUOnc9p5kK6UtUPsEEJSbDNSD2LNIEG0g+VboGVw8RpkYytH4p9fjiIPu1wCwCmG09SU+kKaadj18AhbTHRTdrviCMscPX9irTYTs8mWGdBUS3LSCWBbV/7Jsh8Otbw3JCjXeJJaE1w==" Apr 15 19:16:49 volumio volumio[859]: info: Initializing connection to go-librespot Websocket Apr 15 19:16:49 volumio go-librespot[2499]: time="2024-04-15T19:16:49+08:00" level=debug msg="new websocket client" Apr 15 19:16:49 volumio volumio[859]: info: Connection to go-librespot Websocket established Apr 15 19:16:49 volumio go-librespot[2499]: time="2024-04-15T19:16:49+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 15 19:16:50 volumio go-librespot[2499]: time="2024-04-15T19:16:50+08:00" level=debug msg="completed keyexchange" Apr 15 19:16:50 volumio go-librespot[2499]: time="2024-04-15T19:16:50+08:00" level=debug msg="completed challenge" Apr 15 19:16:51 volumio go-librespot[2499]: time="2024-04-15T19:16:51+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 15 19:16:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 19:16:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 19:16:51 volumio volumio[859]: info: Connection to go-librespot Websocket closed Apr 15 19:16:51 volumio volumio[859]: info: CoreCommandRouter::volumioNext Apr 15 19:16:51 volumio volumio[859]: info: CoreStateMachine::next Apr 15 19:16:51 volumio volumio[859]: info: CoreStateMachine::stop Apr 15 19:16:51 volumio volumio[859]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 15 19:16:51 volumio volumio[859]: info: CoreStateMachine::play index undefined Apr 15 19:16:51 volumio volumio[859]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 15 19:16:51 volumio volumio[859]: info: CorePlayQueue::getTrack 0 Apr 15 19:16:51 volumio volumio[859]: info: CoreCommandRouter::volumioNext Apr 15 19:16:51 volumio volumio[859]: info: CoreStateMachine::next Apr 15 19:16:51 volumio volumio[859]: info: CoreStateMachine::stop Apr 15 19:16:51 volumio volumio[859]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 15 19:16:51 volumio volumio[859]: info: CoreStateMachine::play index undefined Apr 15 19:16:51 volumio volumio[859]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 15 19:16:51 volumio volumio[859]: info: CorePlayQueue::getTrack 0 Apr 15 19:16:52 volumio volumio[859]: info: CoreCommandRouter::volumioNext Apr 15 19:16:52 volumio volumio[859]: info: CoreStateMachine::next Apr 15 19:16:52 volumio volumio[859]: info: CoreStateMachine::stop Apr 15 19:16:52 volumio volumio[859]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 15 19:16:52 volumio volumio[859]: info: CoreStateMachine::play index undefined Apr 15 19:16:52 volumio volumio[859]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 15 19:16:52 volumio volumio[859]: info: CorePlayQueue::getTrack 0 Apr 15 19:16:52 volumio volumio[859]: info: CoreCommandRouter::volumioNext Apr 15 19:16:52 volumio volumio[859]: info: CoreStateMachine::next Apr 15 19:16:52 volumio volumio[859]: info: CoreStateMachine::stop Apr 15 19:16:52 volumio volumio[859]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 15 19:16:52 volumio volumio[859]: info: CoreStateMachine::play index undefined Apr 15 19:16:52 volumio volumio[859]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 15 19:16:52 volumio volumio[859]: info: CorePlayQueue::getTrack 0 Apr 15 19:16:52 volumio volumio[859]: info: Getting Spotify volume Apr 15 19:16:52 volumio volumio[859]: (node:859) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 19:16:52 volumio volumio[859]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 15 19:16:52 volumio volumio[859]: (node:859) 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: 25) Apr 15 19:16:52 volumio volumio[859]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Apr 15 19:16:52 volumio volumio[859]: info: CoreCommandRouter::volumioGetState Apr 15 19:16:52 volumio volumio[859]: info: CorePlayQueue::getTrack 0 Apr 15 19:16:52 volumio volumio[859]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Apr 15 19:16:52 volumio volumio[859]: info: CoreCommandRouter::volumioNext Apr 15 19:16:52 volumio volumio[859]: info: CoreStateMachine::next Apr 15 19:16:52 volumio volumio[859]: info: CoreStateMachine::stop Apr 15 19:16:52 volumio volumio[859]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 15 19:16:52 volumio volumio[859]: info: CoreStateMachine::play index undefined Apr 15 19:16:52 volumio volumio[859]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 15 19:16:52 volumio volumio[859]: info: CorePlayQueue::getTrack 0 Apr 15 19:16:53 volumio volumio[859]: info: CoreCommandRouter::volumioNext Apr 15 19:16:53 volumio volumio[859]: info: CoreStateMachine::next Apr 15 19:16:53 volumio volumio[859]: info: CoreStateMachine::stop Apr 15 19:16:53 volumio volumio[859]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 15 19:16:53 volumio volumio[859]: info: CoreStateMachine::play index undefined Apr 15 19:16:53 volumio volumio[859]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 15 19:16:53 volumio volumio[859]: info: CorePlayQueue::getTrack 0 Apr 15 19:16:54 volumio volumio[859]: info: Initializing connection to go-librespot Websocket Apr 15 19:16:54 volumio volumio[859]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 19:16:54 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 19:16:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 61. Apr 15 19:16:54 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 19:16:54 volumio systemd[1]: Started go-librespot Daemon. Apr 15 19:16:54 volumio go-librespot[2509]: Librespot-go daemon starting... Apr 15 19:16:54 volumio go-librespot[2509]: time="2024-04-15T19:16:54+08:00" level=info msg="generated new device id: e611475abcbf04676d5b86c19ecb82a618745937" Apr 15 19:16:54 volumio go-librespot[2509]: time="2024-04-15T19:16:54+08:00" level=debug msg="stored credentials not found" Apr 15 19:16:54 volumio go-librespot[2509]: time="2024-04-15T19:16:54+08:00" level=debug msg="obtained new client token: AACfFNxSmDQaNnJum6g4qfRXbHcU91a7Xa1NcwTOtAg+ci1LXBvF2LfpBLGBrnODVgTu72ChL9KU1+QDQqESj8Z0wwT0u7Qeo44iNHWBKjystGlukkYVRvEJtTi4iCT3o9qLjNeLnHZlKVNhItrYyc9bWaFbPGIuuCFgX6DYtuSlRIGH1SzFUhTAmavW8oFQp74dMolzq2a+MCYAPO9IArH2tQ+WhF37LqhKtvwcx61kHlYPAYRLP62oPis0OKjquA==" Apr 15 19:16:54 volumio go-librespot[2509]: time="2024-04-15T19:16:54+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 15 19:16:55 volumio go-librespot[2509]: time="2024-04-15T19:16:55+08:00" level=debug msg="completed keyexchange" Apr 15 19:16:55 volumio go-librespot[2509]: time="2024-04-15T19:16:55+08:00" level=debug msg="completed challenge" Apr 15 19:16:55 volumio go-librespot[2509]: time="2024-04-15T19:16:55+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 15 19:16:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 19:16:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 19:16:57 volumio volumio[859]: info: Initializing connection to go-librespot Websocket Apr 15 19:16:57 volumio volumio[859]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 19:16:58 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 19:16:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 62. Apr 15 19:16:58 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 19:16:58 volumio systemd[1]: Started go-librespot Daemon. Apr 15 19:16:58 volumio go-librespot[2518]: Librespot-go daemon starting... Apr 15 19:16:58 volumio go-librespot[2518]: time="2024-04-15T19:16:58+08:00" level=info msg="generated new device id: eb142d0cc5a792aec24a195da6fbf593693295fb" Apr 15 19:16:59 volumio go-librespot[2518]: time="2024-04-15T19:16:59+08:00" level=debug msg="stored credentials not found" Apr 15 19:16:59 volumio go-librespot[2518]: time="2024-04-15T19:16:59+08:00" level=debug msg="obtained new client token: AACp1qCQ8uqgd7Lq7nwSX/fHWlZZ6WabNuWgbZhU0DIR0WnCa1xRNLgrzYxrxgMJ4LdWG2jOYuJgaprf31n2KXzqjjYg9iDpOxIBP1enjhI+BTxeZvZRjn/pFeDEwcR9aMau/K4Ed1SsyfOzaAdEPQNxJZNjQT3IBopv3qeTUFLWVuoguYkKFf4ZKrdLzT052Vn0RBWD7FufB0DPCT5RzKiNlTtumtVY1kfONCLWucAQg7kLcEBsDPasuJeXHh0=" Apr 15 19:16:59 volumio go-librespot[2518]: time="2024-04-15T19:16:59+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 15 19:16:59 volumio go-librespot[2518]: time="2024-04-15T19:16:59+08:00" level=debug msg="completed keyexchange" Apr 15 19:17:00 volumio go-librespot[2518]: time="2024-04-15T19:17:00+08:00" level=debug msg="completed challenge" Apr 15 19:17:00 volumio volumio[859]: info: Initializing connection to go-librespot Websocket Apr 15 19:17:00 volumio go-librespot[2518]: time="2024-04-15T19:17:00+08:00" level=debug msg="new websocket client" Apr 15 19:17:00 volumio volumio[859]: info: Connection to go-librespot Websocket established Apr 15 19:17:00 volumio go-librespot[2518]: time="2024-04-15T19:17:00+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 15 19:17:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 19:17:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 19:17:00 volumio volumio[859]: info: Connection to go-librespot Websocket closed Apr 15 19:17:02 volumio volumio[859]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 15 19:17:03 volumio volumio[859]: info: Getting Spotify volume Apr 15 19:17:03 volumio volumio[859]: (node:859) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 19:17:03 volumio volumio[859]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 15 19:17:03 volumio volumio[859]: (node:859) 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: 26) Apr 15 19:17:03 volumio volumio[859]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Apr 15 19:17:03 volumio volumio[859]: info: CoreCommandRouter::volumioGetState Apr 15 19:17:03 volumio volumio[859]: info: CorePlayQueue::getTrack 0 Apr 15 19:17:03 volumio volumio[859]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Apr 15 19:17:03 volumio volumio[859]: info: Initializing connection to go-librespot Websocket Apr 15 19:17:03 volumio volumio[859]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 19:17:03 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 19:17:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 63. Apr 15 19:17:03 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 19:17:03 volumio systemd[1]: Started go-librespot Daemon. Apr 15 19:17:03 volumio go-librespot[2529]: Librespot-go daemon starting... Apr 15 19:17:03 volumio go-librespot[2529]: time="2024-04-15T19:17:03+08:00" level=info msg="generated new device id: 8e60968b57938375a7b2c722d0d05633d8958ef6" Apr 15 19:17:03 volumio go-librespot[2529]: time="2024-04-15T19:17:03+08:00" level=debug msg="stored credentials not found" Apr 15 19:17:03 volumio go-librespot[2529]: time="2024-04-15T19:17:03+08:00" level=debug msg="obtained new client token: AACWaaDdjXiIlOc0TgBK2m+lyKmG3rEGEl9riM1KbZEpp+mKQmAhdzOUKvI7+qGwHkj+tHYGbn/VGNM/hoo0bZMkpPok/TgIFGQM9HurZF8GIUMT5w5r2reG9MASBa6pFOx9PGpeqaZohIF/DNNeT/vE1/l+1OAShm8QBXnYuqBkQMToZXSR2MJdLZHAVTMg7bcIK3Y+1isfzub8PlEzhDetj2FVgAvOs2XdD5OxFIT0jJ4Mcy6CP41Q7b3mnyBlkg==" Apr 15 19:17:03 volumio volumio[859]: info: CoreCommandRouter::Close All Modals sent Apr 15 19:17:03 volumio go-librespot[2529]: time="2024-04-15T19:17: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 15 19:17:03 volumio go-librespot[2529]: time="2024-04-15T19:17:03+08:00" level=debug msg="completed keyexchange" Apr 15 19:17:04 volumio go-librespot[2529]: time="2024-04-15T19:17:04+08:00" level=debug msg="completed challenge" Apr 15 19:17:04 volumio go-librespot[2529]: time="2024-04-15T19:17:04+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 15 19:17:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 19:17:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 19:17:06 volumio volumio[859]: info: Initializing connection to go-librespot Websocket Apr 15 19:17:06 volumio volumio[859]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 19:17:07 volumio sudo[2540]: pam_unix(sudo:auth): authentication failure; logname= uid=1000 euid=0 tty= ruser=volumio rhost= user=volumio Apr 15 19:17:07 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 19:17:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 64. Apr 15 19:17:07 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 19:17:07 volumio systemd[1]: Started go-librespot Daemon. Apr 15 19:17:07 volumio go-librespot[2541]: Librespot-go daemon starting... Apr 15 19:17:07 volumio go-librespot[2541]: time="2024-04-15T19:17:07+08:00" level=info msg="generated new device id: b53d87448d71b1944816667d4ddc5265563219de" Apr 15 19:17:07 volumio go-librespot[2541]: time="2024-04-15T19:17:07+08:00" level=debug msg="stored credentials not found" Apr 15 19:17:08 volumio go-librespot[2541]: time="2024-04-15T19:17:08+08:00" level=debug msg="obtained new client token: AADAbby2dkodEZroRfzvPBXP2ZTcsDjn6nlFNv7RiTTCduhxBkFXfLSwA7y2D+TWVEgbSOsxrqu92FzGZEAj+Q1a4gZOry1uc6zaCPPL9EZfKvdjVpOFx5eKHNdrBtujsFROy/9AZGRXyb9NnTlfu80GyDSiIQqDbK7d4S+827VM8KwOO5LYCwCc+cK9zZKKVAEEgdOHsysSLVuxO4DgdF1ELqI92GaiI+6kQloCURxBMyBI+dwrWKZKheWlpqtHsw==" Apr 15 19:17:08 volumio go-librespot[2541]: time="2024-04-15T19:17: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 15 19:17:08 volumio go-librespot[2541]: time="2024-04-15T19:17:08+08:00" level=debug msg="completed keyexchange" Apr 15 19:17:08 volumio go-librespot[2541]: time="2024-04-15T19:17:08+08:00" level=debug msg="completed challenge" Apr 15 19:17:08 volumio go-librespot[2541]: time="2024-04-15T19:17:08+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 15 19:17:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 19:17:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 19:17:09 volumio sudo[2540]: pam_unix(sudo:auth): conversation failed Apr 15 19:17:09 volumio sudo[2540]: pam_unix(sudo:auth): auth could not identify password for [volumio] Apr 15 19:17:09 volumio sudo[2540]: volumio : 1 incorrect password attempt ; TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sed -i s/localhost:4004/localhost:3000/g /opt/volumiokiosk.sh Apr 15 19:17:09 volumio volumio[859]: [sudo] password for volumio: Sorry, try again. Apr 15 19:17:09 volumio volumio[859]: [sudo] password for volumio: Apr 15 19:17:09 volumio volumio[859]: sudo: no password was provided Apr 15 19:17:09 volumio volumio[859]: sudo: 1 incorrect password attempt Apr 15 19:17:09 volumio volumio[859]: error: [now-playing] Error modifying Volumio Kiosk script: Error: Command failed: echo volumio | sudo -S sed -i 's/localhost:4004/localhost:3000/g' "/opt/volumiokiosk.sh" Apr 15 19:17:09 volumio volumio[859]: [sudo] password for volumio: Sorry, try again. Apr 15 19:17:09 volumio volumio[859]: [sudo] password for volumio: Apr 15 19:17:09 volumio volumio[859]: sudo: no password was provided Apr 15 19:17:09 volumio volumio[859]: sudo: 1 incorrect password attempt Apr 15 19:17:09 volumio volumio[859]: at checkExecSyncError (child_process.js:616:11) Apr 15 19:17:09 volumio volumio[859]: at execSync (child_process.js:652:15) Apr 15 19:17:09 volumio volumio[859]: at Object.replaceInFile (/data/plugins/user_interface/now_playing/dist/lib/utils/System.js:38:41) Apr 15 19:17:09 volumio volumio[859]: at Object.modifyVolumioKioskScript (/data/plugins/user_interface/now_playing/dist/lib/utils/Kiosk.js:107:21) Apr 15 19:17:09 volumio volumio[859]: at ControllerNowPlaying._ControllerNowPlaying_doOnStop (/data/plugins/user_interface/now_playing/dist/index.js:1811:30) Apr 15 19:17:09 volumio volumio[859]: at ControllerNowPlaying.onStop (/data/plugins/user_interface/now_playing/dist/index.js:489:142) Apr 15 19:17:09 volumio volumio[859]: at PluginManager.stopPlugin (/volumio/app/pluginmanager.js:460:30) Apr 15 19:17:09 volumio volumio[859]: at PluginManager.disableAndStopPlugin (/volumio/app/pluginmanager.js:1883:8) Apr 15 19:17:09 volumio volumio[859]: at CoreCommandRouter.disableAndStopPlugin (/volumio/app/index.js:1531:29) Apr 15 19:17:09 volumio volumio[859]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1356:47) Apr 15 19:17:09 volumio volumio[859]: at Socket.emit (events.js:315:20) Apr 15 19:17:09 volumio volumio[859]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Apr 15 19:17:09 volumio volumio[859]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Apr 15 19:17:09 volumio volumio[859]: warn: [now-playing] MyBackgroundMonitor stopped Apr 15 19:17:09 volumio volumio[859]: info: Disabling plugin now_playing Apr 15 19:17:09 volumio volumio[859]: info: Done. Apr 15 19:17:09 volumio volumio[859]: info: Initializing connection to go-librespot Websocket Apr 15 19:17:09 volumio volumio[859]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 19:17:11 volumio volumio[859]: info: Enabling plugin now_playing Apr 15 19:17:11 volumio volumio[859]: info: Loading plugin "now_playing"... Apr 15 19:17:11 volumio volumio[859]: info: PLUGIN START: now_playing Apr 15 19:17:11 volumio volumio[859]: info: [now-playing] ConfigUpdater: config is up to date. Apr 15 19:17:11 volumio volumio[859]: info: [now-playing] App is listening on port 4004. Apr 15 19:17:11 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 19:17:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 65. Apr 15 19:17:11 volumio volumio[859]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Apr 15 19:17:11 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 19:17:11 volumio volumio[859]: info: Done. Apr 15 19:17:11 volumio systemd[1]: Started go-librespot Daemon. Apr 15 19:17:11 volumio go-librespot[2550]: Librespot-go daemon starting... Apr 15 19:17:12 volumio go-librespot[2550]: time="2024-04-15T19:17:12+08:00" level=info msg="generated new device id: e921d95cf2bc5a3e8d104f02f101bb6f997e05ef" Apr 15 19:17:12 volumio go-librespot[2550]: time="2024-04-15T19:17:12+08:00" level=debug msg="stored credentials not found" Apr 15 19:17:12 volumio go-librespot[2550]: time="2024-04-15T19:17:12+08:00" level=debug msg="obtained new client token: AACcXTZ5MrPZ4XRve89S7LGDKSrC1Rk3IYhPP+BkjfGUntKl1fOwPOxnXN4sxBR7HwOI1Aqew9o0j97sZHDfmD1feP5NRVKIP5G2jfuP/XsdYBgRmQCMixd9CT4Wz3OxtS1sOnWI6rNjKEeORN+OHcxp2DH5J30Jl/DDaN1YStj3bILd4fLiLforyyq6hjf0ZLqSFklo3ueKTPRVt941AwTLMr2EiAv8aRVdYjC8E0MzXAeUgFza6gNDF359+j8=" Apr 15 19:17:12 volumio go-librespot[2550]: time="2024-04-15T19:17: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 15 19:17:12 volumio go-librespot[2550]: time="2024-04-15T19:17:12+08:00" level=debug msg="completed keyexchange" Apr 15 19:17:12 volumio volumio[859]: info: Initializing connection to go-librespot Websocket Apr 15 19:17:12 volumio go-librespot[2550]: time="2024-04-15T19:17:12+08:00" level=debug msg="new websocket client" Apr 15 19:17:12 volumio volumio[859]: info: Connection to go-librespot Websocket established Apr 15 19:17:13 volumio go-librespot[2550]: time="2024-04-15T19:17:13+08:00" level=debug msg="completed challenge" Apr 15 19:17:13 volumio go-librespot[2550]: time="2024-04-15T19:17:13+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 15 19:17:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 19:17:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 19:17:13 volumio volumio[859]: info: Connection to go-librespot Websocket closed Apr 15 19:17:15 volumio volumio[859]: info: Getting Spotify volume Apr 15 19:17:15 volumio volumio[859]: (node:859) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 19:17:15 volumio volumio[859]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 15 19:17:15 volumio volumio[859]: (node:859) 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: 28) Apr 15 19:17:15 volumio volumio[859]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Apr 15 19:17:15 volumio volumio[859]: info: CoreCommandRouter::volumioGetState Apr 15 19:17:15 volumio volumio[859]: info: CorePlayQueue::getTrack 0 Apr 15 19:17:15 volumio volumio[859]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Apr 15 19:17:16 volumio volumio[859]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 15 19:17:16 volumio volumio[859]: info: Initializing connection to go-librespot Websocket Apr 15 19:17:16 volumio volumio[859]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 19:17:16 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 19:17:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 66. Apr 15 19:17:16 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 19:17:16 volumio systemd[1]: Started go-librespot Daemon. Apr 15 19:17:16 volumio go-librespot[2601]: Librespot-go daemon starting... Apr 15 19:17:16 volumio go-librespot[2601]: time="2024-04-15T19:17:16+08:00" level=info msg="generated new device id: 482d4cda6fc6625cac8c6fe0bdec455c059e6ec5" Apr 15 19:17:16 volumio go-librespot[2601]: time="2024-04-15T19:17:16+08:00" level=debug msg="stored credentials not found" Apr 15 19:17:17 volumio go-librespot[2601]: time="2024-04-15T19:17:17+08:00" level=debug msg="obtained new client token: AACh0Py0RAwZGEOIaoBOl/zwKABqemtW4UazpZpg2YUPG9SpheTXkRze/4iWxcpSqfGrzAcid1S6aZC5KD/heiJ/jpCgqWVD1hnAo6pwdn/aXNNRNAGI5ivNXDAVMb4FlIPADJ7lT7Dk7W9ueXf3Tml+yRGtFXIH0Foxu+pPzYNRWSaiVc+XWx5o8IcSXSPC7UpueMtwx+lNNg8micxUxv00IkjybF0r8HLGljWD7ZJmRXjTAJTT0D++B+QFQiU=" Apr 15 19:17:17 volumio go-librespot[2601]: time="2024-04-15T19:17: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 15 19:17:17 volumio go-librespot[2601]: time="2024-04-15T19:17:17+08:00" level=debug msg="completed keyexchange" Apr 15 19:17:17 volumio go-librespot[2601]: time="2024-04-15T19:17:17+08:00" level=debug msg="completed challenge" Apr 15 19:17:17 volumio go-librespot[2601]: time="2024-04-15T19:17:17+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 15 19:17:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 19:17:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 19:17:19 volumio volumio[859]: info: Initializing connection to go-librespot Websocket Apr 15 19:17:19 volumio volumio[859]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 19:17:21 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 19:17:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 67. Apr 15 19:17:21 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 19:17:21 volumio systemd[1]: Started go-librespot Daemon. Apr 15 19:17:21 volumio go-librespot[2610]: Librespot-go daemon starting... Apr 15 19:17:21 volumio go-librespot[2610]: time="2024-04-15T19:17:21+08:00" level=info msg="generated new device id: 8de6f366ff9f9a5d0a9980559bb57f189c710032" Apr 15 19:17:21 volumio go-librespot[2610]: time="2024-04-15T19:17:21+08:00" level=debug msg="stored credentials not found" Apr 15 19:17:21 volumio go-librespot[2610]: time="2024-04-15T19:17:21+08:00" level=debug msg="obtained new client token: AABrIlZtOajkA6qtJ7kalzr+2QJCBVL84emZOIsFyHv2cy7qauPEzpF0VvX0Ql2iOvtKW0iJZO2d7J6znLrWgF50sHGLCzXzs1WqxsgI/I6rFW6OUHOhDAmd0iBuuTYU4Id50rB9nHzv0OVQHuBC936UakNt44E9QTDTeDrcJz+bIic9Nw86+8Gr1GEaRLchGXbzFQ5RjDN6stnLhPpY0l6NigBw/vbD4EEhhWlbhz/SfEx4HdBmSaiPu8gGwjNlNQ==" Apr 15 19:17:21 volumio go-librespot[2610]: time="2024-04-15T19:17:21+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 15 19:17:22 volumio go-librespot[2610]: time="2024-04-15T19:17:22+08:00" level=debug msg="completed keyexchange" Apr 15 19:17:22 volumio go-librespot[2610]: time="2024-04-15T19:17:22+08:00" level=debug msg="completed challenge" Apr 15 19:17:22 volumio volumio[859]: info: Initializing connection to go-librespot Websocket Apr 15 19:17:22 volumio go-librespot[2610]: time="2024-04-15T19:17:22+08:00" level=debug msg="new websocket client" Apr 15 19:17:22 volumio volumio[859]: info: Connection to go-librespot Websocket established Apr 15 19:17:22 volumio go-librespot[2610]: time="2024-04-15T19:17:22+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 15 19:17:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 19:17:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 19:17:22 volumio volumio[859]: info: Connection to go-librespot Websocket closed Apr 15 19:17:23 volumio volumio[859]: info: CALLMETHOD: user_interface touch_display savePointerConf [object Object] Apr 15 19:17:23 volumio volumio[859]: info: CoreCommandRouter::executeOnPlugin: touch_display , savePointerConf Apr 15 19:17:23 volumio sudo[2621]: pam_unix(sudo:auth): authentication failure; logname= uid=1000 euid=0 tty= ruser=volumio rhost= user=volumio Apr 15 19:17:25 volumio sudo[2621]: pam_unix(sudo:auth): conversation failed Apr 15 19:17:25 volumio sudo[2621]: pam_unix(sudo:auth): auth could not identify password for [volumio] Apr 15 19:17:25 volumio sudo[2621]: volumio : 1 incorrect password attempt ; TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sed -i -e /ExecStart=\\/usr\\/bin\\/startx \\/etc\\/X11\\/Xsession \\/opt\\/volumiokiosk.sh/c\\ExecStart=\\/usr\\/bin\\/startx \\/etc\\/X11\\/Xsession \\/opt\\/volumiokiosk.sh -- -nocursor /lib/systemd/system/volumio-kiosk.service Apr 15 19:17:25 volumio volumio[859]: error: touch_display: Error modifying /lib/systemd/system/volumio-kiosk.service: Error: Command failed: /bin/echo volumio | /usr/bin/sudo -S /bin/sed -i -e '/ExecStart=\/usr\/bin\/startx \/etc\/X11\/Xsession \/opt\/volumiokiosk.sh/c\ExecStart=\/usr\/bin\/startx \/etc\/X11\/Xsession \/opt\/volumiokiosk.sh -- -nocursor' /lib/systemd/system/volumio-kiosk.service Apr 15 19:17:25 volumio volumio[859]: [sudo] password for volumio: Sorry, try again. Apr 15 19:17:25 volumio volumio[859]: [sudo] password for volumio: Apr 15 19:17:25 volumio volumio[859]: sudo: no password was provided Apr 15 19:17:25 volumio volumio[859]: sudo: 1 incorrect password attempt Apr 15 19:17:25 volumio volumio[859]: info: Getting Spotify volume Apr 15 19:17:25 volumio volumio[859]: (node:859) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 19:17:25 volumio volumio[859]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 15 19:17:25 volumio volumio[859]: (node:859) 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: 29) Apr 15 19:17:25 volumio volumio[859]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Apr 15 19:17:25 volumio volumio[859]: info: CoreCommandRouter::volumioGetState Apr 15 19:17:25 volumio volumio[859]: info: CorePlayQueue::getTrack 0 Apr 15 19:17:25 volumio volumio[859]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Apr 15 19:17:25 volumio volumio[859]: info: Initializing connection to go-librespot Websocket Apr 15 19:17:25 volumio volumio[859]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 19:17:25 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 19:17:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 68. Apr 15 19:17:25 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 19:17:25 volumio systemd[1]: Started go-librespot Daemon. Apr 15 19:17:25 volumio go-librespot[2622]: Librespot-go daemon starting... Apr 15 19:17:26 volumio go-librespot[2622]: time="2024-04-15T19:17:26+08:00" level=info msg="generated new device id: 112d677eff263268501ee20b93c69697a715577b" Apr 15 19:17:26 volumio go-librespot[2622]: time="2024-04-15T19:17:26+08:00" level=debug msg="stored credentials not found" Apr 15 19:17:26 volumio go-librespot[2622]: time="2024-04-15T19:17:26+08:00" level=debug msg="obtained new client token: AABhUw8XSh+W39ZJX/5oGO6BNLpq5UtSU7uB62Jg5+AWx73QzhY/jYTtr/7tH6daehhwvufWPg+LRST36seotYAT4t+BlNlDga+7KMK1FyxX35UDN7U2skMzTw6Dxg2Dfg5i6AmQuRpoLS5PaNLLhnUU+XiXwQoa5x+hhgd4RfrBIDwvlNt+L6uRcuKWXBHJE0JUmTYfiYcYDIsejruXMLZB8YiHiYJd7+La2eEa+kVoaZKAtJUCmlkGPdkUgLU=" Apr 15 19:17:26 volumio go-librespot[2622]: time="2024-04-15T19:17: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 15 19:17:26 volumio go-librespot[2622]: time="2024-04-15T19:17:26+08:00" level=debug msg="completed keyexchange" Apr 15 19:17:27 volumio go-librespot[2622]: time="2024-04-15T19:17:27+08:00" level=debug msg="completed challenge" Apr 15 19:17:27 volumio go-librespot[2622]: time="2024-04-15T19:17:27+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 15 19:17:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 19:17:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 19:17:28 volumio volumio[859]: info: Initializing connection to go-librespot Websocket Apr 15 19:17:28 volumio volumio[859]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 19:17:30 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 19:17:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 69. Apr 15 19:17:30 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 19:17:30 volumio systemd[1]: Started go-librespot Daemon. Apr 15 19:17:30 volumio go-librespot[2634]: Librespot-go daemon starting... Apr 15 19:17:30 volumio go-librespot[2634]: time="2024-04-15T19:17:30+08:00" level=info msg="generated new device id: 033a942bee71b3ba7d7c53a12ad89e2a9ac979ec" Apr 15 19:17:30 volumio go-librespot[2634]: time="2024-04-15T19:17:30+08:00" level=debug msg="stored credentials not found" Apr 15 19:17:31 volumio go-librespot[2634]: time="2024-04-15T19:17:31+08:00" level=debug msg="obtained new client token: AAAyuEhkXhPjtHweFj5f80eRTkUWnWuGHQPBA/bGMQpSS8YNZMXvsdgc6SjLS9OdaTGTUPFlgzKTxHGNZA+2tjzJ7h6W7Nemdq7rkXoNySeese1r6I0NfUWzk1RZu3mTvV/bMRXd20zC0l+D4OjTPkr0vFU6DlFUQiDsOkIRtRknMyurEOqvLZ51buQIhIh46RcqAuUlMv4M0EFO2x+kpQEn0TYkfPZahnqGXDgwQQDe1ywgJGSnBUON2byLduQ=" Apr 15 19:17:31 volumio go-librespot[2634]: time="2024-04-15T19:17: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 15 19:17:31 volumio go-librespot[2634]: time="2024-04-15T19:17:31+08:00" level=debug msg="completed keyexchange" Apr 15 19:17:31 volumio volumio[859]: info: Initializing connection to go-librespot Websocket Apr 15 19:17:31 volumio go-librespot[2634]: time="2024-04-15T19:17:31+08:00" level=debug msg="new websocket client" Apr 15 19:17:31 volumio volumio[859]: info: Connection to go-librespot Websocket established Apr 15 19:17:32 volumio go-librespot[2634]: time="2024-04-15T19:17:32+08:00" level=debug msg="completed challenge" Apr 15 19:17:32 volumio go-librespot[2634]: time="2024-04-15T19:17: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" Apr 15 19:17:32 volumio volumio[859]: info: Connection to go-librespot Websocket closed Apr 15 19:17:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 19:17:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 19:17:33 volumio volumio[859]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 15 19:17:33 volumio volumio[859]: Error: connect ETIMEDOUT 104.244.43.248:80 Apr 15 19:17:33 volumio volumio[859]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) { Apr 15 19:17:33 volumio volumio[859]: errno: -110, Apr 15 19:17:33 volumio volumio[859]: code: 'ETIMEDOUT', Apr 15 19:17:33 volumio volumio[859]: syscall: 'connect', Apr 15 19:17:33 volumio volumio[859]: address: '104.244.43.248', Apr 15 19:17:33 volumio volumio[859]: port: 80 Apr 15 19:17:33 volumio volumio[859]: } Apr 15 19:17:33 volumio volumio[859]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 15 19:17:34 volumio sudo[2654]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-15 19:16 Apr 15 19:17:34 volumio sudo[2654]: 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"