-- Logs begin at Fri 2024-04-05 08:48:06 EEST, end at Fri 2024-04-05 10:36:47 EEST. -- Apr 05 10:35:00 volumio go-librespot[20160]: time="2024-04-05T10:35:00+03:00" level=debug msg="completed challenge" Apr 05 10:35:00 volumio go-librespot[20160]: time="2024-04-05T10:35:00+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Apr 05 10:35:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 05 10:35:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 05 10:35:01 volumio volumio[994]: info: Initializing connection to go-librespot Websocket Apr 05 10:35:01 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 05 10:35:03 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 05 10:35:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1599. Apr 05 10:35:03 volumio systemd[1]: Stopped go-librespot Daemon. Apr 05 10:35:03 volumio systemd[1]: Started go-librespot Daemon. Apr 05 10:35:03 volumio go-librespot[20168]: Librespot-go daemon starting... Apr 05 10:35:03 volumio go-librespot[20168]: time="2024-04-05T10:35:03+03:00" level=info msg="generated new device id: 20da67c13967ac030a920f90dd6d118f83caa3cb" Apr 05 10:35:03 volumio go-librespot[20168]: time="2024-04-05T10:35:03+03:00" level=debug msg="stored credentials found for 31xvf3vpjlld6elhjalvllnvrsb4" Apr 05 10:35:04 volumio go-librespot[20168]: time="2024-04-05T10:35:04+03:00" level=debug msg="obtained new client token: AACdycepO91lwXY9vVG1e5yxw8e0tfmmatUOP+y8Ik6Khm/vaXrWpxuH9D6En5rL8ZqSQNWjhzJ5ypr5BBJCRnBEqkUZec35nQnVWGMi6NILRUmL1u1t8gpbd8ko4+VkXKRqh0x35vDoOXDCg9NJmZdckUZn7eBo8WLG3dMTC7Wiheb/A/XuaPTM5mHfLPQ2WgwRBfkQi8D0HxqpoTsDJal53xUp+P84UlNaKmYfbMu7a+bE/X9a3Sc815Kk" Apr 05 10:35:04 volumio volumio[994]: info: Initializing connection to go-librespot Websocket Apr 05 10:35:04 volumio go-librespot[20168]: time="2024-04-05T10:35:04+03:00" level=debug msg="new websocket client" Apr 05 10:35:04 volumio volumio[994]: info: Connection to go-librespot Websocket established Apr 05 10:35:04 volumio go-librespot[20168]: time="2024-04-05T10:35:04+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 05 10:35:04 volumio go-librespot[20168]: time="2024-04-05T10:35:04+03:00" level=debug msg="completed keyexchange" Apr 05 10:35:04 volumio go-librespot[20168]: time="2024-04-05T10:35:04+03:00" level=debug msg="completed challenge" Apr 05 10:35:04 volumio go-librespot[20168]: time="2024-04-05T10:35:04+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Apr 05 10:35:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 05 10:35:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 05 10:35:04 volumio volumio[994]: info: Connection to go-librespot Websocket closed Apr 05 10:35:07 volumio volumio[994]: info: Getting Spotify volume Apr 05 10:35:07 volumio volumio[994]: (node:994) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 05 10:35:07 volumio volumio[994]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Apr 05 10:35:07 volumio volumio[994]: (node:994) 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: 550) Apr 05 10:35:07 volumio volumio[994]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Apr 05 10:35:07 volumio volumio[994]: info: CoreCommandRouter::volumioGetState Apr 05 10:35:07 volumio volumio[994]: info: CorePlayQueue::getTrack 3 Apr 05 10:35:07 volumio volumio[994]: SPOTIFY: RECEIVED VOLUMIO VOLUME 69 Apr 05 10:35:07 volumio volumio[994]: info: Initializing connection to go-librespot Websocket Apr 05 10:35:07 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 05 10:35:08 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 05 10:35:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1600. Apr 05 10:35:08 volumio systemd[1]: Stopped go-librespot Daemon. Apr 05 10:35:08 volumio systemd[1]: Started go-librespot Daemon. Apr 05 10:35:08 volumio go-librespot[20177]: Librespot-go daemon starting... Apr 05 10:35:08 volumio go-librespot[20177]: time="2024-04-05T10:35:08+03:00" level=info msg="generated new device id: b5c9225c4254d95e87063b87f49e20505875efba" Apr 05 10:35:08 volumio go-librespot[20177]: time="2024-04-05T10:35:08+03:00" level=debug msg="stored credentials found for 31xvf3vpjlld6elhjalvllnvrsb4" Apr 05 10:35:08 volumio go-librespot[20177]: time="2024-04-05T10:35:08+03:00" level=debug msg="obtained new client token: AADdUPWXQg7JtqF2FkGPIdvig4vVKmzHFjkZx/Rlkzt9ebJ4Vx7uioXE5pMnTHJhFcHXtSBkzHTYpvcVDFcmhbyP3BbtsXAJu7AJhSU8Gu6ZrpYcYP2P7rT0+dmkckL8Qxogc2o9QGaesIcgl9Hz6CEmRepokk8wZ/bBFj4oQd0FCcppYo1dDwmmOeJfThsmHbdBNBxT+RAqcCSqi15CNJK5BeY6ZEaJZ/YdvcHOhQWNMGOe0BavQiH5HSsS7RQ=" Apr 05 10:35:08 volumio go-librespot[20177]: time="2024-04-05T10:35:08+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 05 10:35:08 volumio go-librespot[20177]: time="2024-04-05T10:35:08+03:00" level=debug msg="completed keyexchange" Apr 05 10:35:09 volumio go-librespot[20177]: time="2024-04-05T10:35:09+03:00" level=debug msg="completed challenge" Apr 05 10:35:09 volumio go-librespot[20177]: time="2024-04-05T10:35:09+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Apr 05 10:35:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 05 10:35:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 05 10:35:10 volumio volumio[994]: info: Initializing connection to go-librespot Websocket Apr 05 10:35:10 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 05 10:35:12 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 05 10:35:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1601. Apr 05 10:35:12 volumio systemd[1]: Stopped go-librespot Daemon. Apr 05 10:35:12 volumio systemd[1]: Started go-librespot Daemon. Apr 05 10:35:12 volumio go-librespot[20185]: Librespot-go daemon starting... Apr 05 10:35:12 volumio go-librespot[20185]: time="2024-04-05T10:35:12+03:00" level=info msg="generated new device id: 633fd0e90f410c81714574afc8cbd8553c52d0c7" Apr 05 10:35:12 volumio go-librespot[20185]: time="2024-04-05T10:35:12+03:00" level=debug msg="stored credentials found for 31xvf3vpjlld6elhjalvllnvrsb4" Apr 05 10:35:12 volumio go-librespot[20185]: time="2024-04-05T10:35:12+03:00" level=debug msg="obtained new client token: AABJs1lvLzEae3qgWFxGRBGesFogZrvaoLaSwOS1sQ/8+Ok5Lutc2LJ9S7pHb6bp65AskaGnTuRtmhMEBJ/Zh57J4iT376+yVIMVpS+6kl1jTKmSUffEIjq1eL/2PDvP7jcOf79uHTSlmBCFPb/d9RQbbymwdqXBY8ACdE7rTsvDm3tvuMocBnwDfsQyNhdg2mvPLu+FhLYbtT+fCOwtRx4ku3iVrE8VBNv8+a7J4NS7xRhwzUyBTK/NEASD8pE=" Apr 05 10:35:12 volumio go-librespot[20185]: time="2024-04-05T10:35:12+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 05 10:35:12 volumio go-librespot[20185]: time="2024-04-05T10:35:12+03:00" level=debug msg="completed keyexchange" Apr 05 10:35:13 volumio go-librespot[20185]: time="2024-04-05T10:35:13+03:00" level=debug msg="completed challenge" Apr 05 10:35:13 volumio go-librespot[20185]: time="2024-04-05T10:35:13+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Apr 05 10:35:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 05 10:35:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 05 10:35:13 volumio volumio[994]: info: Initializing connection to go-librespot Websocket Apr 05 10:35:13 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 05 10:35:16 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 05 10:35:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1602. Apr 05 10:35:16 volumio systemd[1]: Stopped go-librespot Daemon. Apr 05 10:35:16 volumio systemd[1]: Started go-librespot Daemon. Apr 05 10:35:16 volumio go-librespot[20194]: Librespot-go daemon starting... Apr 05 10:35:16 volumio go-librespot[20194]: time="2024-04-05T10:35:16+03:00" level=info msg="generated new device id: 9478f1551be8b7a770ae565164487f6c76926541" Apr 05 10:35:16 volumio go-librespot[20194]: time="2024-04-05T10:35:16+03:00" level=debug msg="stored credentials found for 31xvf3vpjlld6elhjalvllnvrsb4" Apr 05 10:35:16 volumio go-librespot[20194]: time="2024-04-05T10:35:16+03:00" level=debug msg="obtained new client token: AACXrMrN00lfMs2yoSuzrXCikDoJlB8brXTIzj1KZB68M/QOnOxmVZXL1Jv3Q69jkp+pdaHDvGkQo0eyzWowkPQsyevxQ+zMJlTrh4Mj5nNkl8/wuQop+1OsJWzfCu/sOErcNbEFE6VIxxAQaYb/EoJEGr8CDhyMcRknF9/qjg70zkQjMWitxvhIyKYgl4uXwOulA3JSik18WkatqT4lUQeE4xdS8edfShiFVR82ZZl2g4Pujjy1E204uwdzUnM=" Apr 05 10:35:16 volumio volumio[994]: info: Initializing connection to go-librespot Websocket Apr 05 10:35:16 volumio go-librespot[20194]: time="2024-04-05T10:35:16+03:00" level=debug msg="new websocket client" Apr 05 10:35:16 volumio volumio[994]: info: Connection to go-librespot Websocket established Apr 05 10:35:16 volumio go-librespot[20194]: time="2024-04-05T10:35:16+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 05 10:35:17 volumio go-librespot[20194]: time="2024-04-05T10:35:17+03:00" level=debug msg="completed keyexchange" Apr 05 10:35:17 volumio go-librespot[20194]: time="2024-04-05T10:35:17+03:00" level=debug msg="completed challenge" Apr 05 10:35:17 volumio go-librespot[20194]: time="2024-04-05T10:35:17+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Apr 05 10:35:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 05 10:35:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 05 10:35:17 volumio volumio[994]: info: Connection to go-librespot Websocket closed Apr 05 10:35:19 volumio volumio[994]: info: Getting Spotify volume Apr 05 10:35:19 volumio volumio[994]: (node:994) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 05 10:35:19 volumio volumio[994]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Apr 05 10:35:19 volumio volumio[994]: (node:994) 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: 551) Apr 05 10:35:19 volumio volumio[994]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Apr 05 10:35:19 volumio volumio[994]: info: CoreCommandRouter::volumioGetState Apr 05 10:35:19 volumio volumio[994]: info: CorePlayQueue::getTrack 3 Apr 05 10:35:19 volumio volumio[994]: SPOTIFY: RECEIVED VOLUMIO VOLUME 69 Apr 05 10:35:20 volumio volumio[994]: info: Initializing connection to go-librespot Websocket Apr 05 10:35:20 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 05 10:35:20 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 05 10:35:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1603. Apr 05 10:35:20 volumio systemd[1]: Stopped go-librespot Daemon. Apr 05 10:35:20 volumio systemd[1]: Started go-librespot Daemon. Apr 05 10:35:20 volumio go-librespot[20244]: Librespot-go daemon starting... Apr 05 10:35:20 volumio go-librespot[20244]: time="2024-04-05T10:35:20+03:00" level=info msg="generated new device id: ddef572a0e2e91f54b7ad7f314be83b276e5e858" Apr 05 10:35:20 volumio go-librespot[20244]: time="2024-04-05T10:35:20+03:00" level=debug msg="stored credentials found for 31xvf3vpjlld6elhjalvllnvrsb4" Apr 05 10:35:21 volumio go-librespot[20244]: time="2024-04-05T10:35:21+03:00" level=debug msg="obtained new client token: AADxxhvH19ldmLhItVhl0CS9lVJhxrqJ9knf6yLLYtvBD6DrSrvEuVFdp4SWcXwaQ8dKOpP6TwcfdMmcVwN1H722WYrraB0oxvHeFmEvslkfnQYS4+r9BysKmiaOCeGr7JwX8P6Y8LIZHz4Msj1481kyLIKIf5T10mPN5d7SqFIcLmNT+NGWUyt9MJDvg5sIUAMno4v26hqwJl0XyLa05RcriWWDeLbKBwQuqM3n9NJlOG+4V4HdfNTkBgRX" Apr 05 10:35:21 volumio go-librespot[20244]: time="2024-04-05T10:35:21+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 05 10:35:21 volumio go-librespot[20244]: time="2024-04-05T10:35:21+03:00" level=debug msg="completed keyexchange" Apr 05 10:35:21 volumio go-librespot[20244]: time="2024-04-05T10:35:21+03:00" level=debug msg="completed challenge" Apr 05 10:35:21 volumio go-librespot[20244]: time="2024-04-05T10:35:21+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Apr 05 10:35:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 05 10:35:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 05 10:35:23 volumio volumio[994]: info: Initializing connection to go-librespot Websocket Apr 05 10:35:23 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 05 10:35:25 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 05 10:35:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1604. Apr 05 10:35:25 volumio systemd[1]: Stopped go-librespot Daemon. Apr 05 10:35:25 volumio systemd[1]: Started go-librespot Daemon. Apr 05 10:35:25 volumio go-librespot[20252]: Librespot-go daemon starting... Apr 05 10:35:25 volumio go-librespot[20252]: time="2024-04-05T10:35:25+03:00" level=info msg="generated new device id: 4a0c23ae8c660f0658d975bfbb396e1242b893ee" Apr 05 10:35:25 volumio go-librespot[20252]: time="2024-04-05T10:35:25+03:00" level=debug msg="stored credentials found for 31xvf3vpjlld6elhjalvllnvrsb4" Apr 05 10:35:25 volumio go-librespot[20252]: time="2024-04-05T10:35:25+03:00" level=debug msg="obtained new client token: AADPRTSJcWrdtb0PuCVEXXd0SpJsgnASldvasTdgVk0RCXd+5BVt8EIt5Jdp2Z18OBlhwn9bIxczvV4gTd3QssRSkljaaJuSuIQbYY/mswQPI3OvaPTciCIWoV4kpTyMZZdvTwzc+DfqKcrl3OYTz1E4U3m+I0x84bGfsFIQLtox/YLEW083G3B+y6oNToDLwLXIvmBsEiA5N9LVA53XzHl9EVFpBbwoL9CYbdC8ZAPWwO5NQe8JeHQN7gkzWcE=" Apr 05 10:35:25 volumio go-librespot[20252]: time="2024-04-05T10:35:25+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 05 10:35:25 volumio go-librespot[20252]: time="2024-04-05T10:35:25+03:00" level=debug msg="completed keyexchange" Apr 05 10:35:26 volumio go-librespot[20252]: time="2024-04-05T10:35:26+03:00" level=debug msg="completed challenge" Apr 05 10:35:26 volumio go-librespot[20252]: time="2024-04-05T10:35:26+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Apr 05 10:35:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 05 10:35:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 05 10:35:26 volumio volumio[994]: info: Initializing connection to go-librespot Websocket Apr 05 10:35:26 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 05 10:35:29 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 05 10:35:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1605. Apr 05 10:35:29 volumio systemd[1]: Stopped go-librespot Daemon. Apr 05 10:35:29 volumio systemd[1]: Started go-librespot Daemon. Apr 05 10:35:29 volumio go-librespot[20260]: Librespot-go daemon starting... Apr 05 10:35:29 volumio go-librespot[20260]: time="2024-04-05T10:35:29+03:00" level=info msg="generated new device id: 5caa1937856d9371b8956e25e74fe88d0d968ff2" Apr 05 10:35:29 volumio go-librespot[20260]: time="2024-04-05T10:35:29+03:00" level=debug msg="stored credentials found for 31xvf3vpjlld6elhjalvllnvrsb4" Apr 05 10:35:29 volumio go-librespot[20260]: time="2024-04-05T10:35:29+03:00" level=debug msg="obtained new client token: AADVyBFEdnExrvx+IP5HwJkm5WgglQjeMVSI9sC51vlBuz3Cqc2Vc8Eax8twHr5CLN0FplsdCppew0m0Bbr53BAw1nr3AtwNfS1JP3HU+NVMRJzx+dwhpvXNBiALoDGlMugeQ4KQFEW6TSeGMFex/d1IEpQD2AoqGWr0/Kn+YH/KDkA9ndhhq3F3/myVbrwH2tfvvoF1bojizXN+A/0JPiw1uNFRtzalyx+ne0+T4mkp46+9SatTXV7icoswUTc=" Apr 05 10:35:29 volumio volumio[994]: info: Initializing connection to go-librespot Websocket Apr 05 10:35:29 volumio volumio[994]: info: Connection to go-librespot Websocket established Apr 05 10:35:29 volumio go-librespot[20260]: time="2024-04-05T10:35:29+03:00" level=debug msg="new websocket client" Apr 05 10:35:29 volumio go-librespot[20260]: time="2024-04-05T10:35:29+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 05 10:35:29 volumio go-librespot[20260]: time="2024-04-05T10:35:29+03:00" level=debug msg="completed keyexchange" Apr 05 10:35:30 volumio go-librespot[20260]: time="2024-04-05T10:35:30+03:00" level=debug msg="completed challenge" Apr 05 10:35:30 volumio go-librespot[20260]: time="2024-04-05T10:35:30+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Apr 05 10:35:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 05 10:35:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 05 10:35:30 volumio volumio[994]: info: Connection to go-librespot Websocket closed Apr 05 10:35:32 volumio volumio[994]: info: Getting Spotify volume Apr 05 10:35:32 volumio volumio[994]: (node:994) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 05 10:35:32 volumio volumio[994]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Apr 05 10:35:32 volumio volumio[994]: (node:994) 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: 552) Apr 05 10:35:32 volumio volumio[994]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Apr 05 10:35:32 volumio volumio[994]: info: CoreCommandRouter::volumioGetState Apr 05 10:35:32 volumio volumio[994]: info: CorePlayQueue::getTrack 3 Apr 05 10:35:32 volumio volumio[994]: SPOTIFY: RECEIVED VOLUMIO VOLUME 69 Apr 05 10:35:33 volumio volumio[994]: info: Initializing connection to go-librespot Websocket Apr 05 10:35:33 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 05 10:35:33 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 05 10:35:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1606. Apr 05 10:35:33 volumio systemd[1]: Stopped go-librespot Daemon. Apr 05 10:35:33 volumio systemd[1]: Started go-librespot Daemon. Apr 05 10:35:33 volumio go-librespot[20269]: Librespot-go daemon starting... Apr 05 10:35:33 volumio go-librespot[20269]: time="2024-04-05T10:35:33+03:00" level=info msg="generated new device id: 02e69caf1b5e0850f57790cf2075e31f7d32b39d" Apr 05 10:35:33 volumio go-librespot[20269]: time="2024-04-05T10:35:33+03:00" level=debug msg="stored credentials found for 31xvf3vpjlld6elhjalvllnvrsb4" Apr 05 10:35:33 volumio go-librespot[20269]: time="2024-04-05T10:35:33+03:00" level=debug msg="obtained new client token: AADummKN4bAJS7KxrU5B8vhyZ/T59efyuK2Yf9drdnyiJ30nwtcqCSG9qhSax9u6+59ZNMajDXtwx8ERilEqXVhjz1R4l+670gHlSRFYhGKHoo+UI7pp46DJ/bcw3hBjADUvSzUvPzMYEp8McSJU5YTyjXdafsYkTBVXSbuPAMK8hmRKR47yXigyDZZJreRsxwquLUszRVnmIz5nzlr4CfdQDceiN+jkgt8chCXSiOz4Vw6PgQvLdm4T7iO6kbk=" Apr 05 10:35:33 volumio go-librespot[20269]: time="2024-04-05T10:35:33+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 05 10:35:34 volumio go-librespot[20269]: time="2024-04-05T10:35:34+03:00" level=debug msg="completed keyexchange" Apr 05 10:35:34 volumio go-librespot[20269]: time="2024-04-05T10:35:34+03:00" level=debug msg="completed challenge" Apr 05 10:35:34 volumio go-librespot[20269]: time="2024-04-05T10:35:34+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Apr 05 10:35:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 05 10:35:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 05 10:35:36 volumio volumio[994]: info: Initializing connection to go-librespot Websocket Apr 05 10:35:36 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 05 10:35:37 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 05 10:35:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1607. Apr 05 10:35:37 volumio systemd[1]: Stopped go-librespot Daemon. Apr 05 10:35:37 volumio systemd[1]: Started go-librespot Daemon. Apr 05 10:35:37 volumio go-librespot[20277]: Librespot-go daemon starting... Apr 05 10:35:37 volumio go-librespot[20277]: time="2024-04-05T10:35:37+03:00" level=info msg="generated new device id: 6876ec5e138a2da8addad68fb86bde0fe3f50a8c" Apr 05 10:35:37 volumio go-librespot[20277]: time="2024-04-05T10:35:37+03:00" level=debug msg="stored credentials found for 31xvf3vpjlld6elhjalvllnvrsb4" Apr 05 10:35:38 volumio go-librespot[20277]: time="2024-04-05T10:35:38+03:00" level=debug msg="obtained new client token: AACmm38ctv8U85YN1OhUwXPB1ZOW3CS+fW0N/AKY1DcUMdjW1dEeZp9Aqzl6HdsfDsOAfa4am5J3huU+fuWKv+4gXsCJWjpjDnbC4gvyrpRfoQls0dgpDCqLz4mD5bwJs+4iipAN9JHSo8wFf6JWv+BuDJvjy9HZRzKP3bfNmaaJQjsYIx0AB+hvvspi3U944HxvXZZkXiOTmgSEcpoNwT9huRjJh/7p7ll07Z9Q1yeHOOsAc+asShrC0P/l" Apr 05 10:35:38 volumio go-librespot[20277]: time="2024-04-05T10:35:38+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Apr 05 10:35:39 volumio volumio[994]: info: Initializing connection to go-librespot Websocket Apr 05 10:35:39 volumio go-librespot[20277]: time="2024-04-05T10:35:39+03:00" level=debug msg="new websocket client" Apr 05 10:35:39 volumio volumio[994]: info: Connection to go-librespot Websocket established Apr 05 10:35:39 volumio go-librespot[20277]: time="2024-04-05T10:35:39+03:00" level=debug msg="completed keyexchange" Apr 05 10:35:39 volumio go-librespot[20277]: time="2024-04-05T10:35:39+03:00" level=debug msg="completed challenge" Apr 05 10:35:40 volumio go-librespot[20277]: time="2024-04-05T10:35:40+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Apr 05 10:35:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 05 10:35:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 05 10:35:40 volumio volumio[994]: info: Connection to go-librespot Websocket closed Apr 05 10:35:42 volumio volumio[994]: info: Getting Spotify volume Apr 05 10:35:42 volumio volumio[994]: (node:994) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 05 10:35:42 volumio volumio[994]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Apr 05 10:35:42 volumio volumio[994]: (node:994) 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: 553) Apr 05 10:35:42 volumio volumio[994]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Apr 05 10:35:42 volumio volumio[994]: info: CoreCommandRouter::volumioGetState Apr 05 10:35:42 volumio volumio[994]: info: CorePlayQueue::getTrack 3 Apr 05 10:35:42 volumio volumio[994]: SPOTIFY: RECEIVED VOLUMIO VOLUME 69 Apr 05 10:35:43 volumio volumio[994]: info: Initializing connection to go-librespot Websocket Apr 05 10:35:43 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 05 10:35:43 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 05 10:35:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1608. Apr 05 10:35:43 volumio systemd[1]: Stopped go-librespot Daemon. Apr 05 10:35:43 volumio systemd[1]: Started go-librespot Daemon. Apr 05 10:35:43 volumio go-librespot[20285]: Librespot-go daemon starting... Apr 05 10:35:43 volumio go-librespot[20285]: time="2024-04-05T10:35:43+03:00" level=info msg="generated new device id: 15609ee972fb5fb4f091473f28125b622c0521e1" Apr 05 10:35:43 volumio go-librespot[20285]: time="2024-04-05T10:35:43+03:00" level=debug msg="stored credentials found for 31xvf3vpjlld6elhjalvllnvrsb4" Apr 05 10:35:43 volumio go-librespot[20285]: time="2024-04-05T10:35:43+03:00" level=debug msg="obtained new client token: AAAUp+iWxPb//HeEV1PtyfHm1JoMTZ8Jj6XtTzoKpJ0FaqPtFdWtPqUbuiU4dCB2U3ZFtOMYI0OOJpLBe+acLxwUowHcd8VpChpkPVvS0mLbIuoWMFF5oGi12hs1ycD4E2v2Ee7KXzuVHPNwwYGlijMT4jAkizvW++6n/uftz8FuHLPWUMN+C1PtMcSbwaSIDrdAZOPll4TcpeS8JWs+yJ+V+AdxRUvYJbKRrWxwIJzc5SWjrE11iv9cI/ug84s=" Apr 05 10:35:43 volumio go-librespot[20285]: time="2024-04-05T10:35:43+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Apr 05 10:35:43 volumio go-librespot[20285]: time="2024-04-05T10:35:43+03:00" level=debug msg="completed keyexchange" Apr 05 10:35:44 volumio go-librespot[20285]: time="2024-04-05T10:35:44+03:00" level=debug msg="completed challenge" Apr 05 10:35:44 volumio go-librespot[20285]: time="2024-04-05T10:35:44+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Apr 05 10:35:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 05 10:35:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 05 10:35:46 volumio volumio[994]: info: Initializing connection to go-librespot Websocket Apr 05 10:35:46 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 05 10:35:47 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 05 10:35:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1609. Apr 05 10:35:47 volumio systemd[1]: Stopped go-librespot Daemon. Apr 05 10:35:47 volumio systemd[1]: Started go-librespot Daemon. Apr 05 10:35:47 volumio go-librespot[20293]: Librespot-go daemon starting... Apr 05 10:35:47 volumio go-librespot[20293]: time="2024-04-05T10:35:47+03:00" level=info msg="generated new device id: 98c2b5e2a775e4d2f6412d4349d6db22fcc4678b" Apr 05 10:35:47 volumio go-librespot[20293]: time="2024-04-05T10:35:47+03:00" level=debug msg="stored credentials found for 31xvf3vpjlld6elhjalvllnvrsb4" Apr 05 10:35:47 volumio go-librespot[20293]: time="2024-04-05T10:35:47+03:00" level=debug msg="obtained new client token: AADeS2aOPcsT4G92VZ6XoW068EvS0hm85scmvPJV5OX6E4yKzez+nsEqwaS1Rn7xg09/FaMGhPgCC8Dp5Hoy6pV9OzmH9Bnk1LD55EU8xRoOwEFsG4t0ZkAsWBX1/vGm3lPNcdizkC6ql3HNBLfplpo/YwDj56da2kf6t7hfMDpQSTjXVA2HuNmdI0Xj07S6xUtf6Zsqw/8Bl8MBoEMQn/pBCwskbucgs+Xnwnhvana6+z6h3EiD8DLjNgET2/g=" Apr 05 10:35:47 volumio go-librespot[20293]: time="2024-04-05T10:35:47+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 05 10:35:48 volumio go-librespot[20293]: time="2024-04-05T10:35:48+03:00" level=debug msg="completed keyexchange" Apr 05 10:35:48 volumio go-librespot[20293]: time="2024-04-05T10:35:48+03:00" level=debug msg="completed challenge" Apr 05 10:35:48 volumio go-librespot[20293]: time="2024-04-05T10:35:48+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Apr 05 10:35:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 05 10:35:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 05 10:35:49 volumio volumio[994]: info: Initializing connection to go-librespot Websocket Apr 05 10:35:49 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 05 10:35:51 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 05 10:35:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1610. Apr 05 10:35:51 volumio systemd[1]: Stopped go-librespot Daemon. Apr 05 10:35:51 volumio systemd[1]: Started go-librespot Daemon. Apr 05 10:35:51 volumio go-librespot[20301]: Librespot-go daemon starting... Apr 05 10:35:51 volumio go-librespot[20301]: time="2024-04-05T10:35:51+03:00" level=info msg="generated new device id: e597ab81d456a71a7591d723158bde163a2195b6" Apr 05 10:35:51 volumio go-librespot[20301]: time="2024-04-05T10:35:51+03:00" level=debug msg="stored credentials found for 31xvf3vpjlld6elhjalvllnvrsb4" Apr 05 10:35:52 volumio go-librespot[20301]: time="2024-04-05T10:35:52+03:00" level=debug msg="obtained new client token: AAAckA6sijOOzgwg0NJx+cyS6hONGAF0t3DB9cKmf7+LKhACZd7uowIsj6jkGzJOzkqi7ZO2LaF2Tlh5Y5Wc+bDdi9KhOocCqas2Lcp76gD7qMJ5U4IwRrgp4ZKtjha2kwkHKcDcr34XwrJ4UVB+pOvE1Ok6nnX3JloXLQtXOnua+5LRPUrdMP+Zc51rnqsVF8H3U75JdheCajj7tV1A2N4etvKSEQJHjPgtPIGJTly9qrlDeRxjPyxj5unm" Apr 05 10:35:52 volumio volumio[994]: info: Initializing connection to go-librespot Websocket Apr 05 10:35:52 volumio go-librespot[20301]: time="2024-04-05T10:35:52+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Apr 05 10:35:52 volumio volumio[994]: info: Connection to go-librespot Websocket established Apr 05 10:35:52 volumio go-librespot[20301]: time="2024-04-05T10:35:52+03:00" level=debug msg="new websocket client" Apr 05 10:35:52 volumio go-librespot[20301]: time="2024-04-05T10:35:52+03:00" level=debug msg="completed keyexchange" Apr 05 10:35:52 volumio nmbd[691]: [2024/04/05 10:35:52.559362, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Apr 05 10:35:52 volumio nmbd[691]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.0.155 for name WORKGROUP<1d>. Apr 05 10:35:52 volumio nmbd[691]: This response was from IP 192.168.0.3, reporting an IP address of 192.168.0.3. Apr 05 10:35:52 volumio go-librespot[20301]: time="2024-04-05T10:35:52+03:00" level=debug msg="completed challenge" Apr 05 10:35:52 volumio go-librespot[20301]: time="2024-04-05T10:35:52+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Apr 05 10:35:52 volumio volumio[994]: info: Connection to go-librespot Websocket closed Apr 05 10:35:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 05 10:35:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 05 10:35:55 volumio volumio[994]: info: Getting Spotify volume Apr 05 10:35:55 volumio volumio[994]: (node:994) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 05 10:35:55 volumio volumio[994]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Apr 05 10:35:55 volumio volumio[994]: (node:994) 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: 554) Apr 05 10:35:55 volumio volumio[994]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Apr 05 10:35:55 volumio volumio[994]: info: CoreCommandRouter::volumioGetState Apr 05 10:35:55 volumio volumio[994]: info: CorePlayQueue::getTrack 3 Apr 05 10:35:55 volumio volumio[994]: SPOTIFY: RECEIVED VOLUMIO VOLUME 69 Apr 05 10:35:55 volumio volumio[994]: info: Initializing connection to go-librespot Websocket Apr 05 10:35:55 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 05 10:35:56 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 05 10:35:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1611. Apr 05 10:35:56 volumio systemd[1]: Stopped go-librespot Daemon. Apr 05 10:35:56 volumio systemd[1]: Started go-librespot Daemon. Apr 05 10:35:56 volumio go-librespot[20311]: Librespot-go daemon starting... Apr 05 10:35:56 volumio go-librespot[20311]: time="2024-04-05T10:35:56+03:00" level=info msg="generated new device id: ef846a4c9aacfff2b0704e1369d3041a0c142d1f" Apr 05 10:35:56 volumio go-librespot[20311]: time="2024-04-05T10:35:56+03:00" level=debug msg="stored credentials found for 31xvf3vpjlld6elhjalvllnvrsb4" Apr 05 10:35:56 volumio go-librespot[20311]: time="2024-04-05T10:35:56+03:00" level=debug msg="obtained new client token: AAB0esUSvjJMrQ8eHEo2S76PBgTB5qfj18iXotRfQ98mOz8rG+oVd48rlyefPvwAUMC95/cL4YAgeG3irVuykhM+UjYaI3wWRs5l2iEMefbZV9r8tMdcVU8SOaPJyLZzSYauspkqZ9AdxKzlTSQfMOa/iB4cblFsGpIp6s+X9Mfm73C6NvkKSnsjhJD+nqScJLE9vj74Qp9tvW2YgF/36iR56huwlQILu4sEe/JF/Yzi9hx4TRv64tejQoY6ybQ=" Apr 05 10:35:56 volumio go-librespot[20311]: time="2024-04-05T10:35:56+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 05 10:35:56 volumio go-librespot[20311]: time="2024-04-05T10:35:56+03:00" level=debug msg="completed keyexchange" Apr 05 10:35:57 volumio go-librespot[20311]: time="2024-04-05T10:35:57+03:00" level=debug msg="completed challenge" Apr 05 10:35:57 volumio go-librespot[20311]: time="2024-04-05T10:35:57+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Apr 05 10:35:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 05 10:35:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 05 10:35:58 volumio volumio[994]: info: Initializing connection to go-librespot Websocket Apr 05 10:35:58 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 05 10:36:00 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 05 10:36:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1612. Apr 05 10:36:00 volumio systemd[1]: Stopped go-librespot Daemon. Apr 05 10:36:00 volumio systemd[1]: Started go-librespot Daemon. Apr 05 10:36:00 volumio go-librespot[20319]: Librespot-go daemon starting... Apr 05 10:36:00 volumio go-librespot[20319]: time="2024-04-05T10:36:00+03:00" level=info msg="generated new device id: 275d37d43ca28e387d4f945e659cc3176963b27a" Apr 05 10:36:00 volumio go-librespot[20319]: time="2024-04-05T10:36:00+03:00" level=debug msg="stored credentials found for 31xvf3vpjlld6elhjalvllnvrsb4" Apr 05 10:36:00 volumio go-librespot[20319]: time="2024-04-05T10:36:00+03:00" level=debug msg="obtained new client token: AABN/5Fa3QVqqqFQj+UXHu9RFb2u17uSJ5UMZYWp8tNd+dWObxZs2+o5HJLHqgHIwhKmjnlJaaeaeZxpaySwdo5IEFejRbInKEOmkp6bo7lU5W24F42UkvzEWcYC0Z24sJSE3iFwBPp1qSlQ2sabFq/i70YMzAGoAJ8BU5j8huPy61HQYolAOUhcc1M43G7H0F6lV9FZVgJqoJCyO+RycSHSzKbZLmJC5KbZEIUyPO6z+SNdftvzDSwk770tz1A=" Apr 05 10:36:00 volumio go-librespot[20319]: time="2024-04-05T10:36:00+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 05 10:36:00 volumio go-librespot[20319]: time="2024-04-05T10:36:00+03:00" level=debug msg="completed keyexchange" Apr 05 10:36:01 volumio go-librespot[20319]: time="2024-04-05T10:36:01+03:00" level=debug msg="completed challenge" Apr 05 10:36:01 volumio go-librespot[20319]: time="2024-04-05T10:36:01+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Apr 05 10:36:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 05 10:36:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 05 10:36:01 volumio volumio[994]: info: Initializing connection to go-librespot Websocket Apr 05 10:36:01 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 05 10:36:04 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 05 10:36:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1613. Apr 05 10:36:04 volumio systemd[1]: Stopped go-librespot Daemon. Apr 05 10:36:04 volumio systemd[1]: Started go-librespot Daemon. Apr 05 10:36:04 volumio go-librespot[20327]: Librespot-go daemon starting... Apr 05 10:36:04 volumio go-librespot[20327]: time="2024-04-05T10:36:04+03:00" level=info msg="generated new device id: a1fcd790e7f6e2e8b5ee20eeb2b9498074ce5f7a" Apr 05 10:36:04 volumio go-librespot[20327]: time="2024-04-05T10:36:04+03:00" level=debug msg="stored credentials found for 31xvf3vpjlld6elhjalvllnvrsb4" Apr 05 10:36:04 volumio go-librespot[20327]: time="2024-04-05T10:36:04+03:00" level=debug msg="obtained new client token: AADBHENJAIaqXwGK3sRXTAVwzUad9mYI/e01QH+Lvv+pc84r8zn14dGG3FUUuDUA3xhObIIpr+rOobiU2v1oznu+emO3PP6ZrhYbs+ZwTAgseiMSFhq015jfCqzed7n9OfIUmvaTZC3OnGNPkazI3tILwI8hr2sHgMxKZXWDguIaCmibTHND70NhsnXawpragOx5OrQQXrE3sGW9+48r71jsuSlZ83zfrCfffhnS3yyJPKcDz6oiqFhaqlp7D1o=" Apr 05 10:36:04 volumio volumio[994]: info: Initializing connection to go-librespot Websocket Apr 05 10:36:04 volumio go-librespot[20327]: time="2024-04-05T10:36:04+03:00" level=debug msg="new websocket client" Apr 05 10:36:04 volumio volumio[994]: info: Connection to go-librespot Websocket established Apr 05 10:36:04 volumio go-librespot[20327]: time="2024-04-05T10:36:04+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 05 10:36:05 volumio go-librespot[20327]: time="2024-04-05T10:36:05+03:00" level=debug msg="completed keyexchange" Apr 05 10:36:05 volumio go-librespot[20327]: time="2024-04-05T10:36:05+03:00" level=debug msg="completed challenge" Apr 05 10:36:05 volumio go-librespot[20327]: time="2024-04-05T10:36:05+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Apr 05 10:36:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 05 10:36:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 05 10:36:05 volumio volumio[994]: info: Connection to go-librespot Websocket closed Apr 05 10:36:07 volumio volumio[994]: info: Getting Spotify volume Apr 05 10:36:07 volumio volumio[994]: (node:994) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 05 10:36:07 volumio volumio[994]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Apr 05 10:36:07 volumio volumio[994]: (node:994) 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: 555) Apr 05 10:36:07 volumio volumio[994]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Apr 05 10:36:07 volumio volumio[994]: info: CoreCommandRouter::volumioGetState Apr 05 10:36:07 volumio volumio[994]: info: CorePlayQueue::getTrack 3 Apr 05 10:36:07 volumio volumio[994]: SPOTIFY: RECEIVED VOLUMIO VOLUME 69 Apr 05 10:36:08 volumio volumio[994]: info: Initializing connection to go-librespot Websocket Apr 05 10:36:08 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 05 10:36:08 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 05 10:36:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1614. Apr 05 10:36:08 volumio systemd[1]: Stopped go-librespot Daemon. Apr 05 10:36:08 volumio systemd[1]: Started go-librespot Daemon. Apr 05 10:36:08 volumio go-librespot[20335]: Librespot-go daemon starting... Apr 05 10:36:08 volumio go-librespot[20335]: time="2024-04-05T10:36:08+03:00" level=info msg="generated new device id: b471d5f2dfb03144456743913242f62745106196" Apr 05 10:36:08 volumio go-librespot[20335]: time="2024-04-05T10:36:08+03:00" level=debug msg="stored credentials found for 31xvf3vpjlld6elhjalvllnvrsb4" Apr 05 10:36:09 volumio go-librespot[20335]: time="2024-04-05T10:36:09+03:00" level=debug msg="obtained new client token: AAAHpj5z6jOcGbAXa/AfZwLfxPcydPxZ/qCygNTst8PBPvsWipiv715PiiipvBkWyvgLfxzKM+83yGZVrT/S1OEIydF5f4gmJ471NNw07CJuopD8T58z/hzxvhwVZ2BOLxhFuijJKV+VZdKuYfQ7nnG7StRoHsNqF+E+D+06X1NOuxjbprocBU27TisxvlVRHEt3apCI3zpR7P3OyvngHbGFI3Q6UwbyVtHer2M4izRdx8RqK8U/3nDfcobO" Apr 05 10:36:09 volumio go-librespot[20335]: time="2024-04-05T10:36:09+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 05 10:36:09 volumio go-librespot[20335]: time="2024-04-05T10:36:09+03:00" level=debug msg="completed keyexchange" Apr 05 10:36:09 volumio go-librespot[20335]: time="2024-04-05T10:36:09+03:00" level=debug msg="completed challenge" Apr 05 10:36:09 volumio go-librespot[20335]: time="2024-04-05T10:36:09+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Apr 05 10:36:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 05 10:36:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 05 10:36:11 volumio volumio[994]: info: Initializing connection to go-librespot Websocket Apr 05 10:36:11 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 05 10:36:13 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 05 10:36:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1615. Apr 05 10:36:13 volumio systemd[1]: Stopped go-librespot Daemon. Apr 05 10:36:13 volumio systemd[1]: Started go-librespot Daemon. Apr 05 10:36:13 volumio go-librespot[20343]: Librespot-go daemon starting... Apr 05 10:36:13 volumio go-librespot[20343]: time="2024-04-05T10:36:13+03:00" level=info msg="generated new device id: 01287d68654d033e37650d68842dfd951eac80fc" Apr 05 10:36:13 volumio go-librespot[20343]: time="2024-04-05T10:36:13+03:00" level=debug msg="stored credentials found for 31xvf3vpjlld6elhjalvllnvrsb4" Apr 05 10:36:13 volumio go-librespot[20343]: time="2024-04-05T10:36:13+03:00" level=debug msg="obtained new client token: AAB2K4de7RJbYoXEXYY9Kwbp3CTghxKwJwlLP39Me9MdCTDBJiJuVxd4Py+D0CpzYQO7UrqJ40cesZRxX7+x6irR6cxeyQ3BDu/4Z2Zkr7XT+s8bMO91EIgN4hnnwZ+lS5tsi+tjVposkWXTce6Mz91hSJAbXsx6XUdR/g4qQBxeezmSjwjfIODco2BQEwND873rEComlcYZuzWyY5Ew/3riBDvhEGDitbb3AfY5XDK+eY4JfMZZYY6RV/ojzuE=" Apr 05 10:36:13 volumio go-librespot[20343]: time="2024-04-05T10:36:13+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 05 10:36:13 volumio go-librespot[20343]: time="2024-04-05T10:36:13+03:00" level=debug msg="completed keyexchange" Apr 05 10:36:14 volumio go-librespot[20343]: time="2024-04-05T10:36:14+03:00" level=debug msg="completed challenge" Apr 05 10:36:14 volumio go-librespot[20343]: time="2024-04-05T10:36:14+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Apr 05 10:36:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 05 10:36:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 05 10:36:14 volumio volumio[994]: info: Initializing connection to go-librespot Websocket Apr 05 10:36:14 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 05 10:36:17 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 05 10:36:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1616. Apr 05 10:36:17 volumio systemd[1]: Stopped go-librespot Daemon. Apr 05 10:36:17 volumio systemd[1]: Started go-librespot Daemon. Apr 05 10:36:17 volumio go-librespot[20352]: Librespot-go daemon starting... Apr 05 10:36:17 volumio go-librespot[20352]: time="2024-04-05T10:36:17+03:00" level=info msg="generated new device id: 7e4ff44c276628ceac253cb0be54cd9adae96202" Apr 05 10:36:17 volumio go-librespot[20352]: time="2024-04-05T10:36:17+03:00" level=debug msg="stored credentials found for 31xvf3vpjlld6elhjalvllnvrsb4" Apr 05 10:36:17 volumio go-librespot[20352]: time="2024-04-05T10:36:17+03:00" level=debug msg="obtained new client token: AAAfXsPUVIYEjvQ2D69N7XfCG0VSKDpvGpzDE9X1i0oWlB/ZW/JyoZv5D2dkz1K8n5rel/DqqjZuilNP9tdf7vO7IjqbzQ9Rx2RIRkjIkUCwRTXiyUBq+XHhqxN3EXTgHtF/O7X9g8EnQPTAwgbhyf9twjWLCGAvt+8Jrul1+kStyN+s+OqV40CChSS1Ne8Zs206JFhClUZt1SMeFO+5MbPIx9TEKhGbbBUrJ9hrZ1G5VCSlw8Fnx2z+bmZlCuk=" Apr 05 10:36:17 volumio volumio[994]: info: Initializing connection to go-librespot Websocket Apr 05 10:36:17 volumio go-librespot[20352]: time="2024-04-05T10:36:17+03:00" level=debug msg="new websocket client" Apr 05 10:36:17 volumio volumio[994]: info: Connection to go-librespot Websocket established Apr 05 10:36:17 volumio go-librespot[20352]: time="2024-04-05T10:36:17+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 05 10:36:17 volumio go-librespot[20352]: time="2024-04-05T10:36:17+03:00" level=debug msg="completed keyexchange" Apr 05 10:36:18 volumio go-librespot[20352]: time="2024-04-05T10:36:18+03:00" level=debug msg="completed challenge" Apr 05 10:36:18 volumio go-librespot[20352]: time="2024-04-05T10:36:18+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Apr 05 10:36:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 05 10:36:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 05 10:36:18 volumio volumio[994]: info: Connection to go-librespot Websocket closed Apr 05 10:36:20 volumio volumio[994]: info: Getting Spotify volume Apr 05 10:36:20 volumio volumio[994]: (node:994) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 05 10:36:20 volumio volumio[994]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Apr 05 10:36:20 volumio volumio[994]: (node:994) 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: 556) Apr 05 10:36:20 volumio volumio[994]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Apr 05 10:36:20 volumio volumio[994]: info: CoreCommandRouter::volumioGetState Apr 05 10:36:20 volumio volumio[994]: info: CorePlayQueue::getTrack 3 Apr 05 10:36:20 volumio volumio[994]: SPOTIFY: RECEIVED VOLUMIO VOLUME 69 Apr 05 10:36:21 volumio volumio[994]: info: Initializing connection to go-librespot Websocket Apr 05 10:36:21 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 05 10:36:21 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 05 10:36:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1617. Apr 05 10:36:21 volumio systemd[1]: Stopped go-librespot Daemon. Apr 05 10:36:21 volumio systemd[1]: Started go-librespot Daemon. Apr 05 10:36:21 volumio go-librespot[20401]: Librespot-go daemon starting... Apr 05 10:36:21 volumio go-librespot[20401]: time="2024-04-05T10:36:21+03:00" level=info msg="generated new device id: 576bc3a3191ad359f9b44d174e97f09895b827ab" Apr 05 10:36:21 volumio go-librespot[20401]: time="2024-04-05T10:36:21+03:00" level=debug msg="stored credentials found for 31xvf3vpjlld6elhjalvllnvrsb4" Apr 05 10:36:21 volumio go-librespot[20401]: time="2024-04-05T10:36:21+03:00" level=debug msg="obtained new client token: AADKN0XlU4EH6D3F3bDDUZ6Xj96u4VkEp9IWrAm6IBHYOULcGy+3yZxhvm5OQlMmtpcgWO1igRv3PbkxSHb8mZYQ7ivOzTkMI43u5LQeV3Md1mAW4vwiLgUYVtlkF70VJ1fpX3U0yXrjAb2vY1kB7ZuHTIwXRuGhpMy5scCc1ry9vZ5s0seRXsFm9aRi2H9oRLMGjP64flR8+l++uYhCMhLAt49Rc+/ek+UjHcKrqeNNZQ/Tp0k5IlB359POzf0=" Apr 05 10:36:21 volumio go-librespot[20401]: time="2024-04-05T10:36:21+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 05 10:36:22 volumio go-librespot[20401]: time="2024-04-05T10:36:22+03:00" level=debug msg="completed keyexchange" Apr 05 10:36:22 volumio go-librespot[20401]: time="2024-04-05T10:36:22+03:00" level=debug msg="completed challenge" Apr 05 10:36:22 volumio go-librespot[20401]: time="2024-04-05T10:36:22+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Apr 05 10:36:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 05 10:36:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 05 10:36:24 volumio volumio[994]: info: Initializing connection to go-librespot Websocket Apr 05 10:36:24 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 05 10:36:25 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 05 10:36:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1618. Apr 05 10:36:25 volumio systemd[1]: Stopped go-librespot Daemon. Apr 05 10:36:25 volumio systemd[1]: Started go-librespot Daemon. Apr 05 10:36:25 volumio go-librespot[20409]: Librespot-go daemon starting... Apr 05 10:36:25 volumio go-librespot[20409]: time="2024-04-05T10:36:25+03:00" level=info msg="generated new device id: fbc28050ee7004503f841fc83302742d513a0dfe" Apr 05 10:36:25 volumio go-librespot[20409]: time="2024-04-05T10:36:25+03:00" level=debug msg="stored credentials found for 31xvf3vpjlld6elhjalvllnvrsb4" Apr 05 10:36:26 volumio go-librespot[20409]: time="2024-04-05T10:36:26+03:00" level=debug msg="obtained new client token: AAAmq/CCv8GAM5BrZuP1vzF6ZCqMXInqb7cHYw/cM6fHWA0/+aFXmXBwUKdwDywE8CofJEi7RNA5tOAK8zQqKQjmMOSnR/U2Ac/YZGhVmcDTm+a6hLgy2XLN/SA5qNzU59B0CT1OVJMG4BW83f1PMMe1R43/vRzAyIbJ5ImDDMvRmrrBsycR++2vfuW5jGb0C0q9MlX9rF/CCUv3uhqL4TM23UKOainu4wbqbJP2yGHlqQACtJJsZOxYkkpf" Apr 05 10:36:26 volumio go-librespot[20409]: time="2024-04-05T10:36:26+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Apr 05 10:36:26 volumio go-librespot[20409]: time="2024-04-05T10:36:26+03:00" level=debug msg="completed keyexchange" Apr 05 10:36:26 volumio go-librespot[20409]: time="2024-04-05T10:36:26+03:00" level=debug msg="completed challenge" Apr 05 10:36:26 volumio go-librespot[20409]: time="2024-04-05T10:36:26+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Apr 05 10:36:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 05 10:36:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 05 10:36:27 volumio volumio[994]: info: Initializing connection to go-librespot Websocket Apr 05 10:36:27 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 05 10:36:30 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 05 10:36:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1619. Apr 05 10:36:30 volumio systemd[1]: Stopped go-librespot Daemon. Apr 05 10:36:30 volumio systemd[1]: Started go-librespot Daemon. Apr 05 10:36:30 volumio go-librespot[20417]: Librespot-go daemon starting... Apr 05 10:36:30 volumio go-librespot[20417]: time="2024-04-05T10:36:30+03:00" level=info msg="generated new device id: a7a717f161113464d2ea19235f763eda7ed0c24d" Apr 05 10:36:30 volumio go-librespot[20417]: time="2024-04-05T10:36:30+03:00" level=debug msg="stored credentials found for 31xvf3vpjlld6elhjalvllnvrsb4" Apr 05 10:36:30 volumio go-librespot[20417]: time="2024-04-05T10:36:30+03:00" level=debug msg="obtained new client token: AABV1piEou+9GkZ5+TVwOIrFE702dissXkuN5i0OBGZAqfcqiFT14PW52qbwJngDAi/ai9RMfmKVswC6BGomZGYo2wGEqfyExBSqI370JlAu3+uBPFYiH6ARfFrCNe9wEqUHJVAX/DCRCzIsDhemP4q+++E2fVpNxafY5UFZLTb6Pydz9awTaIrQnArI0twkITHr04MQqtHAYndeVIxoVQu2GpvuX9nOSIIBeVvFreFuu5RLwvIGMTUh+Hv3BD4=" Apr 05 10:36:30 volumio volumio[994]: info: Initializing connection to go-librespot Websocket Apr 05 10:36:30 volumio go-librespot[20417]: time="2024-04-05T10:36:30+03:00" level=debug msg="new websocket client" Apr 05 10:36:30 volumio volumio[994]: info: Connection to go-librespot Websocket established Apr 05 10:36:30 volumio go-librespot[20417]: time="2024-04-05T10:36:30+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 05 10:36:30 volumio go-librespot[20417]: time="2024-04-05T10:36:30+03:00" level=debug msg="completed keyexchange" Apr 05 10:36:31 volumio go-librespot[20417]: time="2024-04-05T10:36:31+03:00" level=debug msg="completed challenge" Apr 05 10:36:31 volumio go-librespot[20417]: time="2024-04-05T10:36:31+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Apr 05 10:36:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 05 10:36:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 05 10:36:31 volumio volumio[994]: info: Connection to go-librespot Websocket closed Apr 05 10:36:33 volumio volumio[994]: info: Getting Spotify volume Apr 05 10:36:33 volumio volumio[994]: (node:994) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 05 10:36:33 volumio volumio[994]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Apr 05 10:36:33 volumio volumio[994]: (node:994) 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: 557) Apr 05 10:36:33 volumio volumio[994]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Apr 05 10:36:33 volumio volumio[994]: info: CoreCommandRouter::volumioGetState Apr 05 10:36:33 volumio volumio[994]: info: CorePlayQueue::getTrack 3 Apr 05 10:36:33 volumio volumio[994]: SPOTIFY: RECEIVED VOLUMIO VOLUME 69 Apr 05 10:36:34 volumio volumio[994]: info: Initializing connection to go-librespot Websocket Apr 05 10:36:34 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 05 10:36:34 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 05 10:36:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1620. Apr 05 10:36:34 volumio systemd[1]: Stopped go-librespot Daemon. Apr 05 10:36:34 volumio systemd[1]: Started go-librespot Daemon. Apr 05 10:36:34 volumio go-librespot[20425]: Librespot-go daemon starting... Apr 05 10:36:34 volumio go-librespot[20425]: time="2024-04-05T10:36:34+03:00" level=info msg="generated new device id: dbfd0ef8cc2b7f3de6f57618b68812aa3a48668b" Apr 05 10:36:34 volumio go-librespot[20425]: time="2024-04-05T10:36:34+03:00" level=debug msg="stored credentials found for 31xvf3vpjlld6elhjalvllnvrsb4" Apr 05 10:36:34 volumio go-librespot[20425]: time="2024-04-05T10:36:34+03:00" level=debug msg="obtained new client token: AAA+tR22FPZsbnuNEM9uEJEq1iZ5L3iwMBHhOvQd58bsamrTwc9MHq3YZFOc1Rgb8Y2RVPLze/ceGPC1AcaXxZNXut8KlnBpUX4a1POnB3pV8ZvXm4JO2brhTkyMYoHU7mu2fiVMCnp3IOO4ruOU4IF7iIA9DBBojTmjJsydRebCUBUagjaXhcJ/Ws11strrV8aeYv9Ef574fE8FBc8zLZ/JiBRd80gdsBa8kNTHud9FS4KQao18gQhrddhFvGk=" Apr 05 10:36:34 volumio go-librespot[20425]: time="2024-04-05T10:36:34+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 05 10:36:34 volumio go-librespot[20425]: time="2024-04-05T10:36:34+03:00" level=debug msg="completed keyexchange" Apr 05 10:36:35 volumio go-librespot[20425]: time="2024-04-05T10:36:35+03:00" level=debug msg="completed challenge" Apr 05 10:36:35 volumio go-librespot[20425]: time="2024-04-05T10:36:35+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Apr 05 10:36:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 05 10:36:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 05 10:36:37 volumio volumio[994]: info: Initializing connection to go-librespot Websocket Apr 05 10:36:37 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 05 10:36:38 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 05 10:36:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1621. Apr 05 10:36:38 volumio systemd[1]: Stopped go-librespot Daemon. Apr 05 10:36:38 volumio systemd[1]: Started go-librespot Daemon. Apr 05 10:36:38 volumio go-librespot[20434]: Librespot-go daemon starting... Apr 05 10:36:38 volumio go-librespot[20434]: time="2024-04-05T10:36:38+03:00" level=info msg="generated new device id: 905d0341697b5f57da66a7d2e1a294ca80430e38" Apr 05 10:36:38 volumio go-librespot[20434]: time="2024-04-05T10:36:38+03:00" level=debug msg="stored credentials found for 31xvf3vpjlld6elhjalvllnvrsb4" Apr 05 10:36:38 volumio volumio[994]: info: CoreCommandRouter::volumioNext Apr 05 10:36:38 volumio volumio[994]: info: CoreStateMachine::next Apr 05 10:36:38 volumio volumio[994]: info: CoreStateMachine::stop Apr 05 10:36:38 volumio volumio[994]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 05 10:36:38 volumio volumio[994]: info: CoreStateMachine::stPlaybackTimer Apr 05 10:36:38 volumio volumio[994]: info: CoreStateMachine::updateTrackBlock Apr 05 10:36:38 volumio volumio[994]: info: CorePlayQueue::getTrackBlock Apr 05 10:36:38 volumio volumio[994]: info: CoreStateMachine::pushState Apr 05 10:36:38 volumio volumio[994]: info: CorePlayQueue::getTrack 3 Apr 05 10:36:38 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 05 10:36:38 volumio volumio[994]: info: CoreCommandRouter::volumioPushState Apr 05 10:36:38 volumio volumio[994]: info: CoreStateMachine::serviceStop Apr 05 10:36:38 volumio volumio[994]: info: CorePlayQueue::getTrack 3 Apr 05 10:36:38 volumio volumio[994]: info: CoreCommandRouter::serviceStop Apr 05 10:36:38 volumio volumio[994]: info: ControllerMpd::stop Apr 05 10:36:38 volumio volumio[994]: verbose: ControllerMpd::sendMpdCommand stop Apr 05 10:36:38 volumio volumio[994]: SPOTIFY: RECEIVED VOLUMIO VOLUME 69 Apr 05 10:36:38 volumio volumio[994]: info: Apr 05 10:36:38 volumio volumio[994]: ---------------------------- MPD announces state update: player Apr 05 10:36:38 volumio volumio[994]: info: sendMpdCommand stop took 6 milliseconds Apr 05 10:36:38 volumio volumio[994]: info: ControllerMpd::getState Apr 05 10:36:38 volumio volumio[994]: verbose: ControllerMpd::sendMpdCommand status Apr 05 10:36:38 volumio volumio[994]: info: CoreStateMachine::play index undefined Apr 05 10:36:38 volumio volumio[994]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 05 10:36:38 volumio volumio[994]: info: CorePlayQueue::getTrack 4 Apr 05 10:36:38 volumio volumio[994]: info: CoreStateMachine::startPlaybackTimer Apr 05 10:36:38 volumio volumio[994]: info: CorePlayQueue::getTrack 4 Apr 05 10:36:38 volumio volumio[994]: verbose: ControllerMpd::clearAddPlayTracks INTERNAL/Yello - Toy 2016(LP)/05 - Cold Flame.flac Apr 05 10:36:38 volumio volumio[994]: verbose: ControllerMpd::sendMpdCommand stop Apr 05 10:36:38 volumio volumio[994]: info: CoreStateMachine::updateTrackBlock Apr 05 10:36:38 volumio volumio[994]: info: CorePlayQueue::getTrackBlock Apr 05 10:36:38 volumio volumio[994]: info: sendMpdCommand status took 8 milliseconds Apr 05 10:36:38 volumio volumio[994]: info: sendMpdCommand stop took 2 milliseconds Apr 05 10:36:38 volumio volumio[994]: verbose: ControllerMpd::parseState Apr 05 10:36:38 volumio volumio[994]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 05 10:36:38 volumio volumio[994]: verbose: ControllerMpd::sendMpdCommand clear Apr 05 10:36:38 volumio volumio[994]: info: Apr 05 10:36:38 volumio volumio[994]: ---------------------------- MPD announces system playlist update Apr 05 10:36:38 volumio volumio[994]: info: Ignoring MPD Status Update Apr 05 10:36:38 volumio volumio[994]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 05 10:36:38 volumio volumio[994]: info: sendMpdCommand clear took 1 milliseconds Apr 05 10:36:38 volumio volumio[994]: verbose: ControllerMpd::parseTrackInfo Apr 05 10:36:38 volumio volumio[994]: verbose: ControllerMpd::sendMpdCommand add "INTERNAL/Yello - Toy 2016(LP)/05 - Cold Flame.flac" Apr 05 10:36:38 volumio volumio[994]: info: ControllerMpd::pushState Apr 05 10:36:38 volumio volumio[994]: info: CoreCommandRouter::servicePushState Apr 05 10:36:38 volumio volumio[994]: info: CoreStateMachine::pushState Apr 05 10:36:38 volumio volumio[994]: info: CorePlayQueue::getTrack 4 Apr 05 10:36:38 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 05 10:36:38 volumio volumio[994]: info: CoreCommandRouter::volumioPushState Apr 05 10:36:38 volumio volumio[994]: info: CorePlayQueue::getTrack 4 Apr 05 10:36:38 volumio volumio[994]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"04 - Electrified II.flac","artist":"Yello","album":"Toy","uri":"INTERNAL/Yello - Toy 2016(LP)/04 - Electrified II.flac","trackType":"flac"} Apr 05 10:36:38 volumio volumio[994]: verbose: CURRENT POSITION 4 Apr 05 10:36:38 volumio volumio[994]: info: CoreStateMachine::syncState stateService stop Apr 05 10:36:38 volumio volumio[994]: info: CoreStateMachine::syncState currentStatus stop Apr 05 10:36:38 volumio volumio[994]: info: CoreStateMachine::pushState Apr 05 10:36:38 volumio volumio[994]: info: CorePlayQueue::getTrack 4 Apr 05 10:36:38 volumio volumio[994]: info: CoreCommandRouter::volumioPushState Apr 05 10:36:38 volumio volumio[994]: info: No code Apr 05 10:36:38 volumio volumio[994]: info: CoreStateMachine::pushState Apr 05 10:36:38 volumio volumio[994]: info: CorePlayQueue::getTrack 4 Apr 05 10:36:38 volumio volumio[994]: info: CoreCommandRouter::volumioPushState Apr 05 10:36:38 volumio volumio[994]: info: ------------------------------ 38ms Apr 05 10:36:38 volumio volumio[994]: error: updateQueue error: null Apr 05 10:36:38 volumio volumio[994]: info: Apr 05 10:36:38 volumio volumio[994]: ---------------------------- MPD announces system playlist update Apr 05 10:36:38 volumio volumio[994]: info: Ignoring MPD Status Update Apr 05 10:36:38 volumio volumio[994]: info: ------------------------------ 29ms Apr 05 10:36:38 volumio volumio[994]: info: sendMpdCommand add "INTERNAL/Yello - Toy 2016(LP)/05 - Cold Flame.flac" took 28 milliseconds Apr 05 10:36:38 volumio volumio[994]: verbose: ControllerMpd::sendMpdCommand play Apr 05 10:36:38 volumio volumio[994]: SPOTIFY: RECEIVED VOLUMIO VOLUME 69 Apr 05 10:36:38 volumio volumio[994]: info: Apr 05 10:36:38 volumio volumio[994]: ---------------------------- MPD announces state update: player Apr 05 10:36:38 volumio volumio[994]: info: ------------------------------ 16ms Apr 05 10:36:38 volumio volumio[994]: info: sendMpdCommand play took 15 milliseconds Apr 05 10:36:38 volumio volumio[994]: info: ControllerMpd::getState Apr 05 10:36:38 volumio volumio[994]: verbose: ControllerMpd::sendMpdCommand status Apr 05 10:36:38 volumio volumio[994]: info: Apr 05 10:36:38 volumio volumio[994]: ---------------------------- MPD announces state update: player Apr 05 10:36:38 volumio volumio[994]: info: sendMpdCommand status took 9 milliseconds Apr 05 10:36:38 volumio volumio[994]: info: ControllerMpd::getState Apr 05 10:36:38 volumio volumio[994]: verbose: ControllerMpd::sendMpdCommand status Apr 05 10:36:38 volumio volumio[994]: verbose: ControllerMpd::parseState Apr 05 10:36:38 volumio volumio[994]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 05 10:36:38 volumio volumio[994]: info: sendMpdCommand status took 3 milliseconds Apr 05 10:36:38 volumio volumio[994]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 05 10:36:38 volumio volumio[994]: verbose: ControllerMpd::parseState Apr 05 10:36:38 volumio volumio[994]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 05 10:36:38 volumio volumio[994]: verbose: ControllerMpd::parseTrackInfo Apr 05 10:36:38 volumio volumio[994]: info: ControllerMpd::pushState Apr 05 10:36:38 volumio volumio[994]: info: CoreCommandRouter::servicePushState Apr 05 10:36:38 volumio volumio[994]: info: CorePlayQueue::getTrack 4 Apr 05 10:36:38 volumio volumio[994]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":243,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"05 - Cold Flame.flac","artist":"Yello","album":"Toy","uri":"INTERNAL/Yello - Toy 2016(LP)/05 - Cold Flame.flac","trackType":"flac"} Apr 05 10:36:38 volumio volumio[994]: verbose: CURRENT POSITION 4 Apr 05 10:36:38 volumio volumio[994]: info: CoreStateMachine::syncState stateService play Apr 05 10:36:38 volumio volumio[994]: info: CoreStateMachine::syncState currentStatus stop Apr 05 10:36:38 volumio volumio[994]: info: ------------------------------ 15ms Apr 05 10:36:38 volumio volumio[994]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 05 10:36:38 volumio volumio[994]: verbose: ControllerMpd::parseTrackInfo Apr 05 10:36:38 volumio volumio[994]: info: ControllerMpd::pushState Apr 05 10:36:38 volumio volumio[994]: info: CoreCommandRouter::servicePushState Apr 05 10:36:38 volumio volumio[994]: info: CorePlayQueue::getTrack 4 Apr 05 10:36:38 volumio volumio[994]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":243,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"05 - Cold Flame.flac","artist":"Yello","album":"Toy","uri":"INTERNAL/Yello - Toy 2016(LP)/05 - Cold Flame.flac","trackType":"flac"} Apr 05 10:36:38 volumio volumio[994]: verbose: CURRENT POSITION 4 Apr 05 10:36:38 volumio volumio[994]: info: CoreStateMachine::syncState stateService play Apr 05 10:36:38 volumio volumio[994]: info: CoreStateMachine::syncState currentStatus play Apr 05 10:36:38 volumio volumio[994]: info: Received an update from plugin. extracting info from payload Apr 05 10:36:38 volumio volumio[994]: info: CoreStateMachine::pushState Apr 05 10:36:38 volumio volumio[994]: info: CorePlayQueue::getTrack 4 Apr 05 10:36:38 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 05 10:36:38 volumio volumio[994]: info: CoreCommandRouter::volumioPushState Apr 05 10:36:38 volumio volumio[994]: info: CoreStateMachine::pushState Apr 05 10:36:38 volumio volumio[994]: info: CorePlayQueue::getTrack 4 Apr 05 10:36:38 volumio volumio[994]: info: CoreCommandRouter::volumioPushState Apr 05 10:36:38 volumio volumio[994]: info: ------------------------------ 18ms Apr 05 10:36:38 volumio volumio[994]: SPOTIFY: RECEIVED VOLUMIO VOLUME 69 Apr 05 10:36:38 volumio volumio[994]: SPOTIFY: RECEIVED VOLUMIO VOLUME 69 Apr 05 10:36:40 volumio volumio[994]: info: Initializing connection to go-librespot Websocket Apr 05 10:36:40 volumio go-librespot[20434]: time="2024-04-05T10:36:40+03:00" level=debug msg="new websocket client" Apr 05 10:36:40 volumio volumio[994]: info: Connection to go-librespot Websocket established Apr 05 10:36:41 volumio go-librespot[20434]: time="2024-04-05T10:36:41+03:00" level=debug msg="obtained new client token: AACogfDQdJ42VF4WZAvr0TUqXeUs2fmLV0iPjeMPbD89UgCzb0ZUOIgRIG4aSk1Ut0kCJsikjOOrIQ+HQo/l6GfLh9rZD0axcDELvwg5+a2DWbhA7BeMEyJnPIUXKB3EBo/350BKJx+3kZT92g+EF3GmVtzfV/v+Btri+nFi2tJimQWJTzlCzHo77HA4qhHTkLhENbAkcdGFEkccqSNashlZUHxFnNoDM7SG6TnYHP3vVvKsQzTaxBch08MfBpU=" Apr 05 10:36:42 volumio go-librespot[20434]: time="2024-04-05T10:36:42+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 05 10:36:42 volumio go-librespot[20434]: time="2024-04-05T10:36:42+03:00" level=debug msg="completed keyexchange" Apr 05 10:36:42 volumio go-librespot[20434]: time="2024-04-05T10:36:42+03:00" level=debug msg="completed challenge" Apr 05 10:36:42 volumio go-librespot[20434]: time="2024-04-05T10:36:42+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Apr 05 10:36:42 volumio volumio[994]: info: Connection to go-librespot Websocket closed Apr 05 10:36:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 05 10:36:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 05 10:36:43 volumio volumio[994]: info: Getting Spotify volume Apr 05 10:36:43 volumio volumio[994]: (node:994) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 05 10:36:43 volumio volumio[994]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Apr 05 10:36:43 volumio volumio[994]: (node:994) 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: 558) Apr 05 10:36:43 volumio volumio[994]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Apr 05 10:36:43 volumio volumio[994]: info: CoreCommandRouter::volumioGetState Apr 05 10:36:43 volumio volumio[994]: info: CorePlayQueue::getTrack 4 Apr 05 10:36:43 volumio volumio[994]: SPOTIFY: RECEIVED VOLUMIO VOLUME 69 Apr 05 10:36:44 volumio volumio[994]: info: CoreCommandRouter::volumioSeek Apr 05 10:36:44 volumio volumio[994]: info: CoreStateMachine::seek Apr 05 10:36:44 volumio volumio[994]: info: CorePlayQueue::getTrack 4 Apr 05 10:36:44 volumio volumio[994]: info: TRACKBLOCK {"uri":"mnt/INTERNAL/Yello - Toy 2016(LP)/05 - Cold Flame.flac","service":"mpd","name":"05 - Cold Flame.flac","artist":"Yello","album":"Toy","type":"track","tracknumber":0,"albumart":"/albumart?cacheid=315&web=Yello/Toy/extralarge&path=%2FINTERNAL%2FYello%20-%20Toy%20%202016(LP)&metadata=false","duration":243,"trackType":"flac","samplerate":"192 kHz","bitdepth":"24 bit","channels":2} Apr 05 10:36:44 volumio volumio[994]: info: CoreStateMachine::startPlaybackTimer Apr 05 10:36:44 volumio volumio[994]: info: CorePlayQueue::getTrack 4 Apr 05 10:36:44 volumio volumio[994]: info: ControllerMpd::seek Apr 05 10:36:44 volumio volumio[994]: info: CoreStateMachine::pushState Apr 05 10:36:44 volumio volumio[994]: info: CorePlayQueue::getTrack 4 Apr 05 10:36:44 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 05 10:36:44 volumio volumio[994]: info: CoreCommandRouter::volumioPushState Apr 05 10:36:44 volumio volumio[994]: SPOTIFY: RECEIVED VOLUMIO VOLUME 69 Apr 05 10:36:44 volumio volumio[994]: error: null Apr 05 10:36:44 volumio volumio[994]: info: Apr 05 10:36:44 volumio volumio[994]: ---------------------------- MPD announces state update: player Apr 05 10:36:44 volumio volumio[994]: info: ControllerMpd::getState Apr 05 10:36:44 volumio volumio[994]: verbose: ControllerMpd::sendMpdCommand status Apr 05 10:36:44 volumio volumio[994]: info: sendMpdCommand status took 1 milliseconds Apr 05 10:36:44 volumio volumio[994]: verbose: ControllerMpd::parseState Apr 05 10:36:44 volumio volumio[994]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 05 10:36:44 volumio volumio[994]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 05 10:36:44 volumio volumio[994]: verbose: ControllerMpd::parseTrackInfo Apr 05 10:36:44 volumio volumio[994]: info: ControllerMpd::pushState Apr 05 10:36:44 volumio volumio[994]: info: CoreCommandRouter::servicePushState Apr 05 10:36:44 volumio volumio[994]: info: CorePlayQueue::getTrack 4 Apr 05 10:36:44 volumio volumio[994]: verbose: STATE SERVICE {"status":"play","position":0,"seek":26000,"duration":243,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5418 Kbps","isStreaming":false,"title":"05 - Cold Flame.flac","artist":"Yello","album":"Toy","uri":"INTERNAL/Yello - Toy 2016(LP)/05 - Cold Flame.flac","trackType":"flac"} Apr 05 10:36:44 volumio volumio[994]: verbose: CURRENT POSITION 4 Apr 05 10:36:44 volumio volumio[994]: info: CoreStateMachine::syncState stateService play Apr 05 10:36:44 volumio volumio[994]: info: CoreStateMachine::syncState currentStatus play Apr 05 10:36:44 volumio volumio[994]: info: Received an update from plugin. extracting info from payload Apr 05 10:36:44 volumio volumio[994]: info: CoreStateMachine::pushState Apr 05 10:36:44 volumio volumio[994]: info: CorePlayQueue::getTrack 4 Apr 05 10:36:44 volumio volumio[994]: info: CoreCommandRouter::volumioPushState Apr 05 10:36:44 volumio volumio[994]: info: CoreStateMachine::pushState Apr 05 10:36:44 volumio volumio[994]: info: CorePlayQueue::getTrack 4 Apr 05 10:36:44 volumio volumio[994]: info: CoreCommandRouter::volumioPushState Apr 05 10:36:44 volumio volumio[994]: info: ------------------------------ 10ms Apr 05 10:36:44 volumio volumio[994]: SPOTIFY: RECEIVED VOLUMIO VOLUME 69 Apr 05 10:36:44 volumio volumio[994]: SPOTIFY: RECEIVED VOLUMIO VOLUME 69 Apr 05 10:36:45 volumio volumio[994]: info: Initializing connection to go-librespot Websocket Apr 05 10:36:45 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 05 10:36:45 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 05 10:36:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1622. Apr 05 10:36:45 volumio systemd[1]: Stopped go-librespot Daemon. Apr 05 10:36:45 volumio systemd[1]: Started go-librespot Daemon. Apr 05 10:36:45 volumio go-librespot[20442]: Librespot-go daemon starting... Apr 05 10:36:45 volumio go-librespot[20442]: time="2024-04-05T10:36:45+03:00" level=info msg="generated new device id: 44e09e8968bfc5fc0c27a7c1d7b1b0e8e10d823d" Apr 05 10:36:45 volumio go-librespot[20442]: time="2024-04-05T10:36:45+03:00" level=debug msg="stored credentials found for 31xvf3vpjlld6elhjalvllnvrsb4" Apr 05 10:36:46 volumio go-librespot[20442]: time="2024-04-05T10:36:46+03:00" level=debug msg="obtained new client token: AADqbqYVzE3GpNiZInE7yiflp77LynapGaXfTOmzMkWNEgB1M52PPTPCDWMnEy0apD3Nk+7CFRDV5j5B8HqZC7Wx13O27vhJuDcupJMQiNrL0H1gskQQJEsibEsnjTQoslN8jugee3xUG7wObCD5JBe5l/W1MW05LyGMxSzNVykY9TRHH+Nf1679FjbN3tE9i6V2xw1h2ttuQpyOspqKG+tNkblLPU7NLJXH5NZNaUCp4oRTqiLL3qOwsU5/" Apr 05 10:36:46 volumio go-librespot[20442]: time="2024-04-05T10:36:46+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 05 10:36:46 volumio go-librespot[20442]: time="2024-04-05T10:36:46+03:00" level=debug msg="completed keyexchange" Apr 05 10:36:46 volumio go-librespot[20442]: time="2024-04-05T10:36:46+03:00" level=debug msg="completed challenge" Apr 05 10:36:46 volumio go-librespot[20442]: time="2024-04-05T10:36:46+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Apr 05 10:36:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 05 10:36:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 05 10:36:47 volumio volumio[994]: info: Preload queue cleared Apr 05 10:36:47 volumio volumio[994]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 05 10:36:47 volumio volumio[994]: info: CoreStateMachine::ClearQueue Apr 05 10:36:47 volumio volumio[994]: info: CoreStateMachine::stop Apr 05 10:36:47 volumio volumio[994]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 05 10:36:47 volumio volumio[994]: info: CoreStateMachine::stPlaybackTimer Apr 05 10:36:47 volumio volumio[994]: info: CoreStateMachine::updateTrackBlock Apr 05 10:36:47 volumio volumio[994]: info: CorePlayQueue::getTrackBlock Apr 05 10:36:47 volumio volumio[994]: info: CoreStateMachine::pushState Apr 05 10:36:47 volumio volumio[994]: info: CorePlayQueue::getTrack 4 Apr 05 10:36:47 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 05 10:36:47 volumio volumio[994]: info: CoreCommandRouter::volumioPushState Apr 05 10:36:47 volumio volumio[994]: info: CoreStateMachine::serviceStop Apr 05 10:36:47 volumio volumio[994]: info: CorePlayQueue::getTrack 4 Apr 05 10:36:47 volumio volumio[994]: info: CoreCommandRouter::serviceStop Apr 05 10:36:47 volumio volumio[994]: info: ControllerMpd::stop Apr 05 10:36:47 volumio volumio[994]: verbose: ControllerMpd::sendMpdCommand stop Apr 05 10:36:47 volumio volumio[994]: info: CorePlayQueue::clearPlayQueue Apr 05 10:36:47 volumio volumio[994]: info: CorePlayQueue::saveQueue Apr 05 10:36:47 volumio volumio[994]: info: CoreCommandRouter::volumioPushQueue Apr 05 10:36:47 volumio volumio[994]: info: CoreStateMachine::addQueueItems Apr 05 10:36:47 volumio volumio[994]: info: CorePlayQueue::addQueueItems Apr 05 10:36:47 volumio volumio[994]: info: Preload queue cleared Apr 05 10:36:47 volumio volumio[994]: info: Adding Item to queue: music-library/INTERNAL/Rammstein - Zeit - 2022 (VinylRip DSD128, EU Universal Music Group) Apr 05 10:36:47 volumio volumio[994]: info: Exploding uri music-library/INTERNAL/Rammstein - Zeit - 2022 (VinylRip DSD128, EU Universal Music Group) in service mpd Apr 05 10:36:47 volumio volumio[994]: SPOTIFY: RECEIVED VOLUMIO VOLUME 69 Apr 05 10:36:47 volumio volumio[994]: info: Apr 05 10:36:47 volumio volumio[994]: ---------------------------- MPD announces state update: player Apr 05 10:36:47 volumio volumio[994]: info: ALBUMART /albumart?cacheid=315&web=Rammstein/Zeit/extralarge&path=%2Fmnt%2FINTERNAL%2FRammstein%20-%20Zeit%20-%202022%20(VinylRip%20DSD128%2C%20EU%20Universal%20Music%20Group)%2F01%20-%20Armee%20Der%20Tristen.dsf&metadata=false Apr 05 10:36:47 volumio volumio[994]: info: URI /mnt/INTERNAL/Rammstein - Zeit - 2022 (VinylRip DSD128, EU Universal Music Group)/01 - Armee Der Tristen.dsf Apr 05 10:36:47 volumio volumio[994]: info: ALBUMART /albumart?cacheid=315&web=Rammstein/Zeit/extralarge&path=%2Fmnt%2FINTERNAL%2FRammstein%20-%20Zeit%20-%202022%20(VinylRip%20DSD128%2C%20EU%20Universal%20Music%20Group)%2F02%20-%20Zeit.dsf&metadata=false Apr 05 10:36:47 volumio volumio[994]: info: URI /mnt/INTERNAL/Rammstein - Zeit - 2022 (VinylRip DSD128, EU Universal Music Group)/02 - Zeit.dsf Apr 05 10:36:47 volumio volumio[994]: info: ALBUMART /albumart?cacheid=315&web=Rammstein/Zeit/extralarge&path=%2Fmnt%2FINTERNAL%2FRammstein%20-%20Zeit%20-%202022%20(VinylRip%20DSD128%2C%20EU%20Universal%20Music%20Group)%2F03%20-%20Schwarz.dsf&metadata=false Apr 05 10:36:47 volumio volumio[994]: info: URI /mnt/INTERNAL/Rammstein - Zeit - 2022 (VinylRip DSD128, EU Universal Music Group)/03 - Schwarz.dsf Apr 05 10:36:47 volumio volumio[994]: info: ALBUMART /albumart?cacheid=315&web=Rammstein/Zeit/extralarge&path=%2Fmnt%2FINTERNAL%2FRammstein%20-%20Zeit%20-%202022%20(VinylRip%20DSD128%2C%20EU%20Universal%20Music%20Group)%2F04%20-%20Giftig.dsf&metadata=false Apr 05 10:36:47 volumio volumio[994]: info: URI /mnt/INTERNAL/Rammstein - Zeit - 2022 (VinylRip DSD128, EU Universal Music Group)/04 - Giftig.dsf Apr 05 10:36:47 volumio volumio[994]: info: ALBUMART /albumart?cacheid=315&web=Rammstein/Zeit/extralarge&path=%2Fmnt%2FINTERNAL%2FRammstein%20-%20Zeit%20-%202022%20(VinylRip%20DSD128%2C%20EU%20Universal%20Music%20Group)%2F05%20-%20Zick%20Zack.dsf&metadata=false Apr 05 10:36:47 volumio volumio[994]: info: URI /mnt/INTERNAL/Rammstein - Zeit - 2022 (VinylRip DSD128, EU Universal Music Group)/05 - Zick Zack.dsf Apr 05 10:36:47 volumio volumio[994]: info: ALBUMART /albumart?cacheid=315&web=Rammstein/Zeit/extralarge&path=%2Fmnt%2FINTERNAL%2FRammstein%20-%20Zeit%20-%202022%20(VinylRip%20DSD128%2C%20EU%20Universal%20Music%20Group)%2F06%20-%20OK.dsf&metadata=false Apr 05 10:36:47 volumio volumio[994]: info: URI /mnt/INTERNAL/Rammstein - Zeit - 2022 (VinylRip DSD128, EU Universal Music Group)/06 - OK.dsf Apr 05 10:36:47 volumio volumio[994]: info: ALBUMART /albumart?cacheid=315&web=Rammstein/Zeit/extralarge&path=%2Fmnt%2FINTERNAL%2FRammstein%20-%20Zeit%20-%202022%20(VinylRip%20DSD128%2C%20EU%20Universal%20Music%20Group)%2F07%20-%20Meine%20Tr%C3%A4nen.dsf&metadata=false Apr 05 10:36:47 volumio volumio[994]: info: URI /mnt/INTERNAL/Rammstein - Zeit - 2022 (VinylRip DSD128, EU Universal Music Group)/07 - Meine Tränen.dsf Apr 05 10:36:47 volumio volumio[994]: info: ALBUMART /albumart?cacheid=315&web=Rammstein/Zeit/extralarge&path=%2Fmnt%2FINTERNAL%2FRammstein%20-%20Zeit%20-%202022%20(VinylRip%20DSD128%2C%20EU%20Universal%20Music%20Group)%2F08%20-%20Angst.dsf&metadata=false Apr 05 10:36:47 volumio volumio[994]: info: URI /mnt/INTERNAL/Rammstein - Zeit - 2022 (VinylRip DSD128, EU Universal Music Group)/08 - Angst.dsf Apr 05 10:36:47 volumio volumio[994]: info: ALBUMART /albumart?cacheid=315&web=Rammstein/Zeit/extralarge&path=%2Fmnt%2FINTERNAL%2FRammstein%20-%20Zeit%20-%202022%20(VinylRip%20DSD128%2C%20EU%20Universal%20Music%20Group)%2F09%20-%20Dicke%20Titten.dsf&metadata=false Apr 05 10:36:47 volumio volumio[994]: info: URI /mnt/INTERNAL/Rammstein - Zeit - 2022 (VinylRip DSD128, EU Universal Music Group)/09 - Dicke Titten.dsf Apr 05 10:36:47 volumio volumio[994]: info: ALBUMART /albumart?cacheid=315&web=Rammstein/Zeit/extralarge&path=%2Fmnt%2FINTERNAL%2FRammstein%20-%20Zeit%20-%202022%20(VinylRip%20DSD128%2C%20EU%20Universal%20Music%20Group)%2F10%20-%20L%C3%BCgen.dsf&metadata=false Apr 05 10:36:47 volumio volumio[994]: info: URI /mnt/INTERNAL/Rammstein - Zeit - 2022 (VinylRip DSD128, EU Universal Music Group)/10 - Lügen.dsf Apr 05 10:36:47 volumio volumio[994]: info: ALBUMART /albumart?cacheid=315&web=Rammstein/Zeit/extralarge&path=%2Fmnt%2FINTERNAL%2FRammstein%20-%20Zeit%20-%202022%20(VinylRip%20DSD128%2C%20EU%20Universal%20Music%20Group)%2F11%20-%20Adieu.dsf&metadata=false Apr 05 10:36:47 volumio volumio[994]: info: URI /mnt/INTERNAL/Rammstein - Zeit - 2022 (VinylRip DSD128, EU Universal Music Group)/11 - Adieu.dsf Apr 05 10:36:47 volumio volumio[994]: info: ALBUMART /albumart?cacheid=315&web=Rammstein/Zeit/extralarge&path=%2Fmnt%2FINTERNAL%2FRammstein%20-%20Zeit%20-%202022%20(VinylRip%20DSD128%2C%20EU%20Universal%20Music%20Group)%2FRammstein%20-%20Zeit.cue&metadata=false Apr 05 10:36:47 volumio volumio[994]: info: URI /mnt/INTERNAL/Rammstein - Zeit - 2022 (VinylRip DSD128, EU Universal Music Group)/Rammstein - Zeit.cue Apr 05 10:36:47 volumio volumio[994]: info: ALBUMART /albumart?cacheid=315&web=Rammstein/Zeit/extralarge&path=%2Fmnt%2FINTERNAL%2FRammstein%20-%20Zeit%20-%202022%20(VinylRip%20DSD128%2C%20EU%20Universal%20Music%20Group)%2FRammstein%20-%20Zeit.cue&metadata=false Apr 05 10:36:47 volumio volumio[994]: info: URI /mnt/INTERNAL/Rammstein - Zeit - 2022 (VinylRip DSD128, EU Universal Music Group)/Rammstein - Zeit.cue Apr 05 10:36:47 volumio volumio[994]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 05 10:36:47 volumio volumio[994]: Error: Unable to resolve or reject the same promise twice Apr 05 10:36:47 volumio volumio[994]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Apr 05 10:36:47 volumio volumio[994]: at /volumio/app/plugins/music_service/mpd/index.js:2568:21 Apr 05 10:36:47 volumio volumio[994]: at MpdClient.handleMessage (/volumio/app/plugins/music_service/mpd/lib/mpd.js:77:3) Apr 05 10:36:47 volumio volumio[994]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:68:12) Apr 05 10:36:47 volumio volumio[994]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12) Apr 05 10:36:47 volumio volumio[994]: at Socket.emit (events.js:400:28) Apr 05 10:36:47 volumio volumio[994]: at addChunk (internal/streams/readable.js:293:12) Apr 05 10:36:47 volumio volumio[994]: at readableAddChunk (internal/streams/readable.js:263:11) Apr 05 10:36:47 volumio volumio[994]: at Socket.Readable.push (internal/streams/readable.js:206:10) Apr 05 10:36:47 volumio volumio[994]: at Pipe.onStreamRead (internal/stream_base_commons.js:188:23) Apr 05 10:36:47 volumio volumio[994]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 05 10:36:47 volumio sudo[20459]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-05 10:35 Apr 05 10:36:47 volumio sudo[20459]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="9552505bba4239c163ac9ee7b0b87a56e0dd0574" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="3d3fc502273a5c173ba19f72c1a952bdb2bdd3b0" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 13 Feb 2024 06:46:56 PM CET" VOLUMIO_VERSION="3.616" VOLUMIO_HARDWARE="tinkerboard" VOLUMIO_DEVICENAME="Asus Tinkerboard" VOLUMIO_HASH="3e288fe4307d08f950c7f8db4447c221"