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