-- Logs begin at Sun 2024-07-21 17:08:38 CEST, end at Sun 2024-07-21 19:41:19 CEST. -- Jul 21 19:40:01 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 21 19:40:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22485. Jul 21 19:40:01 volumio systemd[1]: Stopped go-librespot Daemon. Jul 21 19:40:01 volumio systemd[1]: Started go-librespot Daemon. Jul 21 19:40:01 volumio go-librespot[6382]: Librespot-go daemon starting... Jul 21 19:40:01 volumio go-librespot[6382]: time="2024-07-21T19:40:01+02:00" level=info msg="generated new device id: e50932ddd9bea7a37e735c1e9d31f4f8a0cd828d" Jul 21 19:40:01 volumio go-librespot[6382]: time="2024-07-21T19:40:01+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" Jul 21 19:40:02 volumio go-librespot[6382]: time="2024-07-21T19:40:02+02:00" level=debug msg="obtained new client token: AACboKyQKBrPWAe36bTy1TRJDcgjISZeRuCfUhSqXv6bAV55t/RP+2Ghp8fxiTnxreUW3Dtf5NzfYbYnkKoAiX2/etxrFXwzXjUHi2bdb869vQLs51EjPLqEHqpYhQmTOdMEVEXllpPp8v6xbL6458NZRdaOixwggO8QQxBlCSxUTL/DZv/QMImdja18bh3uj39eHg6kcw9AM2vesdc7k1asjBApppT45PMaNqmQJojtK3sQ32tLmEV+2qhOag==" Jul 21 19:40:02 volumio volumio[742]: info: Initializing connection to go-librespot Websocket Jul 21 19:40:02 volumio go-librespot[6382]: time="2024-07-21T19:40:02+02:00" level=debug msg="new websocket client" Jul 21 19:40:02 volumio volumio[742]: info: Connection to go-librespot Websocket established Jul 21 19:40:02 volumio go-librespot[6382]: time="2024-07-21T19:40:02+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jul 21 19:40:02 volumio go-librespot[6382]: time="2024-07-21T19:40:02+02:00" level=debug msg="completed keyexchange" Jul 21 19:40:02 volumio go-librespot[6382]: time="2024-07-21T19:40:02+02:00" level=debug msg="completed challenge" Jul 21 19:40:02 volumio go-librespot[6382]: time="2024-07-21T19:40:02+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 21 19:40:02 volumio volumio[742]: info: Connection to go-librespot Websocket closed Jul 21 19:40:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 21 19:40:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 21 19:40:05 volumio volumio[742]: info: Getting Spotify volume Jul 21 19:40:05 volumio volumio[742]: (node:742) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 21 19:40:05 volumio volumio[742]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jul 21 19:40:05 volumio volumio[742]: (node:742) 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: 8017) Jul 21 19:40:05 volumio volumio[742]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 5 Jul 21 19:40:05 volumio volumio[742]: info: CoreCommandRouter::volumioGetState Jul 21 19:40:05 volumio volumio[742]: info: CorePlayQueue::getTrack 2 Jul 21 19:40:05 volumio volumio[742]: info: Initializing connection to go-librespot Websocket Jul 21 19:40:05 volumio volumio[742]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 21 19:40:06 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 21 19:40:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22486. Jul 21 19:40:06 volumio systemd[1]: Stopped go-librespot Daemon. Jul 21 19:40:06 volumio systemd[1]: Started go-librespot Daemon. Jul 21 19:40:06 volumio go-librespot[6397]: Librespot-go daemon starting... Jul 21 19:40:06 volumio go-librespot[6397]: time="2024-07-21T19:40:06+02:00" level=info msg="generated new device id: 05255a6d6262ffeb9ca60f18ce1880ffbe338d51" Jul 21 19:40:06 volumio go-librespot[6397]: time="2024-07-21T19:40:06+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" Jul 21 19:40:06 volumio go-librespot[6397]: time="2024-07-21T19:40:06+02:00" level=debug msg="obtained new client token: AABGLhJus+6qYrA59tqtnw7+cZ2BBbdbYXT7aQ6EZkw0+kxOo4IflJfB1Q9JYjlV0WbpfwER4aODZ3NoLQnS9vIbsv+CxbQLNgPn/A0MsRXvD6ssLiJdF3QTb9owI2BjvAZp2H7yQZoxlXbCIbRMS/5PyWkG+zwFe26GMJMeZE5TgVBTWB+Qoj/k3zfFNFl+HM9qfLWfWCAOyrdsHulea+FMlnikVxktGG2mNKst4ur2PEVBuNXmWj7640jgem6c" Jul 21 19:40:06 volumio go-librespot[6397]: time="2024-07-21T19:40:06+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jul 21 19:40:06 volumio go-librespot[6397]: time="2024-07-21T19:40:06+02:00" level=debug msg="completed keyexchange" Jul 21 19:40:07 volumio go-librespot[6397]: time="2024-07-21T19:40:07+02:00" level=debug msg="completed challenge" Jul 21 19:40:07 volumio go-librespot[6397]: time="2024-07-21T19:40:07+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 21 19:40:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 21 19:40:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 21 19:40:08 volumio volumio[742]: info: Initializing connection to go-librespot Websocket Jul 21 19:40:08 volumio volumio[742]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 21 19:40:10 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 21 19:40:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22487. Jul 21 19:40:10 volumio systemd[1]: Stopped go-librespot Daemon. Jul 21 19:40:10 volumio systemd[1]: Started go-librespot Daemon. Jul 21 19:40:10 volumio go-librespot[6413]: Librespot-go daemon starting... Jul 21 19:40:10 volumio go-librespot[6413]: time="2024-07-21T19:40:10+02:00" level=info msg="generated new device id: 00fd8f4ad1eabff4ee535f67d90438a50ca0c310" Jul 21 19:40:10 volumio go-librespot[6413]: time="2024-07-21T19:40:10+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" Jul 21 19:40:10 volumio go-librespot[6413]: time="2024-07-21T19:40:10+02:00" level=debug msg="obtained new client token: AACdpxD1dcUwt7lHt52VkTcdnG+MLLMzrf/iI6IfkGISEYTu/kiUmgJfEs4JLlH2I+7uJ3bvUidiekB805FZfs41tXFlknPQK+24hT8+Hkg5imAIG3YPyGrlZrkkTGzr88g+OSB9DMRnOHM7hDSUSdr/vbyIEQm/LGBvkeCBUHaDXBbSqrEu3dzz60nGydIYoLPkAZeKWmumHvn7ecOxKOme1szn9Ty59rdUA1dCDqGx9os0gKjFH5M1HwmHUeTR" Jul 21 19:40:10 volumio go-librespot[6413]: time="2024-07-21T19:40:10+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jul 21 19:40:10 volumio go-librespot[6413]: time="2024-07-21T19:40:10+02:00" level=debug msg="completed keyexchange" Jul 21 19:40:11 volumio go-librespot[6413]: time="2024-07-21T19:40:11+02:00" level=debug msg="completed challenge" Jul 21 19:40:11 volumio go-librespot[6413]: time="2024-07-21T19:40:11+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 21 19:40:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 21 19:40:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 21 19:40:11 volumio volumio[742]: info: Initializing connection to go-librespot Websocket Jul 21 19:40:11 volumio volumio[742]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 21 19:40:14 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 21 19:40:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22488. Jul 21 19:40:14 volumio systemd[1]: Stopped go-librespot Daemon. Jul 21 19:40:14 volumio systemd[1]: Started go-librespot Daemon. Jul 21 19:40:14 volumio go-librespot[6432]: Librespot-go daemon starting... Jul 21 19:40:14 volumio go-librespot[6432]: time="2024-07-21T19:40:14+02:00" level=info msg="generated new device id: 5ed3e58c70c49465bda22fa7e6f2b5ed7fea87d3" Jul 21 19:40:14 volumio go-librespot[6432]: time="2024-07-21T19:40:14+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" Jul 21 19:40:14 volumio go-librespot[6432]: time="2024-07-21T19:40:14+02:00" level=debug msg="obtained new client token: AAB8nREcPzbqLkcHqksvmqTvH0godSSgDqPRl+r3JH/fvX07w6zbJijJqNpZ1T9ba3gFX21zrUG/J3aXozjJE4XngBBFpHfLMGEFRmw5DCcQyQbutxY88WAhv9IwKB5l3qSLWKx/SZ38a+sIIIVWwq+i6WiB9vgvPpTTcyJpdRhchEsQA5UYQWmjqwH1GNf8UEAY5smdfoBVZVHwEZZbA/LEpX2c51SoFd+Qej3C5AuFifBAXkRjfwgH8znb2f6x" Jul 21 19:40:14 volumio volumio[742]: info: Initializing connection to go-librespot Websocket Jul 21 19:40:14 volumio go-librespot[6432]: time="2024-07-21T19:40:14+02:00" level=debug msg="new websocket client" Jul 21 19:40:14 volumio volumio[742]: info: Connection to go-librespot Websocket established Jul 21 19:40:15 volumio go-librespot[6432]: time="2024-07-21T19:40:15+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jul 21 19:40:15 volumio go-librespot[6432]: time="2024-07-21T19:40:15+02:00" level=debug msg="completed keyexchange" Jul 21 19:40:15 volumio go-librespot[6432]: time="2024-07-21T19:40:15+02:00" level=debug msg="completed challenge" Jul 21 19:40:15 volumio go-librespot[6432]: time="2024-07-21T19:40:15+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 21 19:40:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 21 19:40:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 21 19:40:15 volumio volumio[742]: info: Connection to go-librespot Websocket closed Jul 21 19:40:17 volumio volumio[742]: info: Getting Spotify volume Jul 21 19:40:17 volumio volumio[742]: (node:742) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 21 19:40:17 volumio volumio[742]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jul 21 19:40:17 volumio volumio[742]: (node:742) 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: 8018) Jul 21 19:40:17 volumio volumio[742]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 5 Jul 21 19:40:17 volumio volumio[742]: info: CoreCommandRouter::volumioGetState Jul 21 19:40:17 volumio volumio[742]: info: CorePlayQueue::getTrack 2 Jul 21 19:40:18 volumio volumio[742]: info: Initializing connection to go-librespot Websocket Jul 21 19:40:18 volumio volumio[742]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 21 19:40:18 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 21 19:40:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22489. Jul 21 19:40:18 volumio systemd[1]: Stopped go-librespot Daemon. Jul 21 19:40:18 volumio systemd[1]: Started go-librespot Daemon. Jul 21 19:40:18 volumio go-librespot[6449]: Librespot-go daemon starting... Jul 21 19:40:18 volumio go-librespot[6449]: time="2024-07-21T19:40:18+02:00" level=info msg="generated new device id: 7f89eec73f6ca526e5b06ac0bfedcf186c3a7195" Jul 21 19:40:18 volumio go-librespot[6449]: time="2024-07-21T19:40:18+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" Jul 21 19:40:19 volumio go-librespot[6449]: time="2024-07-21T19:40:19+02:00" level=debug msg="obtained new client token: AAA2bFuc+jLg+NfnahZrx4P6HmCDf/Jyo+qjixB57X2917Vj2hYqBab5/xghDTjFubY4Wupq//rIBu2VN9mG+EErhVFxOec0lbPbbZC5V6XJqXt+ILfONP5n5iWsFWgzb5zxd7GaI/tStTPjfqnbHYHBcZLaZ39Eea/EZpw8+5VlvjUM1o78aRm+y1oXB1tFKsnq5d2Hg4G9zuOvaBfhlXlLHLPjWZtWF+/N+9YCvnALNXtoh0emoj8HaxJzQg==" Jul 21 19:40:19 volumio go-librespot[6449]: time="2024-07-21T19:40:19+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jul 21 19:40:19 volumio go-librespot[6449]: time="2024-07-21T19:40:19+02:00" level=debug msg="completed keyexchange" Jul 21 19:40:19 volumio go-librespot[6449]: time="2024-07-21T19:40:19+02:00" level=debug msg="completed challenge" Jul 21 19:40:19 volumio go-librespot[6449]: time="2024-07-21T19:40:19+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 21 19:40:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 21 19:40:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 21 19:40:21 volumio volumio[742]: info: Initializing connection to go-librespot Websocket Jul 21 19:40:21 volumio volumio[742]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 21 19:40:23 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 21 19:40:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22490. Jul 21 19:40:23 volumio systemd[1]: Stopped go-librespot Daemon. Jul 21 19:40:23 volumio systemd[1]: Started go-librespot Daemon. Jul 21 19:40:23 volumio go-librespot[6465]: Librespot-go daemon starting... Jul 21 19:40:23 volumio go-librespot[6465]: time="2024-07-21T19:40:23+02:00" level=info msg="generated new device id: c33258d4473beab0612bb7d207cae7525b8785ac" Jul 21 19:40:23 volumio go-librespot[6465]: time="2024-07-21T19:40:23+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" Jul 21 19:40:23 volumio go-librespot[6465]: time="2024-07-21T19:40:23+02:00" level=debug msg="obtained new client token: AAA+XKQx4rJFrNQhyufCbpp+8ZFKE/oAMloFsCcoQZfi+FuXRLSl4hZnh31Cu/bs1XWzCcLSnpQ3IMRl+YXSGaup6IKx3/KEET5HEAwBV2zpKrpG+DwK+WLHK53ws6y40eFTDULLZtdG0Gsylh2N7yRYhtoWULS7OfzFQI663sraFDtfjY20rNwc6Hv/lPlV42GyhUsuRkOCWXdhMUHAjiqf4ac1REM5Vakwl54Vqh19Y5OdyVjKdRDQfilEdYmJ" Jul 21 19:40:23 volumio go-librespot[6465]: time="2024-07-21T19:40:23+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jul 21 19:40:23 volumio go-librespot[6465]: time="2024-07-21T19:40:23+02:00" level=debug msg="completed keyexchange" Jul 21 19:40:24 volumio go-librespot[6465]: time="2024-07-21T19:40:24+02:00" level=debug msg="completed challenge" Jul 21 19:40:24 volumio go-librespot[6465]: time="2024-07-21T19:40:24+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 21 19:40:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 21 19:40:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 21 19:40:24 volumio volumio[742]: info: Initializing connection to go-librespot Websocket Jul 21 19:40:24 volumio volumio[742]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 21 19:40:27 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 21 19:40:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22491. Jul 21 19:40:27 volumio systemd[1]: Stopped go-librespot Daemon. Jul 21 19:40:27 volumio systemd[1]: Started go-librespot Daemon. Jul 21 19:40:27 volumio go-librespot[6481]: Librespot-go daemon starting... Jul 21 19:40:27 volumio go-librespot[6481]: time="2024-07-21T19:40:27+02:00" level=info msg="generated new device id: 8760adcbff34b7223d9cd64f8abf6f2b26a4a68d" Jul 21 19:40:27 volumio go-librespot[6481]: time="2024-07-21T19:40:27+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" Jul 21 19:40:27 volumio go-librespot[6481]: time="2024-07-21T19:40:27+02:00" level=debug msg="obtained new client token: AADj9iwzLn1IqBepXD+QBgRyuf2xClG1Hr2lZCeVVn1QJT+Vhxy7nGCSprB2FT4h6ie2IBI9vCASp8VR1wR4BFul65Y5bHSQYKL9hgkv7W3lfw2Mq/SQOHNNR0WhWPAMBaujT4s1r4cPDdlijcFE8Ni+a1sKGiH4Grve92qQUrmU/hzOJ1iBymMuZwe/33wSa52hp3bN2qiRRWGw2SPaEUfMpuvA34/fuv6voWiDO8K+sq/5k3deuec9zrTnczpE" Jul 21 19:40:27 volumio volumio[742]: info: Initializing connection to go-librespot Websocket Jul 21 19:40:27 volumio go-librespot[6481]: time="2024-07-21T19:40:27+02:00" level=debug msg="new websocket client" Jul 21 19:40:27 volumio volumio[742]: info: Connection to go-librespot Websocket established Jul 21 19:40:27 volumio go-librespot[6481]: time="2024-07-21T19:40:27+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jul 21 19:40:27 volumio go-librespot[6481]: time="2024-07-21T19:40:27+02:00" level=debug msg="completed keyexchange" Jul 21 19:40:28 volumio go-librespot[6481]: time="2024-07-21T19:40:28+02:00" level=debug msg="completed challenge" Jul 21 19:40:28 volumio go-librespot[6481]: time="2024-07-21T19:40:28+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 21 19:40:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 21 19:40:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 21 19:40:28 volumio volumio[742]: info: Connection to go-librespot Websocket closed Jul 21 19:40:30 volumio volumio[742]: info: Getting Spotify volume Jul 21 19:40:30 volumio volumio[742]: (node:742) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 21 19:40:30 volumio volumio[742]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jul 21 19:40:30 volumio volumio[742]: (node:742) 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: 8019) Jul 21 19:40:30 volumio volumio[742]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 5 Jul 21 19:40:30 volumio volumio[742]: info: CoreCommandRouter::volumioGetState Jul 21 19:40:30 volumio volumio[742]: info: CorePlayQueue::getTrack 2 Jul 21 19:40:31 volumio volumio[742]: info: Initializing connection to go-librespot Websocket Jul 21 19:40:31 volumio volumio[742]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 21 19:40:32 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 21 19:40:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22492. Jul 21 19:40:32 volumio systemd[1]: Stopped go-librespot Daemon. Jul 21 19:40:32 volumio systemd[1]: Started go-librespot Daemon. Jul 21 19:40:32 volumio go-librespot[6499]: Librespot-go daemon starting... Jul 21 19:40:32 volumio go-librespot[6499]: time="2024-07-21T19:40:32+02:00" level=info msg="generated new device id: d9e5964fe2d2d3e1063c8e4b35968e8af4565317" Jul 21 19:40:32 volumio go-librespot[6499]: time="2024-07-21T19:40:32+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" Jul 21 19:40:32 volumio go-librespot[6499]: time="2024-07-21T19:40:32+02:00" level=debug msg="obtained new client token: AACqPQdCzFofglS6iFqb9DeIpke0cuuaewfWTHCIvXol4Cz2UinbVzxegWXu5+eshdOdIe+6SsioCFSl3apD+ieUlay+ChasVhF+SoOV+r9MclkfMr0wxI5zD736ysCPc+ObvKuF3b4wMalS4jmOdaX2KrOhzfg51XYKDG0bQebVz6n51IL9+TixFlkZRULt0t4dS9NqsS94Ree6OqEvQc/0VcsVZxCQT3CYIS8JwK9z7S+pKVrJyaTETgGC95Ll" Jul 21 19:40:32 volumio go-librespot[6499]: time="2024-07-21T19:40:32+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jul 21 19:40:32 volumio go-librespot[6499]: time="2024-07-21T19:40:32+02:00" level=debug msg="completed keyexchange" Jul 21 19:40:33 volumio go-librespot[6499]: time="2024-07-21T19:40:33+02:00" level=debug msg="completed challenge" Jul 21 19:40:33 volumio go-librespot[6499]: time="2024-07-21T19:40:33+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 21 19:40:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 21 19:40:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 21 19:40:34 volumio volumio[742]: info: Initializing connection to go-librespot Websocket Jul 21 19:40:34 volumio volumio[742]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 21 19:40:36 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 21 19:40:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22493. Jul 21 19:40:36 volumio systemd[1]: Stopped go-librespot Daemon. Jul 21 19:40:36 volumio systemd[1]: Started go-librespot Daemon. Jul 21 19:40:36 volumio go-librespot[6515]: Librespot-go daemon starting... Jul 21 19:40:36 volumio go-librespot[6515]: time="2024-07-21T19:40:36+02:00" level=info msg="generated new device id: 393614496cefe547bad56d3a7566550b20ca389e" Jul 21 19:40:36 volumio go-librespot[6515]: time="2024-07-21T19:40:36+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" Jul 21 19:40:36 volumio go-librespot[6515]: time="2024-07-21T19:40:36+02:00" level=debug msg="obtained new client token: AACg6DIKik39hXU5X5muXz/p/DWyThVD1PLXDLYOuiINeKhnzjqRQt5cvRpIw1WfCvg+XFYfrZM1quXUe6JFPD+t81XQOQSV5sfPPo4JFhlOPM/O5dVTptU0t6VWPJ8GjS5kK09dRGO8erNbxv2WKovtvDlnWqRboAuibszvzQKuIXWmjJwxOzJWJEJZIvh9AUoqpA/Iz02fbMcL04AYyU6w1V0zFaTA7WaDoP/A/2P/DWk+xp1Ay9hx5CRh/p98" Jul 21 19:40:36 volumio go-librespot[6515]: time="2024-07-21T19:40:36+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jul 21 19:40:36 volumio go-librespot[6515]: time="2024-07-21T19:40:36+02:00" level=debug msg="completed keyexchange" Jul 21 19:40:37 volumio go-librespot[6515]: time="2024-07-21T19:40:37+02:00" level=debug msg="completed challenge" Jul 21 19:40:37 volumio go-librespot[6515]: time="2024-07-21T19:40:37+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 21 19:40:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 21 19:40:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 21 19:40:37 volumio volumio[742]: info: Initializing connection to go-librespot Websocket Jul 21 19:40:37 volumio volumio[742]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 21 19:40:39 volumio volumio[742]: verbose: New Socket.io Connection to 192.168.50.10 from 192.168.50.69 UA: okhttp/4.9.2 Total Clients: 5 Jul 21 19:40:39 volumio volumio[742]: info: CoreCommandRouter::volumioGetState Jul 21 19:40:39 volumio volumio[742]: info: CorePlayQueue::getTrack 2 Jul 21 19:40:39 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jul 21 19:40:39 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jul 21 19:40:40 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 21 19:40:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22494. Jul 21 19:40:40 volumio systemd[1]: Stopped go-librespot Daemon. Jul 21 19:40:40 volumio systemd[1]: Started go-librespot Daemon. Jul 21 19:40:40 volumio go-librespot[6530]: Librespot-go daemon starting... Jul 21 19:40:40 volumio go-librespot[6530]: time="2024-07-21T19:40:40+02:00" level=info msg="generated new device id: a0f55cca2a276f9a3898f40bd11a9653dd677a34" Jul 21 19:40:40 volumio go-librespot[6530]: time="2024-07-21T19:40:40+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" Jul 21 19:40:40 volumio volumio[742]: verbose: New Socket.io Connection to 192.168.50.10 from 192.168.50.69 UA: okhttp/4.9.2 Total Clients: 6 Jul 21 19:40:40 volumio go-librespot[6530]: time="2024-07-21T19:40:40+02:00" level=debug msg="obtained new client token: AAAcN23T1T6SHDI/v9kfaRQopsUM9Jao1uNoNe2rMchEGf0CcLsSGaUJOKvaIgXRP/uFcbKk80LQ2nNee56VruJVsBKOiANCi31G+tDodmC5wdxY51zHB5q4HQi6X0G5v8hVdXUb0zukON08ZX8on8hqfCibZjgpBRfjJJz0J61b45dfnxclomFC99uLJpyWlcYExiM0Y3RRKgqOjzx9QBz9+5Zs5U/YH0P/+GwUoK2kQswSMunEwIp/U7TZAWel" Jul 21 19:40:40 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jul 21 19:40:40 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jul 21 19:40:40 volumio volumio[742]: info: CoreCommandRouter::volumioGetVisibleSources Jul 21 19:40:40 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 21 19:40:40 volumio volumio[742]: info: CoreCommandRouter::volumioGetState Jul 21 19:40:40 volumio volumio[742]: info: CorePlayQueue::getTrack 2 Jul 21 19:40:40 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jul 21 19:40:40 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jul 21 19:40:40 volumio volumio[742]: info: Initializing connection to go-librespot Websocket Jul 21 19:40:40 volumio go-librespot[6530]: time="2024-07-21T19:40:40+02:00" level=debug msg="new websocket client" Jul 21 19:40:40 volumio volumio[742]: info: Connection to go-librespot Websocket established Jul 21 19:40:41 volumio volumio[742]: info: Received Get System Info Jul 21 19:40:41 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 21 19:40:41 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 21 19:40:41 volumio volumio[742]: info: Discovery: Getting this device information Jul 21 19:40:41 volumio volumio[742]: info: CoreCommandRouter::volumioGetState Jul 21 19:40:41 volumio volumio[742]: info: CorePlayQueue::getTrack 2 Jul 21 19:40:41 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 21 19:40:41 volumio volumio[742]: info: CoreCommandRouter::volumioGetState Jul 21 19:40:41 volumio volumio[742]: info: CorePlayQueue::getTrack 2 Jul 21 19:40:41 volumio go-librespot[6530]: time="2024-07-21T19:40:41+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jul 21 19:40:41 volumio volumio[742]: info: Listing playlists Jul 21 19:40:41 volumio volumio[742]: info: CoreCommandRouter::volumioGetQueue Jul 21 19:40:41 volumio volumio[742]: info: CoreStateMachine::getQueue Jul 21 19:40:41 volumio volumio[742]: info: CorePlayQueue::getQueue Jul 21 19:40:41 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jul 21 19:40:41 volumio go-librespot[6530]: time="2024-07-21T19:40:41+02:00" level=debug msg="completed keyexchange" Jul 21 19:40:41 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 21 19:40:41 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 21 19:40:41 volumio volumio[742]: info: Discovery: Getting this device information Jul 21 19:40:41 volumio volumio[742]: info: CoreCommandRouter::volumioGetState Jul 21 19:40:41 volumio volumio[742]: info: CorePlayQueue::getTrack 2 Jul 21 19:40:41 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 21 19:40:41 volumio go-librespot[6530]: time="2024-07-21T19:40:41+02:00" level=debug msg="completed challenge" Jul 21 19:40:41 volumio go-librespot[6530]: time="2024-07-21T19:40:41+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 21 19:40:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 21 19:40:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 21 19:40:41 volumio volumio[742]: info: Connection to go-librespot Websocket closed Jul 21 19:40:42 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jul 21 19:40:42 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jul 21 19:40:43 volumio volumio[742]: info: Getting Spotify volume Jul 21 19:40:43 volumio volumio[742]: (node:742) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 21 19:40:43 volumio volumio[742]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jul 21 19:40:43 volumio volumio[742]: (node:742) 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: 8020) Jul 21 19:40:43 volumio volumio[742]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 6 Jul 21 19:40:44 volumio volumio[742]: info: CoreCommandRouter::volumioGetState Jul 21 19:40:44 volumio volumio[742]: info: CorePlayQueue::getTrack 2 Jul 21 19:40:44 volumio volumio[742]: info: Initializing connection to go-librespot Websocket Jul 21 19:40:44 volumio volumio[742]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 21 19:40:44 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 21 19:40:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22495. Jul 21 19:40:44 volumio systemd[1]: Stopped go-librespot Daemon. Jul 21 19:40:44 volumio systemd[1]: Started go-librespot Daemon. Jul 21 19:40:44 volumio go-librespot[6584]: Librespot-go daemon starting... Jul 21 19:40:44 volumio go-librespot[6584]: time="2024-07-21T19:40:44+02:00" level=info msg="generated new device id: 47760458a8622fd1a6a82d566d1f00a22e56b538" Jul 21 19:40:44 volumio go-librespot[6584]: time="2024-07-21T19:40:44+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" Jul 21 19:40:45 volumio go-librespot[6584]: time="2024-07-21T19:40:45+02:00" level=debug msg="obtained new client token: AABQPXevyff//F5tG5i2ErikiUF8c73fmyZICyuJPFhg+zqJOrxdbd15Kzvo1evNqXAvwgyWGvlKhFHIeDaRehf3Ptj3OHZnPLWMQW3jSa3hQ+EFxfaWFLn0LLJlSpW7y3BzYWEkIpGkuRsKnLTZ9roOCi7DeDrYaJ2jStP+QWostzJ5oE6fYVA7iI5lu5TFFGDKOKR3Vne0YI0Z4LAGYglfMBpVRlYMJfF4UXgxdniVt6+1xo2GRs6CZWQzE6wn" Jul 21 19:40:45 volumio go-librespot[6584]: time="2024-07-21T19:40:45+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jul 21 19:40:45 volumio go-librespot[6584]: time="2024-07-21T19:40:45+02:00" level=debug msg="completed keyexchange" Jul 21 19:40:46 volumio sudo[6595]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 21 19:40:46 volumio sudo[6595]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 21 19:40:46 volumio sudo[6597]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 21 19:40:46 volumio sudo[6597]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 21 19:40:46 volumio sudo[6595]: pam_unix(sudo:session): session closed for user root Jul 21 19:40:46 volumio sudo[6597]: pam_unix(sudo:session): session closed for user root Jul 21 19:40:46 volumio go-librespot[6584]: time="2024-07-21T19:40:46+02:00" level=debug msg="completed challenge" Jul 21 19:40:46 volumio go-librespot[6584]: time="2024-07-21T19:40:46+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 21 19:40:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 21 19:40:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 21 19:40:46 volumio kernel: hwmon hwmon1: Undervoltage detected! Jul 21 19:40:46 volumio volumio[742]: verbose: New Socket.io Connection to 192.168.50.10 from 192.168.50.69 UA: okhttp/4.9.2 Total Clients: 6 Jul 21 19:40:46 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jul 21 19:40:46 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jul 21 19:40:46 volumio volumio[742]: info: CoreCommandRouter::volumioGetVisibleSources Jul 21 19:40:46 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 21 19:40:46 volumio volumio[742]: info: CoreCommandRouter::volumioGetState Jul 21 19:40:46 volumio volumio[742]: info: CorePlayQueue::getTrack 2 Jul 21 19:40:46 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jul 21 19:40:46 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jul 21 19:40:46 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jul 21 19:40:46 volumio volumio[742]: info: Received Get System Info Jul 21 19:40:46 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 21 19:40:46 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 21 19:40:46 volumio volumio[742]: info: Discovery: Getting this device information Jul 21 19:40:46 volumio volumio[742]: info: CoreCommandRouter::volumioGetState Jul 21 19:40:46 volumio volumio[742]: info: CorePlayQueue::getTrack 2 Jul 21 19:40:46 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 21 19:40:46 volumio volumio[742]: info: CoreCommandRouter::volumioGetState Jul 21 19:40:46 volumio volumio[742]: info: CorePlayQueue::getTrack 2 Jul 21 19:40:46 volumio volumio[742]: info: Listing playlists Jul 21 19:40:47 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jul 21 19:40:47 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jul 21 19:40:47 volumio volumio[742]: info: Initializing connection to go-librespot Websocket Jul 21 19:40:47 volumio volumio[742]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 21 19:40:47 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jul 21 19:40:47 volumio volumio[742]: info: Received Get System Info Jul 21 19:40:47 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 21 19:40:47 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 21 19:40:47 volumio volumio[742]: info: Discovery: Getting this device information Jul 21 19:40:47 volumio volumio[742]: info: CoreCommandRouter::volumioGetState Jul 21 19:40:47 volumio volumio[742]: info: CorePlayQueue::getTrack 2 Jul 21 19:40:47 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 21 19:40:48 volumio volumio[742]: info: CoreCommandRouter::volumioGetQueue Jul 21 19:40:48 volumio volumio[742]: info: CoreStateMachine::getQueue Jul 21 19:40:48 volumio volumio[742]: info: CorePlayQueue::getQueue Jul 21 19:40:48 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 21 19:40:48 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 21 19:40:48 volumio volumio[742]: info: Discovery: Getting this device information Jul 21 19:40:48 volumio volumio[742]: info: CoreCommandRouter::volumioGetState Jul 21 19:40:48 volumio volumio[742]: info: CorePlayQueue::getTrack 2 Jul 21 19:40:48 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 21 19:40:49 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jul 21 19:40:49 volumio volumio[742]: info: Received Get System Info Jul 21 19:40:49 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 21 19:40:49 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 21 19:40:49 volumio volumio[742]: info: Discovery: Getting this device information Jul 21 19:40:49 volumio volumio[742]: info: CoreCommandRouter::volumioGetState Jul 21 19:40:49 volumio volumio[742]: info: CorePlayQueue::getTrack 2 Jul 21 19:40:49 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 21 19:40:49 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 21 19:40:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22496. Jul 21 19:40:49 volumio systemd[1]: Stopped go-librespot Daemon. Jul 21 19:40:49 volumio systemd[1]: Started go-librespot Daemon. Jul 21 19:40:49 volumio go-librespot[6609]: Librespot-go daemon starting... Jul 21 19:40:49 volumio go-librespot[6609]: time="2024-07-21T19:40:49+02:00" level=info msg="generated new device id: 076e2cb385db0457086eecf9d3ddefc1336114db" Jul 21 19:40:49 volumio go-librespot[6609]: time="2024-07-21T19:40:49+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" Jul 21 19:40:49 volumio go-librespot[6609]: time="2024-07-21T19:40:49+02:00" level=debug msg="obtained new client token: AAAZ7HPl43w4D4HftN9lEWedOHLCP5e1tJwsls6XlN4DdFF1GgbnVUH0Tbd9m4nxSwJs/vjL90Wackb1Ll9XChngXM8OlVKZmSdJw5WJncENKzKo3ETAELfW8nOrIfPYuQo9wuMzU5BqlrHTZPV1hOZQ7dlHk6oJ/HNHcx7d9tTKyIJ5Vdv6lby7TOTPPqIbrtUAUinU2To/ThlmndK6xnyJ4kp0Ana6KuqctqcFuTEzU5AwwTiJOgyyMt9k8utU" Jul 21 19:40:50 volumio go-librespot[6609]: time="2024-07-21T19:40:50+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jul 21 19:40:50 volumio go-librespot[6609]: time="2024-07-21T19:40:50+02:00" level=debug msg="completed keyexchange" Jul 21 19:40:50 volumio kernel: hwmon hwmon1: Voltage normalised Jul 21 19:40:50 volumio go-librespot[6609]: time="2024-07-21T19:40:50+02:00" level=debug msg="completed challenge" Jul 21 19:40:50 volumio go-librespot[6609]: time="2024-07-21T19:40:50+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 21 19:40:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 21 19:40:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 21 19:40:50 volumio volumio[742]: info: Initializing connection to go-librespot Websocket Jul 21 19:40:50 volumio volumio[742]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 21 19:40:53 volumio volumio[742]: info: Initializing connection to go-librespot Websocket Jul 21 19:40:53 volumio volumio[742]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 21 19:40:53 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 21 19:40:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22497. Jul 21 19:40:53 volumio systemd[1]: Stopped go-librespot Daemon. Jul 21 19:40:53 volumio systemd[1]: Started go-librespot Daemon. Jul 21 19:40:53 volumio go-librespot[6625]: Librespot-go daemon starting... Jul 21 19:40:53 volumio go-librespot[6625]: time="2024-07-21T19:40:53+02:00" level=info msg="generated new device id: f5b9b3626fd04863bfa837cdb35f3708e7d928d0" Jul 21 19:40:53 volumio go-librespot[6625]: time="2024-07-21T19:40:53+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" Jul 21 19:40:54 volumio go-librespot[6625]: time="2024-07-21T19:40:54+02:00" level=debug msg="obtained new client token: AADHiCv45qUZQz3eAKEQxWSyK7zbE2gc3WcGQWslSIxda0WPS2cKzMLBasn13oc+gyRenLfqGl59uckHjuifXYD7jp85ps3ZtG/oTJ2uqnnEuQ2Wi113uRYrcYQ1sWTIXsGkJ7yLy2EimjcbQgjQstHET/T8ohk7Ss1PqQ0VoNy1ESFcoUaKhPuUV/42xcQWeMqBMn8+p9bRFtaMfx4J5TwXMs0TdI1nljbLkc6VT+oAn4RwSkcE618vv36DAw==" Jul 21 19:40:54 volumio go-librespot[6625]: time="2024-07-21T19:40:54+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jul 21 19:40:54 volumio go-librespot[6625]: time="2024-07-21T19:40:54+02:00" level=debug msg="completed keyexchange" Jul 21 19:40:54 volumio go-librespot[6625]: time="2024-07-21T19:40:54+02:00" level=debug msg="completed challenge" Jul 21 19:40:54 volumio go-librespot[6625]: time="2024-07-21T19:40:54+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 21 19:40:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 21 19:40:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 21 19:40:56 volumio volumio[742]: info: Initializing connection to go-librespot Websocket Jul 21 19:40:56 volumio volumio[742]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 21 19:40:58 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 21 19:40:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22498. Jul 21 19:40:58 volumio systemd[1]: Stopped go-librespot Daemon. Jul 21 19:40:58 volumio systemd[1]: Started go-librespot Daemon. Jul 21 19:40:58 volumio go-librespot[6640]: Librespot-go daemon starting... Jul 21 19:40:58 volumio go-librespot[6640]: time="2024-07-21T19:40:58+02:00" level=info msg="generated new device id: 1beef53fec929cb1c88fec227c25f7c153672a6d" Jul 21 19:40:58 volumio go-librespot[6640]: time="2024-07-21T19:40:58+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" Jul 21 19:40:58 volumio go-librespot[6640]: time="2024-07-21T19:40:58+02:00" level=debug msg="obtained new client token: AACRcrhIifXYBuOkh7CTDrzE4HZNcJuSVMZZrcLW9ZNEMUfXQF8xrfeW8PJRm20Eid+EYfeffq24tDARH3sTPOISD/VIjDyWTEPpDgi6lWj0t9S9tPCskG/cNKm57MZs3tcsRI6SXe9kw0IOc6zqCthJsrPWCZMFD86otUDWicnTFjg4JqNQchuBazOh930k5zXatRQsv4OBDrHnkmCiHoCeyj1Xur8pj1uU7vDbNvhZ74CxvbOvo6b3ibv1p59e" Jul 21 19:40:58 volumio go-librespot[6640]: time="2024-07-21T19:40:58+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jul 21 19:40:58 volumio go-librespot[6640]: time="2024-07-21T19:40:58+02:00" level=debug msg="completed keyexchange" Jul 21 19:40:59 volumio go-librespot[6640]: time="2024-07-21T19:40:59+02:00" level=debug msg="completed challenge" Jul 21 19:40:59 volumio go-librespot[6640]: time="2024-07-21T19:40:59+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 21 19:40:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 21 19:40:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 21 19:40:59 volumio volumio[742]: info: Initializing connection to go-librespot Websocket Jul 21 19:40:59 volumio volumio[742]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 21 19:41:02 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 21 19:41:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22499. Jul 21 19:41:02 volumio systemd[1]: Stopped go-librespot Daemon. Jul 21 19:41:02 volumio systemd[1]: Started go-librespot Daemon. Jul 21 19:41:02 volumio go-librespot[6655]: Librespot-go daemon starting... Jul 21 19:41:02 volumio go-librespot[6655]: time="2024-07-21T19:41:02+02:00" level=info msg="generated new device id: cb8376d1b4f62537fdb8084ed6e1edad45e0510a" Jul 21 19:41:02 volumio go-librespot[6655]: time="2024-07-21T19:41:02+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" Jul 21 19:41:02 volumio go-librespot[6655]: time="2024-07-21T19:41:02+02:00" level=debug msg="obtained new client token: AACo5mXenXO1cXA1ECGjgtAhsfoeXCZbOCZFl9501mWjRxn9/WGMKe/XaRItaEM9uvZtBfazAN3SEpktnIsvArwr7NW9bBqXftUJesQTTi6hCUBGnQcS/csCHog3MomyLVrPiFfs6n44XBzU2OgVLxJDIHkdQ1QzCPJct+bhyMxlfKR8bPzPIqt7KLluqoXLV0fbIK/3PTMd004/bvkvqkVyhrmpw1RRxsJym/6H/qc0X4C7cIZbw7CZ4N/TTm63" Jul 21 19:41:02 volumio volumio[742]: info: Initializing connection to go-librespot Websocket Jul 21 19:41:02 volumio go-librespot[6655]: time="2024-07-21T19:41:02+02:00" level=debug msg="new websocket client" Jul 21 19:41:02 volumio volumio[742]: info: Connection to go-librespot Websocket established Jul 21 19:41:02 volumio go-librespot[6655]: time="2024-07-21T19:41:02+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jul 21 19:41:03 volumio go-librespot[6655]: time="2024-07-21T19:41:03+02:00" level=debug msg="completed keyexchange" Jul 21 19:41:03 volumio go-librespot[6655]: time="2024-07-21T19:41:03+02:00" level=debug msg="completed challenge" Jul 21 19:41:03 volumio go-librespot[6655]: time="2024-07-21T19:41:03+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 21 19:41:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 21 19:41:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 21 19:41:03 volumio volumio[742]: info: Connection to go-librespot Websocket closed Jul 21 19:41:05 volumio volumio[742]: info: Getting Spotify volume Jul 21 19:41:05 volumio volumio[742]: (node:742) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 21 19:41:05 volumio volumio[742]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jul 21 19:41:05 volumio volumio[742]: (node:742) 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: 8021) Jul 21 19:41:05 volumio volumio[742]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Jul 21 19:41:05 volumio volumio[742]: info: CoreCommandRouter::volumioGetState Jul 21 19:41:05 volumio volumio[742]: info: CorePlayQueue::getTrack 2 Jul 21 19:41:05 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jul 21 19:41:05 volumio volumio[742]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Jul 21 19:41:05 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Jul 21 19:41:05 volumio volumio[742]: info: Received Get System Version Jul 21 19:41:05 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 21 19:41:05 volumio volumio[742]: info: Received Get System Info Jul 21 19:41:05 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 21 19:41:05 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 21 19:41:05 volumio volumio[742]: info: Discovery: Getting this device information Jul 21 19:41:05 volumio volumio[742]: info: CoreCommandRouter::volumioGetState Jul 21 19:41:05 volumio volumio[742]: info: CorePlayQueue::getTrack 2 Jul 21 19:41:05 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 21 19:41:06 volumio volumio[742]: info: Initializing connection to go-librespot Websocket Jul 21 19:41:06 volumio volumio[742]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 21 19:41:06 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 21 19:41:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22500. Jul 21 19:41:06 volumio systemd[1]: Stopped go-librespot Daemon. Jul 21 19:41:06 volumio systemd[1]: Started go-librespot Daemon. Jul 21 19:41:06 volumio go-librespot[6672]: Librespot-go daemon starting... Jul 21 19:41:06 volumio go-librespot[6672]: time="2024-07-21T19:41:06+02:00" level=info msg="generated new device id: 8278e77e57ec97c33971430019694f27ebe9889e" Jul 21 19:41:06 volumio go-librespot[6672]: time="2024-07-21T19:41:06+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" Jul 21 19:41:07 volumio go-librespot[6672]: time="2024-07-21T19:41:07+02:00" level=debug msg="obtained new client token: AABZF5FwsHEP90Dkn3kFuIc6LDk/CU/UIWNEO67EkTViDamrdemMxElfo1TdHOChQmCDldyI+bHGl3vd5fMaRuUSpKdcKqX2ODVtunIeCXFb5kIWLWvNIWr8xuQNik/kbtsOE7lmIkubkpLPiglOhf3runr+4Wth3Wc/jEE0gNrCU/tLjCSikgctGysqmylY5ps4jzOHLksImIfBMxvqpPcIhrMgyxsgGbiDIPjgU4AnpRwQDT3DNTy/+rLKFw==" Jul 21 19:41:07 volumio go-librespot[6672]: time="2024-07-21T19:41:07+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jul 21 19:41:07 volumio go-librespot[6672]: time="2024-07-21T19:41:07+02:00" level=debug msg="completed keyexchange" Jul 21 19:41:07 volumio go-librespot[6672]: time="2024-07-21T19:41:07+02:00" level=debug msg="completed challenge" Jul 21 19:41:07 volumio go-librespot[6672]: time="2024-07-21T19:41:07+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 21 19:41:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 21 19:41:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 21 19:41:09 volumio volumio[742]: info: Initializing connection to go-librespot Websocket Jul 21 19:41:09 volumio volumio[742]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 21 19:41:11 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 21 19:41:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22501. Jul 21 19:41:11 volumio systemd[1]: Stopped go-librespot Daemon. Jul 21 19:41:11 volumio systemd[1]: Started go-librespot Daemon. Jul 21 19:41:11 volumio go-librespot[6688]: Librespot-go daemon starting... Jul 21 19:41:11 volumio go-librespot[6688]: time="2024-07-21T19:41:11+02:00" level=info msg="generated new device id: f059457c07e15a5f95cbc43894c78b7986882595" Jul 21 19:41:11 volumio go-librespot[6688]: time="2024-07-21T19:41:11+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" Jul 21 19:41:11 volumio go-librespot[6688]: time="2024-07-21T19:41:11+02:00" level=debug msg="obtained new client token: AADeiroKGLK+W2IbsKlZdY7Ehkocomgh54Ujjt6rH2gTpurnla2yMUN5+ajYeOFLjV9Fp53jirkq2WUF7x42c1Om9mn/h5+WB6wQ45Kbz8W8GHdcN50diZt6B+LIiZjZpq9wae1zLdGDQ76zQi9QKGtfp4teloz3XG2X6FlSvd4ZX7RjwGRs20wkAf4OArkYj8zA3mYulBAvwXA8jjlh6FE1ssfSxqtzR5MKz6eBCRA/JPktibdL508mddvzCwQ8" Jul 21 19:41:11 volumio go-librespot[6688]: time="2024-07-21T19:41:11+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jul 21 19:41:11 volumio go-librespot[6688]: time="2024-07-21T19:41:11+02:00" level=debug msg="completed keyexchange" Jul 21 19:41:12 volumio go-librespot[6688]: time="2024-07-21T19:41:12+02:00" level=debug msg="completed challenge" Jul 21 19:41:12 volumio go-librespot[6688]: time="2024-07-21T19:41:12+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 21 19:41:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 21 19:41:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 21 19:41:12 volumio volumio[742]: info: Initializing connection to go-librespot Websocket Jul 21 19:41:12 volumio volumio[742]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 21 19:41:15 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 21 19:41:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22502. Jul 21 19:41:15 volumio systemd[1]: Stopped go-librespot Daemon. Jul 21 19:41:15 volumio systemd[1]: Started go-librespot Daemon. Jul 21 19:41:15 volumio go-librespot[6704]: Librespot-go daemon starting... Jul 21 19:41:15 volumio go-librespot[6704]: time="2024-07-21T19:41:15+02:00" level=info msg="generated new device id: b0e5419330d02201931b0cf25f0cfdcb0c26c756" Jul 21 19:41:15 volumio go-librespot[6704]: time="2024-07-21T19:41:15+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" Jul 21 19:41:15 volumio go-librespot[6704]: time="2024-07-21T19:41:15+02:00" level=debug msg="obtained new client token: AADlgCINTH7FPuJo1lOlNkiMHYAAmXmtDog4rzn969omHYUVye3nAQM0XOoFIzIUQFdso1vBBwaEiNtz5LcewWuA2HbQvb3CZZWMb/BZr8yxiJm1HErb48pF2oi4fMsOcuYq0lITzYJRNy6PYzSfyFMML/fZBN9l3E6FVr3nYvmzio3xk/MrSax1aJQZlwSvUHLhVLLCA6/IEcFA7LHJ289Cw1oibHGiQyxLpHsHjX8FVt5GPh2bky5av9gyD/+J" Jul 21 19:41:15 volumio volumio[742]: info: Initializing connection to go-librespot Websocket Jul 21 19:41:15 volumio go-librespot[6704]: time="2024-07-21T19:41:15+02:00" level=debug msg="new websocket client" Jul 21 19:41:15 volumio volumio[742]: info: Connection to go-librespot Websocket established Jul 21 19:41:15 volumio go-librespot[6704]: time="2024-07-21T19:41:15+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jul 21 19:41:15 volumio go-librespot[6704]: time="2024-07-21T19:41:15+02:00" level=debug msg="completed keyexchange" Jul 21 19:41:16 volumio go-librespot[6704]: time="2024-07-21T19:41:16+02:00" level=debug msg="completed challenge" Jul 21 19:41:16 volumio go-librespot[6704]: time="2024-07-21T19:41:16+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 21 19:41:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 21 19:41:16 volumio volumio[742]: info: Connection to go-librespot Websocket closed Jul 21 19:41:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 21 19:41:18 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jul 21 19:41:18 volumio volumio[742]: info: CURURI: music-library/NAS/Muzyka_NAS/Bronski Beat Jul 21 19:41:18 volumio volumio[742]: info: Preload queue cleared Jul 21 19:41:18 volumio volumio[742]: info: Getting Spotify volume Jul 21 19:41:18 volumio volumio[742]: (node:742) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 21 19:41:18 volumio volumio[742]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jul 21 19:41:18 volumio volumio[742]: (node:742) 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: 8022) Jul 21 19:41:18 volumio volumio[742]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Jul 21 19:41:18 volumio volumio[742]: info: CoreCommandRouter::volumioGetState Jul 21 19:41:18 volumio volumio[742]: info: CorePlayQueue::getTrack 2 Jul 21 19:41:18 volumio volumio[742]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jul 21 19:41:18 volumio volumio[742]: info: CURURI: music-library/NAS/Muzyka_NAS/Bronski Beat/The Age of Consent Jul 21 19:41:19 volumio volumio[742]: info: Preload queue cleared Jul 21 19:41:19 volumio volumio[742]: info: Preloading song: music-library/NAS/Muzyka_NAS/Bronski Beat/The Age of Consent/05 Love and Money.flac Jul 21 19:41:19 volumio volumio[742]: info: Preloading song: music-library/NAS/Muzyka_NAS/Bronski Beat/The Age of Consent/11 I Feel Love (Medley with Marc Almond).flac Jul 21 19:41:19 volumio volumio[742]: info: Preloading song: music-library/NAS/Muzyka_NAS/Bronski Beat/The Age of Consent/13 Hard rain (Re-mix from 'Hundreds and Thousands').flac Jul 21 19:41:19 volumio volumio[742]: info: Preloading song: music-library/NAS/Muzyka_NAS/Bronski Beat/The Age of Consent/16 Heatwave (Re-mix from 'Hundreds and Thousands').flac Jul 21 19:41:19 volumio volumio[742]: info: Preloading song: music-library/NAS/Muzyka_NAS/Bronski Beat/The Age of Consent/The Age Of Consent JP.CUE Jul 21 19:41:19 volumio volumio[742]: info: Preloading song: music-library/NAS/Muzyka_NAS/Bronski Beat/The Age of Consent/The Age Of Consent.CUE Jul 21 19:41:19 volumio volumio[742]: info: Exploding uri music-library/NAS/Muzyka_NAS/Bronski Beat/The Age of Consent/05 Love and Money.flac in service mpd Jul 21 19:41:19 volumio volumio[742]: info: ALBUMART /albumart?cacheid=952&web=Bronski%20Beat/The%20Age%20of%20Consent/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FBronski%20Beat%2FThe%20Age%20of%20Consent%2F05%20Love%20and%20Money.flac&metadata=false Jul 21 19:41:19 volumio volumio[742]: info: URI /mnt/NAS/Muzyka_NAS/Bronski Beat/The Age of Consent/05 Love and Money.flac Jul 21 19:41:19 volumio volumio[742]: info: Exploding uri music-library/NAS/Muzyka_NAS/Bronski Beat/The Age of Consent/11 I Feel Love (Medley with Marc Almond).flac in service mpd Jul 21 19:41:19 volumio volumio[742]: info: ALBUMART /albumart?cacheid=952&web=Bronski%20Beat/The%20Age%20of%20Consent/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FBronski%20Beat%2FThe%20Age%20of%20Consent%2F11%20I%20Feel%20Love%20(Medley%20with%20Marc%20Almond).flac&metadata=false Jul 21 19:41:19 volumio volumio[742]: info: URI /mnt/NAS/Muzyka_NAS/Bronski Beat/The Age of Consent/11 I Feel Love (Medley with Marc Almond).flac Jul 21 19:41:19 volumio volumio[742]: info: Exploding uri music-library/NAS/Muzyka_NAS/Bronski Beat/The Age of Consent/13 Hard rain (Re-mix from 'Hundreds and Thousands').flac in service mpd Jul 21 19:41:19 volumio volumio[742]: info: ALBUMART /albumart?cacheid=952&web=Bronski%20Beat/The%20Age%20of%20Consent/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FBronski%20Beat%2FThe%20Age%20of%20Consent%2F13%20Hard%20rain%20(Re-mix%20from%20'Hundreds%20and%20Thousands').flac&metadata=false Jul 21 19:41:19 volumio volumio[742]: info: URI /mnt/NAS/Muzyka_NAS/Bronski Beat/The Age of Consent/13 Hard rain (Re-mix from 'Hundreds and Thousands').flac Jul 21 19:41:19 volumio volumio[742]: info: Exploding uri music-library/NAS/Muzyka_NAS/Bronski Beat/The Age of Consent/16 Heatwave (Re-mix from 'Hundreds and Thousands').flac in service mpd Jul 21 19:41:19 volumio volumio[742]: info: ALBUMART /albumart?cacheid=952&web=Bronski%20Beat/The%20Age%20of%20Consent/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FBronski%20Beat%2FThe%20Age%20of%20Consent%2F16%20Heatwave%20(Re-mix%20from%20'Hundreds%20and%20Thousands').flac&metadata=false Jul 21 19:41:19 volumio volumio[742]: info: URI /mnt/NAS/Muzyka_NAS/Bronski Beat/The Age of Consent/16 Heatwave (Re-mix from 'Hundreds and Thousands').flac Jul 21 19:41:19 volumio volumio[742]: info: Exploding uri music-library/NAS/Muzyka_NAS/Bronski Beat/The Age of Consent/The Age Of Consent JP.CUE in service mpd Jul 21 19:41:19 volumio volumio[742]: info: ALBUMART /albumart?cacheid=952&web=BRONSKI%20BEAT/The%20Age%20Of%20Consent%201996-BRONSKI%20BEAT/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FBronski%20Beat%2FThe%20Age%20of%20Consent%2FThe%20Age%20Of%20Consent%20JP.CUE&metadata=false Jul 21 19:41:19 volumio volumio[742]: info: URI /mnt/NAS/Muzyka_NAS/Bronski Beat/The Age of Consent/The Age Of Consent JP.CUE Jul 21 19:41:19 volumio volumio[742]: info: ALBUMART /albumart?cacheid=952&web=BRONSKI%20BEAT/The%20Age%20Of%20Consent%201996-BRONSKI%20BEAT/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FBronski%20Beat%2FThe%20Age%20of%20Consent%2FThe%20Age%20Of%20Consent%20JP.CUE&metadata=false Jul 21 19:41:19 volumio volumio[742]: info: URI /mnt/NAS/Muzyka_NAS/Bronski Beat/The Age of Consent/The Age Of Consent JP.CUE Jul 21 19:41:19 volumio volumio[742]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 21 19:41:19 volumio volumio[742]: Error: Unable to resolve or reject the same promise twice Jul 21 19:41:19 volumio volumio[742]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Jul 21 19:41:19 volumio volumio[742]: at /volumio/app/plugins/music_service/mpd/index.js:2568:21 Jul 21 19:41:19 volumio volumio[742]: at MpdClient.handleMessage (/volumio/app/plugins/music_service/mpd/lib/mpd.js:77:3) Jul 21 19:41:19 volumio volumio[742]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:68:12) Jul 21 19:41:19 volumio volumio[742]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12) Jul 21 19:41:19 volumio volumio[742]: at Socket.emit (events.js:315:20) Jul 21 19:41:19 volumio volumio[742]: at addChunk (internal/streams/readable.js:309:12) Jul 21 19:41:19 volumio volumio[742]: at readableAddChunk (internal/streams/readable.js:280:11) Jul 21 19:41:19 volumio volumio[742]: at Socket.Readable.push (internal/streams/readable.js:223:10) Jul 21 19:41:19 volumio volumio[742]: at Pipe.onStreamRead (internal/stream_base_commons.js:188:23) Jul 21 19:41:19 volumio volumio[742]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 21 19:41:19 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 21 19:41:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22503. Jul 21 19:41:19 volumio systemd[1]: Stopped go-librespot Daemon. Jul 21 19:41:19 volumio systemd[1]: Started go-librespot Daemon. Jul 21 19:41:19 volumio go-librespot[6728]: Librespot-go daemon starting... Jul 21 19:41:19 volumio go-librespot[6728]: time="2024-07-21T19:41:19+02:00" level=info msg="generated new device id: 4aa67f86cc6238aca5bb83f29aa51a8e212bed23" Jul 21 19:41:19 volumio go-librespot[6728]: time="2024-07-21T19:41:19+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" Jul 21 19:41:19 volumio sudo[6737]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-07-21 19:40 Jul 21 19:41:19 volumio sudo[6737]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="e7445fab547cd22e23d9bef72406cfb610bc1d7d" VOLUMIO_FE_VERSION="5d5e99f8f803b3ec5fc5e8ca13bb4023600f3eee" VOLUMIO_FE3_VERSION="a6ae210575eae1ff43f06ab71e1cd17576840623" VOLUMIO_BE_VERSION="a9e1e1dd6072ffb15c0fcb8938d9ea0d8900c0da" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 24 Apr 2024 02:10:14 PM CEST" VOLUMIO_VERSION="3.661" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5bdefd4af4423fd17aacb83a8538bf1f"