-- Logs begin at Sun 2024-10-13 09:56:04 CST, end at Sun 2024-10-13 12:08:41 CST. -- Oct 13 12:07:00 player go-librespot[12002]: time="2024-10-13T12:07:00+08:00" level=info msg="connected to ap-gae2.spotify.com:443" Oct 13 12:07:00 player go-librespot[12002]: time="2024-10-13T12:07:00+08:00" level=debug msg="completed keyexchange" Oct 13 12:07:00 player go-librespot[12002]: time="2024-10-13T12:07:00+08:00" level=debug msg="completed challenge" Oct 13 12:07:00 player go-librespot[12002]: time="2024-10-13T12:07:00+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 13 12:07:00 player systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 13 12:07:00 player volumio[6293]: info: Connection to go-librespot Websocket closed Oct 13 12:07:00 player systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 13 12:07:01 player volumio[6293]: info: Getting Spotify volume Oct 13 12:07:01 player volumio[6293]: (node:6293) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 13 12:07:01 player volumio[6293]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Oct 13 12:07:01 player volumio[6293]: (node:6293) 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: 1050) Oct 13 12:07:01 player volumio[6293]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Oct 13 12:07:01 player volumio[6293]: info: CoreCommandRouter::volumioGetState Oct 13 12:07:01 player volumio[6293]: info: CorePlayQueue::getTrack 9 Oct 13 12:07:01 player volumio[6293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Oct 13 12:07:03 player volumio[6293]: info: Initializing connection to go-librespot Websocket Oct 13 12:07:03 player volumio[6293]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 13 12:07:03 player systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 13 12:07:03 player systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2197. Oct 13 12:07:03 player systemd[1]: Stopped go-librespot Daemon. Oct 13 12:07:03 player systemd[1]: Started go-librespot Daemon. Oct 13 12:07:03 player go-librespot[12010]: Librespot-go daemon starting... Oct 13 12:07:03 player go-librespot[12010]: time="2024-10-13T12:07:03+08:00" level=info msg="generated new device id: 7fbd9bfcb37833c00a77bbc534953969010b2cdd" Oct 13 12:07:03 player go-librespot[12010]: time="2024-10-13T12:07:03+08:00" level=debug msg="stored credentials not found" Oct 13 12:07:04 player go-librespot[12010]: time="2024-10-13T12:07:04+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Oct 13 12:07:04 player go-librespot[12010]: time="2024-10-13T12:07:04+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 13 12:07:04 player go-librespot[12010]: time="2024-10-13T12:07:04+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 13 12:07:04 player go-librespot[12010]: time="2024-10-13T12:07:04+08:00" level=debug msg="zeroconf server listening on port 46793" Oct 13 12:07:05 player go-librespot[12010]: time="2024-10-13T12:07:05+08:00" level=debug msg="obtained new client token: AABezdVOZrcaBtkWKaIj2qpS1gHnh3QBqJ0tM+cFj3XbpdqYraIHWlWPTLNeYma59vAscVRBr3vUheGqIqUd68vJtRecb17NR7UGbN025azHmuZWyOjEH4At85aBH3am65rpqfis5O7tfc20F3Ffc+RWzq68yPL+u2bXOQiWQBsNS7GiXa/JaB5/61xc8FSIyBgM8/0mPSMa9Oad4V8iCsgjyeN+EjgR6pimi8OQKfql/cjqhsA+FVzF7Ci17NND" Oct 13 12:07:05 player go-librespot[12010]: time="2024-10-13T12:07:05+08:00" level=info msg="connected to ap-gae2.spotify.com:4070" Oct 13 12:07:05 player go-librespot[12010]: time="2024-10-13T12:07:05+08:00" level=debug msg="completed keyexchange" Oct 13 12:07:06 player go-librespot[12010]: time="2024-10-13T12:07:06+08:00" level=debug msg="completed challenge" Oct 13 12:07:06 player go-librespot[12010]: time="2024-10-13T12:07:06+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 13 12:07:06 player systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 13 12:07:06 player systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 13 12:07:06 player volumio[6293]: info: Initializing connection to go-librespot Websocket Oct 13 12:07:06 player volumio[6293]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 13 12:07:09 player systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 13 12:07:09 player systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2198. Oct 13 12:07:09 player systemd[1]: Stopped go-librespot Daemon. Oct 13 12:07:09 player systemd[1]: Started go-librespot Daemon. Oct 13 12:07:09 player go-librespot[12019]: Librespot-go daemon starting... Oct 13 12:07:09 player go-librespot[12019]: time="2024-10-13T12:07:09+08:00" level=info msg="generated new device id: 47096ab89748f948ddf1a42ea21105a48a4a9768" Oct 13 12:07:09 player go-librespot[12019]: time="2024-10-13T12:07:09+08:00" level=debug msg="stored credentials not found" Oct 13 12:07:09 player volumio[6293]: info: Initializing connection to go-librespot Websocket Oct 13 12:07:09 player go-librespot[12019]: time="2024-10-13T12:07:09+08:00" level=debug msg="new websocket client" Oct 13 12:07:09 player volumio[6293]: info: Connection to go-librespot Websocket established Oct 13 12:07:10 player go-librespot[12019]: time="2024-10-13T12:07:10+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 13 12:07:10 player go-librespot[12019]: time="2024-10-13T12:07:10+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 13 12:07:10 player go-librespot[12019]: time="2024-10-13T12:07:10+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 13 12:07:10 player go-librespot[12019]: time="2024-10-13T12:07:10+08:00" level=debug msg="zeroconf server listening on port 41797" Oct 13 12:07:11 player go-librespot[12019]: time="2024-10-13T12:07:11+08:00" level=debug msg="obtained new client token: AAAGPKZRY6Kdqd7+yR40S880bC592QIh6S8+Y9hE9dg06s28yeV/w4rq8VAinYJRzJyx6PRJJvcJMyAGI0V7nbEFfuA7+3Q2XmeRbuVJQswGUiDxybfVX9L8gzjqQjhZ+dkwHVoA/x4xHTUm6h4/NywklPTAukfOUa5nUROFdVGnl1+IaCU03DAt49Td46LGGLxrGa8CsTxEtoKM3Ry6N2RelBoO+c2iC5YWTMe/areN5ZcFz9Dg5JLk5poquw==" Oct 13 12:07:11 player go-librespot[12019]: time="2024-10-13T12:07:11+08:00" level=info msg="connected to ap-gae2.spotify.com:4070" Oct 13 12:07:11 player go-librespot[12019]: time="2024-10-13T12:07:11+08:00" level=debug msg="completed keyexchange" Oct 13 12:07:11 player go-librespot[12019]: time="2024-10-13T12:07:11+08:00" level=debug msg="completed challenge" Oct 13 12:07:11 player go-librespot[12019]: time="2024-10-13T12:07:11+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 13 12:07:11 player systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 13 12:07:11 player volumio[6293]: info: Connection to go-librespot Websocket closed Oct 13 12:07:11 player systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 13 12:07:12 player volumio[6293]: info: Getting Spotify volume Oct 13 12:07:12 player volumio[6293]: (node:6293) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 13 12:07:12 player volumio[6293]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Oct 13 12:07:12 player volumio[6293]: (node:6293) 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: 1051) Oct 13 12:07:12 player volumio[6293]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Oct 13 12:07:12 player volumio[6293]: info: CoreCommandRouter::volumioGetState Oct 13 12:07:12 player volumio[6293]: info: CorePlayQueue::getTrack 9 Oct 13 12:07:12 player volumio[6293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Oct 13 12:07:14 player volumio[6293]: info: Initializing connection to go-librespot Websocket Oct 13 12:07:14 player volumio[6293]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 13 12:07:15 player systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 13 12:07:15 player systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2199. Oct 13 12:07:15 player systemd[1]: Stopped go-librespot Daemon. Oct 13 12:07:15 player systemd[1]: Started go-librespot Daemon. Oct 13 12:07:15 player go-librespot[12072]: Librespot-go daemon starting... Oct 13 12:07:15 player go-librespot[12072]: time="2024-10-13T12:07:15+08:00" level=info msg="generated new device id: 92c1fa48bad398a8b90051fbba76cf90b11527f9" Oct 13 12:07:15 player go-librespot[12072]: time="2024-10-13T12:07:15+08:00" level=debug msg="stored credentials not found" Oct 13 12:07:15 player go-librespot[12072]: time="2024-10-13T12:07:15+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Oct 13 12:07:15 player go-librespot[12072]: time="2024-10-13T12:07:15+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 13 12:07:15 player go-librespot[12072]: time="2024-10-13T12:07:15+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 13 12:07:15 player go-librespot[12072]: time="2024-10-13T12:07:15+08:00" level=debug msg="zeroconf server listening on port 33637" Oct 13 12:07:16 player go-librespot[12072]: time="2024-10-13T12:07:16+08:00" level=debug msg="obtained new client token: AACn0dwPecRln+zUAcnkfd8+4XNIDWM5do5cAVrO5wpgXX2/KEQSf3khqVl1cOchAIvIJiawzM4VeeyyzTMWj5EDcI5NW1E3vFvxJIJ06IbsgOgFzFqd+V9nG8zBxO+46zU0AU+4aZQ4zJ8OVYR9i3Jux2KvrYBmCboIgAmFYvUkesExnAGfZthm+KlIQ3j3KU9qfmtGGrqDaoCRuWFIEVJOlc+EloSFoFy2PDBr1tFGKmNVCJnNqNSCrfbynfQV" Oct 13 12:07:16 player go-librespot[12072]: time="2024-10-13T12:07:16+08:00" level=info msg="connected to ap-gae2.spotify.com:4070" Oct 13 12:07:16 player go-librespot[12072]: time="2024-10-13T12:07:16+08:00" level=debug msg="completed keyexchange" Oct 13 12:07:17 player go-librespot[12072]: time="2024-10-13T12:07:17+08:00" level=debug msg="completed challenge" Oct 13 12:07:17 player go-librespot[12072]: time="2024-10-13T12:07:17+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 13 12:07:17 player systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 13 12:07:17 player systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 13 12:07:17 player volumio[6293]: info: Initializing connection to go-librespot Websocket Oct 13 12:07:17 player volumio[6293]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 13 12:07:20 player systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 13 12:07:20 player systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2200. Oct 13 12:07:20 player systemd[1]: Stopped go-librespot Daemon. Oct 13 12:07:20 player systemd[1]: Started go-librespot Daemon. Oct 13 12:07:20 player go-librespot[12080]: Librespot-go daemon starting... Oct 13 12:07:20 player go-librespot[12080]: time="2024-10-13T12:07:20+08:00" level=info msg="generated new device id: ff6d33c1a2899ef7c0a1d55985e7336a276332ce" Oct 13 12:07:20 player go-librespot[12080]: time="2024-10-13T12:07:20+08:00" level=debug msg="stored credentials not found" Oct 13 12:07:20 player volumio[6293]: info: Initializing connection to go-librespot Websocket Oct 13 12:07:20 player go-librespot[12080]: time="2024-10-13T12:07:20+08:00" level=debug msg="new websocket client" Oct 13 12:07:20 player volumio[6293]: info: Connection to go-librespot Websocket established Oct 13 12:07:21 player go-librespot[12080]: time="2024-10-13T12:07:21+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 13 12:07:21 player go-librespot[12080]: time="2024-10-13T12:07:21+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 13 12:07:21 player go-librespot[12080]: time="2024-10-13T12:07:21+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 13 12:07:21 player go-librespot[12080]: time="2024-10-13T12:07:21+08:00" level=debug msg="zeroconf server listening on port 35307" Oct 13 12:07:22 player go-librespot[12080]: time="2024-10-13T12:07:22+08:00" level=debug msg="obtained new client token: AAAkta4R2WFRqog6JYl/P9RNih+EmHO/dZrRQ+HjLOpDxPwO4P0xde737eTTpPe/uK3RzBS64KRADZTe4tEhZoANYuO+uNNggGoUzuiJX1yQNEErbIGywYnyWxyy2/C2hkWrV+UxzvyR4tz8WcpJ88CDNt/u6T8nZRXp0GGkNKF3a/xhxZQCK7MzK/zFRDwSvJl8NEifyrC2Tf1Jfg5KceCee3shz2EmAt/IqU49ylh4JIG+l8uIN9JaB5Pg4g==" Oct 13 12:07:22 player go-librespot[12080]: time="2024-10-13T12:07:22+08:00" level=info msg="connected to ap-gae2.spotify.com:4070" Oct 13 12:07:22 player go-librespot[12080]: time="2024-10-13T12:07:22+08:00" level=debug msg="completed keyexchange" Oct 13 12:07:22 player go-librespot[12080]: time="2024-10-13T12:07:22+08:00" level=debug msg="completed challenge" Oct 13 12:07:22 player go-librespot[12080]: time="2024-10-13T12:07:22+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 13 12:07:22 player systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 13 12:07:22 player systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 13 12:07:22 player volumio[6293]: info: Connection to go-librespot Websocket closed Oct 13 12:07:23 player volumio[6293]: info: Getting Spotify volume Oct 13 12:07:23 player volumio[6293]: (node:6293) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 13 12:07:23 player volumio[6293]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Oct 13 12:07:23 player volumio[6293]: (node:6293) 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: 1052) Oct 13 12:07:24 player volumio[6293]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Oct 13 12:07:24 player volumio[6293]: info: CoreCommandRouter::volumioGetState Oct 13 12:07:24 player volumio[6293]: info: CorePlayQueue::getTrack 9 Oct 13 12:07:24 player volumio[6293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Oct 13 12:07:25 player volumio[6293]: info: Initializing connection to go-librespot Websocket Oct 13 12:07:25 player volumio[6293]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 13 12:07:26 player systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 13 12:07:26 player systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2201. Oct 13 12:07:26 player systemd[1]: Stopped go-librespot Daemon. Oct 13 12:07:26 player systemd[1]: Started go-librespot Daemon. Oct 13 12:07:26 player go-librespot[12089]: Librespot-go daemon starting... Oct 13 12:07:26 player go-librespot[12089]: time="2024-10-13T12:07:26+08:00" level=info msg="generated new device id: 77070f09cb8ec84f234c3f36a96a0b50bd855a62" Oct 13 12:07:26 player go-librespot[12089]: time="2024-10-13T12:07:26+08:00" level=debug msg="stored credentials not found" Oct 13 12:07:27 player go-librespot[12089]: time="2024-10-13T12:07:27+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Oct 13 12:07:27 player go-librespot[12089]: time="2024-10-13T12:07:27+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 13 12:07:27 player go-librespot[12089]: time="2024-10-13T12:07:27+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 13 12:07:27 player go-librespot[12089]: time="2024-10-13T12:07:27+08:00" level=debug msg="zeroconf server listening on port 42089" Oct 13 12:07:27 player go-librespot[12089]: time="2024-10-13T12:07:27+08:00" level=debug msg="obtained new client token: AABg/B9Q8Bs6upkLCjut7omzagXotAjApAv316ydF7HLLfYwB05XNsYLPYslbChmbZf2cdQ3ZywM6twdJHMAS2ylnboPZQNuekGlYLeaRcMXPIgwKhbSnXX1t2BatdKHZe2wC8IrTSWVyF134aFsQIRNJzz7xB6pslDXod7pgBN7OSnOKA8v2wCbRmqvGTKtLl1MVeCU4vArvjP5vZI08N2MutCBg9aRUMen+HLQ6tGRUejb5HgAshCt2VESUocH" Oct 13 12:07:27 player go-librespot[12089]: time="2024-10-13T12:07:27+08:00" level=info msg="connected to ap-gae2.spotify.com:4070" Oct 13 12:07:27 player go-librespot[12089]: time="2024-10-13T12:07:27+08:00" level=debug msg="completed keyexchange" Oct 13 12:07:28 player go-librespot[12089]: time="2024-10-13T12:07:28+08:00" level=debug msg="completed challenge" Oct 13 12:07:28 player go-librespot[12089]: time="2024-10-13T12:07:28+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 13 12:07:28 player systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 13 12:07:28 player systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 13 12:07:28 player volumio[6293]: info: Initializing connection to go-librespot Websocket Oct 13 12:07:28 player volumio[6293]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 13 12:07:31 player systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 13 12:07:31 player systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2202. Oct 13 12:07:31 player systemd[1]: Stopped go-librespot Daemon. Oct 13 12:07:31 player systemd[1]: Started go-librespot Daemon. Oct 13 12:07:31 player go-librespot[12097]: Librespot-go daemon starting... Oct 13 12:07:31 player go-librespot[12097]: time="2024-10-13T12:07:31+08:00" level=info msg="generated new device id: 1012d9d7c445f5943670604f7ae555de313ea991" Oct 13 12:07:31 player go-librespot[12097]: time="2024-10-13T12:07:31+08:00" level=debug msg="stored credentials not found" Oct 13 12:07:31 player volumio[6293]: info: Initializing connection to go-librespot Websocket Oct 13 12:07:32 player go-librespot[12097]: time="2024-10-13T12:07:31+08:00" level=debug msg="new websocket client" Oct 13 12:07:32 player volumio[6293]: info: Connection to go-librespot Websocket established Oct 13 12:07:32 player go-librespot[12097]: time="2024-10-13T12:07:32+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 13 12:07:32 player go-librespot[12097]: time="2024-10-13T12:07:32+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 13 12:07:32 player go-librespot[12097]: time="2024-10-13T12:07:32+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 13 12:07:32 player go-librespot[12097]: time="2024-10-13T12:07:32+08:00" level=debug msg="zeroconf server listening on port 40093" Oct 13 12:07:33 player go-librespot[12097]: time="2024-10-13T12:07:33+08:00" level=debug msg="obtained new client token: AADPPI27DxMqqnTTNTJujaC5NkF5+LD8DI+3dsBU15KRA40RvPF5F7NeRu750mpUlF2Ge48TkQpP9jMyvaRhL3hQEEyHSVBpw4q5Di1M0jfVK8YA90juRm7QvReKyAoOxMhFtkXlgp1UM//HpWOhJPNpaCLeqLFwKvCl92Sdn+qiNAtP+RohDSfRkUJEyuYUahdF7Wx7K7J10N8HSO0iOmJhdCBDScbUuadKS5dBvFwH8W1h+PvqMkjoqobyIA==" Oct 13 12:07:33 player go-librespot[12097]: time="2024-10-13T12:07:33+08:00" level=info msg="connected to ap-gae2.spotify.com:4070" Oct 13 12:07:33 player go-librespot[12097]: time="2024-10-13T12:07:33+08:00" level=debug msg="completed keyexchange" Oct 13 12:07:34 player go-librespot[12097]: time="2024-10-13T12:07:34+08:00" level=debug msg="completed challenge" Oct 13 12:07:34 player go-librespot[12097]: time="2024-10-13T12:07:34+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 13 12:07:34 player systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 13 12:07:34 player volumio[6293]: info: Connection to go-librespot Websocket closed Oct 13 12:07:34 player systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 13 12:07:35 player volumio[6293]: info: Getting Spotify volume Oct 13 12:07:35 player volumio[6293]: (node:6293) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 13 12:07:35 player volumio[6293]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Oct 13 12:07:35 player volumio[6293]: (node:6293) 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: 1053) Oct 13 12:07:35 player volumio[6293]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Oct 13 12:07:35 player volumio[6293]: info: CoreCommandRouter::volumioGetState Oct 13 12:07:35 player volumio[6293]: info: CorePlayQueue::getTrack 9 Oct 13 12:07:35 player volumio[6293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Oct 13 12:07:37 player volumio[6293]: info: Initializing connection to go-librespot Websocket Oct 13 12:07:37 player volumio[6293]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 13 12:07:37 player systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 13 12:07:37 player systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2203. Oct 13 12:07:37 player systemd[1]: Stopped go-librespot Daemon. Oct 13 12:07:37 player systemd[1]: Started go-librespot Daemon. Oct 13 12:07:37 player go-librespot[12105]: Librespot-go daemon starting... Oct 13 12:07:37 player go-librespot[12105]: time="2024-10-13T12:07:37+08:00" level=info msg="generated new device id: 46c10a98e121c68758cf5061ff6a66fb66dc21df" Oct 13 12:07:37 player go-librespot[12105]: time="2024-10-13T12:07:37+08:00" level=debug msg="stored credentials not found" Oct 13 12:07:38 player go-librespot[12105]: time="2024-10-13T12:07:38+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 13 12:07:38 player go-librespot[12105]: time="2024-10-13T12:07:38+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 13 12:07:38 player go-librespot[12105]: time="2024-10-13T12:07:38+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 13 12:07:38 player go-librespot[12105]: time="2024-10-13T12:07:38+08:00" level=debug msg="zeroconf server listening on port 42767" Oct 13 12:07:38 player go-librespot[12105]: time="2024-10-13T12:07:38+08:00" level=debug msg="obtained new client token: AAD8U0+nF69uthDUe8QhIrkfphlqVWciqRcihuzv71X7BtP5c58+no6+AVFsIF2Z8RrkujpEax1UeP1SPv4rU9/crVjqFuRzaZo3o5ww1ULtxPH3lQ99IDdwLNQu3RQ9OcjJO+AVobtNyK62FdgXOyAU10cZHYlDREsL5kt+vrY3ekTtfKMmPKdhqJFqQGNxz7WjqWidSNr6YYOYMzQeOIen8BTgg2y5smiaIB7nDrNTwgvrkek1bYf/NyBzAaqY" Oct 13 12:07:39 player go-librespot[12105]: time="2024-10-13T12:07:39+08:00" level=info msg="connected to ap-gae2.spotify.com:4070" Oct 13 12:07:39 player go-librespot[12105]: time="2024-10-13T12:07:39+08:00" level=debug msg="completed keyexchange" Oct 13 12:07:39 player go-librespot[12105]: time="2024-10-13T12:07:39+08:00" level=debug msg="completed challenge" Oct 13 12:07:39 player go-librespot[12105]: time="2024-10-13T12:07:39+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 13 12:07:39 player systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 13 12:07:39 player systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 13 12:07:40 player volumio[6293]: info: Initializing connection to go-librespot Websocket Oct 13 12:07:40 player volumio[6293]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 13 12:07:42 player systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 13 12:07:42 player systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2204. Oct 13 12:07:42 player systemd[1]: Stopped go-librespot Daemon. Oct 13 12:07:42 player systemd[1]: Started go-librespot Daemon. Oct 13 12:07:42 player go-librespot[12114]: Librespot-go daemon starting... Oct 13 12:07:42 player go-librespot[12114]: time="2024-10-13T12:07:42+08:00" level=info msg="generated new device id: e0e8b73f670895b5e9e56dcb550e92554283bb2d" Oct 13 12:07:42 player go-librespot[12114]: time="2024-10-13T12:07:42+08:00" level=debug msg="stored credentials not found" Oct 13 12:07:43 player volumio[6293]: info: Initializing connection to go-librespot Websocket Oct 13 12:07:43 player go-librespot[12114]: time="2024-10-13T12:07:43+08:00" level=debug msg="new websocket client" Oct 13 12:07:43 player volumio[6293]: info: Connection to go-librespot Websocket established Oct 13 12:07:43 player go-librespot[12114]: time="2024-10-13T12:07:43+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 13 12:07:43 player go-librespot[12114]: time="2024-10-13T12:07:43+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 13 12:07:43 player go-librespot[12114]: time="2024-10-13T12:07:43+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 13 12:07:43 player go-librespot[12114]: time="2024-10-13T12:07:43+08:00" level=debug msg="zeroconf server listening on port 33345" Oct 13 12:07:44 player go-librespot[12114]: time="2024-10-13T12:07:44+08:00" level=debug msg="obtained new client token: AAAr/IUwjqT05bAIWncwGPFSdECrz2JXim9aukIjcHjmTC1r4zQuTDAe0znPnOf4wH1AnQ+/3CfCkG+3L/d8aHCjopdmjey2QvPpvx66RslHNXr4fQNsRjxoUpEKfvrDiTdo3ihramUiE+HYtIEJUtcayMgKmXr11yL8SE+/f1iPq7L3m3G69POuUga8pN2Vb2d8uDD4E7DSc+k55AR4krqM2wwc/7+B0N3pBFt7/H7kkRR7XxEKsTz7T5gmhhJj" Oct 13 12:07:44 player go-librespot[12114]: time="2024-10-13T12:07:44+08:00" level=info msg="connected to ap-gae2.spotify.com:4070" Oct 13 12:07:44 player go-librespot[12114]: time="2024-10-13T12:07:44+08:00" level=debug msg="completed keyexchange" Oct 13 12:07:45 player go-librespot[12114]: time="2024-10-13T12:07:45+08:00" level=debug msg="completed challenge" Oct 13 12:07:45 player go-librespot[12114]: time="2024-10-13T12:07:45+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 13 12:07:45 player systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 13 12:07:45 player systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 13 12:07:45 player volumio[6293]: info: Connection to go-librespot Websocket closed Oct 13 12:07:46 player volumio[6293]: info: Getting Spotify volume Oct 13 12:07:46 player volumio[6293]: (node:6293) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 13 12:07:46 player volumio[6293]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Oct 13 12:07:46 player volumio[6293]: (node:6293) 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: 1054) Oct 13 12:07:46 player volumio[6293]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Oct 13 12:07:46 player volumio[6293]: info: CoreCommandRouter::volumioGetState Oct 13 12:07:46 player volumio[6293]: info: CorePlayQueue::getTrack 9 Oct 13 12:07:46 player volumio[6293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Oct 13 12:07:48 player volumio[6293]: info: Initializing connection to go-librespot Websocket Oct 13 12:07:48 player volumio[6293]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 13 12:07:48 player systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 13 12:07:48 player systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2205. Oct 13 12:07:48 player systemd[1]: Stopped go-librespot Daemon. Oct 13 12:07:48 player systemd[1]: Started go-librespot Daemon. Oct 13 12:07:48 player go-librespot[12122]: Librespot-go daemon starting... Oct 13 12:07:48 player go-librespot[12122]: time="2024-10-13T12:07:48+08:00" level=info msg="generated new device id: e392f31d101fdd6f96f55bf0e53e6b8f69d44228" Oct 13 12:07:48 player go-librespot[12122]: time="2024-10-13T12:07:48+08:00" level=debug msg="stored credentials not found" Oct 13 12:07:49 player go-librespot[12122]: time="2024-10-13T12:07:49+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 13 12:07:49 player go-librespot[12122]: time="2024-10-13T12:07:49+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 13 12:07:49 player go-librespot[12122]: time="2024-10-13T12:07:49+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 13 12:07:49 player go-librespot[12122]: time="2024-10-13T12:07:49+08:00" level=debug msg="zeroconf server listening on port 37453" Oct 13 12:07:50 player go-librespot[12122]: time="2024-10-13T12:07:50+08:00" level=debug msg="obtained new client token: AAAnWdv2mCXYUcJwQXnbQCRNqnzsHK0FuZZN7QJcVv17Qx/E0aqNBZQD3PHrnH2nj1f1XntoFs23NBpjQG/k4V7k8kfmeBPdCLD315paAUH/HO1QqrbGo2OEMtaViZ53yfjl9G2fKqenLDwoKeir05y3guCa6BUxOinPlkwRO1/CNOaM7FPQXKkUeJGZDpcKTO/mkALbcC37Ny/C37qB6d4P4adH+YGpnfRoU+6Y+uvj0kTB7NVLOKSYXIM8vEq5" Oct 13 12:07:50 player go-librespot[12122]: time="2024-10-13T12:07:50+08:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070 (error: dial tcp 104.199.241.202:4070: connect: connection refused), retrying with a different AP" Oct 13 12:07:50 player go-librespot[12122]: time="2024-10-13T12:07:50+08:00" level=info msg="connected to ap-gae2.spotify.com:443" Oct 13 12:07:50 player go-librespot[12122]: time="2024-10-13T12:07:50+08:00" level=debug msg="completed keyexchange" Oct 13 12:07:50 player go-librespot[12122]: time="2024-10-13T12:07:50+08:00" level=debug msg="completed challenge" Oct 13 12:07:51 player go-librespot[12122]: time="2024-10-13T12:07:51+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 13 12:07:51 player systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 13 12:07:51 player systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 13 12:07:51 player volumio[6293]: info: Initializing connection to go-librespot Websocket Oct 13 12:07:51 player volumio[6293]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 13 12:07:54 player systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 13 12:07:54 player systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2206. Oct 13 12:07:54 player systemd[1]: Stopped go-librespot Daemon. Oct 13 12:07:54 player systemd[1]: Started go-librespot Daemon. Oct 13 12:07:54 player go-librespot[12131]: Librespot-go daemon starting... Oct 13 12:07:54 player go-librespot[12131]: time="2024-10-13T12:07:54+08:00" level=info msg="generated new device id: 8f0df75e2891641374290c65c793953fe63069a3" Oct 13 12:07:54 player go-librespot[12131]: time="2024-10-13T12:07:54+08:00" level=debug msg="stored credentials not found" Oct 13 12:07:54 player volumio[6293]: info: Initializing connection to go-librespot Websocket Oct 13 12:07:54 player go-librespot[12131]: time="2024-10-13T12:07:54+08:00" level=debug msg="new websocket client" Oct 13 12:07:54 player volumio[6293]: info: Connection to go-librespot Websocket established Oct 13 12:07:55 player go-librespot[12131]: time="2024-10-13T12:07:55+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 13 12:07:55 player go-librespot[12131]: time="2024-10-13T12:07:55+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 13 12:07:55 player go-librespot[12131]: time="2024-10-13T12:07:55+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 13 12:07:55 player go-librespot[12131]: time="2024-10-13T12:07:55+08:00" level=debug msg="zeroconf server listening on port 39717" Oct 13 12:07:55 player go-librespot[12131]: time="2024-10-13T12:07:55+08:00" level=debug msg="obtained new client token: AABE0PhbZO6cYFuD92Rwx8SSVnHjJMlbvEBOyuTAmzecINyliu3ZCg/a5+14DkUsAIr8BUKdySj/MkJ1IyN9UIVmNFjGCOYmXsS4/PV+hk6UqvYyHLZHbZIHTH59eCpNSbXb2GTEApNr9phg2XRNPIKiSagGlaORRroA9qK1TDe+BcxPzGUtn7H4Yo1mDWO6zv4E9mLjYqckmbxHrrfMHh5IbpiZkclGPGmLaZosFyOO8sOMI/xpm4IAt+/Ao3GQ" Oct 13 12:07:55 player go-librespot[12131]: time="2024-10-13T12:07:55+08:00" level=info msg="connected to ap-gae2.spotify.com:4070" Oct 13 12:07:55 player go-librespot[12131]: time="2024-10-13T12:07:55+08:00" level=debug msg="completed keyexchange" Oct 13 12:07:56 player go-librespot[12131]: time="2024-10-13T12:07:56+08:00" level=debug msg="completed challenge" Oct 13 12:07:56 player go-librespot[12131]: time="2024-10-13T12:07:56+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 13 12:07:56 player systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 13 12:07:56 player systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 13 12:07:56 player volumio[6293]: info: Connection to go-librespot Websocket closed Oct 13 12:07:57 player volumio[6293]: info: Getting Spotify volume Oct 13 12:07:57 player volumio[6293]: (node:6293) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 13 12:07:57 player volumio[6293]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Oct 13 12:07:57 player volumio[6293]: (node:6293) 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: 1055) Oct 13 12:07:57 player volumio[6293]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Oct 13 12:07:57 player volumio[6293]: info: CoreCommandRouter::volumioGetState Oct 13 12:07:57 player volumio[6293]: info: CorePlayQueue::getTrack 9 Oct 13 12:07:57 player volumio[6293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Oct 13 12:07:59 player volumio[6293]: info: Initializing connection to go-librespot Websocket Oct 13 12:07:59 player volumio[6293]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 13 12:07:59 player systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 13 12:07:59 player systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2207. Oct 13 12:07:59 player systemd[1]: Stopped go-librespot Daemon. Oct 13 12:07:59 player systemd[1]: Started go-librespot Daemon. Oct 13 12:07:59 player go-librespot[12140]: Librespot-go daemon starting... Oct 13 12:07:59 player go-librespot[12140]: time="2024-10-13T12:07:59+08:00" level=info msg="generated new device id: f6376a87e747616294b1a1f533eac3e83a1b8fdc" Oct 13 12:07:59 player go-librespot[12140]: time="2024-10-13T12:07:59+08:00" level=debug msg="stored credentials not found" Oct 13 12:08:00 player go-librespot[12140]: time="2024-10-13T12:08:00+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 13 12:08:00 player go-librespot[12140]: time="2024-10-13T12:08:00+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 13 12:08:00 player go-librespot[12140]: time="2024-10-13T12:08:00+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 13 12:08:00 player go-librespot[12140]: time="2024-10-13T12:08:00+08:00" level=debug msg="zeroconf server listening on port 43291" Oct 13 12:08:01 player go-librespot[12140]: time="2024-10-13T12:08:01+08:00" level=debug msg="obtained new client token: AAA/5Xv9O8XqQ6CNC45nloxgB7Sx68oiopxjEBcJ4BS1HWANmyr2NBINjlL8RH7mDPaCUOhkZqGdl1R3E3o7U+hdVoNFg/30GgQZdsFIovTJXte05pjx7dhTzd8WBVya/5utE0+50/qEOdYbanVaxR7wa0sQSsF5VyEsvEPQjrILI8iLw504rI6klbT9yj1946vf6Keb2WpmJnWwoLSZsxui5t2vopfCSP9fwyoqyob7CHBt7DSJHOiYEqbkZO/c" Oct 13 12:08:01 player go-librespot[12140]: time="2024-10-13T12:08:01+08:00" level=info msg="connected to ap-gae2.spotify.com:4070" Oct 13 12:08:01 player go-librespot[12140]: time="2024-10-13T12:08:01+08:00" level=debug msg="completed keyexchange" Oct 13 12:08:02 player go-librespot[12140]: time="2024-10-13T12:08:02+08:00" level=debug msg="completed challenge" Oct 13 12:08:02 player go-librespot[12140]: time="2024-10-13T12:08:02+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 13 12:08:02 player systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 13 12:08:02 player systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 13 12:08:02 player volumio[6293]: info: Initializing connection to go-librespot Websocket Oct 13 12:08:02 player volumio[6293]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 13 12:08:05 player systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 13 12:08:05 player systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2208. Oct 13 12:08:05 player systemd[1]: Stopped go-librespot Daemon. Oct 13 12:08:05 player systemd[1]: Started go-librespot Daemon. Oct 13 12:08:05 player go-librespot[12150]: Librespot-go daemon starting... Oct 13 12:08:05 player go-librespot[12150]: time="2024-10-13T12:08:05+08:00" level=info msg="generated new device id: f2eb88d11a2c23254293f0167aac81b87dd01f52" Oct 13 12:08:05 player go-librespot[12150]: time="2024-10-13T12:08:05+08:00" level=debug msg="stored credentials not found" Oct 13 12:08:05 player volumio[6293]: info: Initializing connection to go-librespot Websocket Oct 13 12:08:05 player go-librespot[12150]: time="2024-10-13T12:08:05+08:00" level=debug msg="new websocket client" Oct 13 12:08:05 player volumio[6293]: info: Connection to go-librespot Websocket established Oct 13 12:08:06 player volumio[6293]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 13 12:08:06 player volumio[6293]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 13 12:08:06 player volumio[6293]: info: Discovery: Getting this device information Oct 13 12:08:06 player volumio[6293]: info: CoreCommandRouter::volumioGetState Oct 13 12:08:06 player volumio[6293]: info: CorePlayQueue::getTrack 9 Oct 13 12:08:06 player volumio[6293]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 13 12:08:06 player volumio[6293]: verbose: New Socket.io Connection to 192.168.74.147:3000 from 192.168.74.67 UA: Dart/3.4 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Oct 13 12:08:06 player volumio[6293]: info: CoreCommandRouter::volumioGetState Oct 13 12:08:06 player volumio[6293]: info: CorePlayQueue::getTrack 9 Oct 13 12:08:06 player volumio[6293]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 13 12:08:06 player volumio[6293]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 13 12:08:06 player go-librespot[12150]: time="2024-10-13T12:08:06+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Oct 13 12:08:06 player go-librespot[12150]: time="2024-10-13T12:08:06+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 13 12:08:06 player go-librespot[12150]: time="2024-10-13T12:08:06+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 13 12:08:06 player go-librespot[12150]: time="2024-10-13T12:08:06+08:00" level=debug msg="zeroconf server listening on port 37353" Oct 13 12:08:06 player go-librespot[12150]: time="2024-10-13T12:08:06+08:00" level=debug msg="obtained new client token: AAAjGPtrLieosWl6pSZ1FG+JCk008i06ESiPEFxZp45kX+HVTCkS5eiBcAtu36Imbqh14Lffm2RFmoR2Rd2osDOOnqxKYrttwI7i0fKGyPvsc3lUOhN9auycDup0T9Vqw7D/JUvps2+Aq5c5BV6lGkvR5FY1i8ExZZx4oQTdzHGqHtW1bmDfkpBqINfnCN7UCuczHlQWIt6uxF7IPwRkac/ya96AabJV8G8ukgraWKwZqR3Xz4gW4kjJCVmc8ZG+" Oct 13 12:08:07 player go-librespot[12150]: time="2024-10-13T12:08:07+08:00" level=info msg="connected to ap-gae2.spotify.com:4070" Oct 13 12:08:07 player go-librespot[12150]: time="2024-10-13T12:08:07+08:00" level=debug msg="completed keyexchange" Oct 13 12:08:07 player go-librespot[12150]: time="2024-10-13T12:08:07+08:00" level=debug msg="completed challenge" Oct 13 12:08:07 player go-librespot[12150]: time="2024-10-13T12:08:07+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 13 12:08:07 player systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 13 12:08:07 player volumio[6293]: info: Connection to go-librespot Websocket closed Oct 13 12:08:07 player systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 13 12:08:08 player volumio[6293]: info: Getting Spotify volume Oct 13 12:08:08 player volumio[6293]: (node:6293) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 13 12:08:08 player volumio[6293]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Oct 13 12:08:08 player volumio[6293]: (node:6293) 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: 1056) Oct 13 12:08:08 player volumio[6293]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Oct 13 12:08:08 player volumio[6293]: info: CoreCommandRouter::volumioGetState Oct 13 12:08:08 player volumio[6293]: info: CorePlayQueue::getTrack 9 Oct 13 12:08:08 player volumio[6293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Oct 13 12:08:08 player sudo[12160]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 13 12:08:08 player sudo[12160]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 13 12:08:08 player sudo[12160]: pam_unix(sudo:session): session closed for user root Oct 13 12:08:08 player sudo[12163]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 13 12:08:08 player sudo[12163]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 13 12:08:08 player sudo[12163]: pam_unix(sudo:session): session closed for user root Oct 13 12:08:08 player volumio[6293]: verbose: New Socket.io Connection to 192.168.74.147 from 192.168.74.67 UA: Mozilla/5.0 (Linux; Android 14; 2201122G Build/UKQ1.230917.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/129.0.6668.81 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Oct 13 12:08:09 player sudo[12166]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 13 12:08:09 player sudo[12166]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 13 12:08:09 player sudo[12166]: pam_unix(sudo:session): session closed for user root Oct 13 12:08:09 player sudo[12169]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 13 12:08:09 player sudo[12169]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 13 12:08:09 player sudo[12169]: pam_unix(sudo:session): session closed for user root Oct 13 12:08:09 player volumio[6293]: verbose: New Socket.io Connection to 192.168.74.147 from 192.168.74.67 UA: Mozilla/5.0 (Linux; Android 14; 2201122G Build/UKQ1.230917.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/129.0.6668.81 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Oct 13 12:08:09 player volumio[6293]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 13 12:08:09 player volumio[6293]: info: CoreCommandRouter::volumioGetVisibleSources Oct 13 12:08:09 player volumio[6293]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 13 12:08:09 player volumio[6293]: info: CoreCommandRouter::volumioGetState Oct 13 12:08:09 player volumio[6293]: info: CorePlayQueue::getTrack 9 Oct 13 12:08:09 player volumio[6293]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 13 12:08:09 player volumio[6293]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 13 12:08:09 player volumio[6293]: info: Received Get System Info Oct 13 12:08:09 player volumio[6293]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 13 12:08:09 player volumio[6293]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 13 12:08:09 player volumio[6293]: info: Discovery: Getting this device information Oct 13 12:08:09 player volumio[6293]: info: CoreCommandRouter::volumioGetState Oct 13 12:08:09 player volumio[6293]: info: CorePlayQueue::getTrack 9 Oct 13 12:08:09 player volumio[6293]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 13 12:08:09 player volumio[6293]: info: CoreCommandRouter::volumioGetState Oct 13 12:08:09 player volumio[6293]: info: CorePlayQueue::getTrack 9 Oct 13 12:08:09 player volumio[6293]: info: Listing playlists Oct 13 12:08:09 player volumio[6293]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 13 12:08:09 player volumio[6293]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 13 12:08:10 player volumio[6293]: info: Initializing connection to go-librespot Websocket Oct 13 12:08:10 player volumio[6293]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 13 12:08:11 player systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 13 12:08:11 player systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2209. Oct 13 12:08:11 player systemd[1]: Stopped go-librespot Daemon. Oct 13 12:08:11 player systemd[1]: Started go-librespot Daemon. Oct 13 12:08:11 player go-librespot[12171]: Librespot-go daemon starting... Oct 13 12:08:11 player go-librespot[12171]: time="2024-10-13T12:08:11+08:00" level=info msg="generated new device id: 5c294592eb2d6d74834cd68d215f0f5ce7a81d22" Oct 13 12:08:11 player go-librespot[12171]: time="2024-10-13T12:08:11+08:00" level=debug msg="stored credentials not found" Oct 13 12:08:11 player volumio[6293]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Oct 13 12:08:11 player volumio[6293]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 13 12:08:11 player volumio[6293]: info: Received Get System Info Oct 13 12:08:11 player volumio[6293]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 13 12:08:11 player volumio[6293]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 13 12:08:11 player volumio[6293]: info: Discovery: Getting this device information Oct 13 12:08:11 player volumio[6293]: info: CoreCommandRouter::volumioGetState Oct 13 12:08:11 player volumio[6293]: info: CorePlayQueue::getTrack 9 Oct 13 12:08:11 player volumio[6293]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 13 12:08:11 player volumio[6293]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 13 12:08:11 player go-librespot[12171]: time="2024-10-13T12:08:11+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 13 12:08:11 player go-librespot[12171]: time="2024-10-13T12:08:11+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 13 12:08:11 player go-librespot[12171]: time="2024-10-13T12:08:11+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 13 12:08:11 player go-librespot[12171]: time="2024-10-13T12:08:11+08:00" level=debug msg="zeroconf server listening on port 39053" Oct 13 12:08:12 player go-librespot[12171]: time="2024-10-13T12:08:12+08:00" level=debug msg="obtained new client token: AAAg5+0WiUQKHgpHpAEuj7k5iVYBiXaFhswHM6didTcn8nYLV9ZpNGxxAf08OiFP/9Ih1NYB0XVFN4ibpS5Km4GSNTx9ksaCbWdY0rOo9Z9+bqBtVowkpr5mZQLocfYmsl0wsj86RnwBkoluqC37ky+J2N9NXUP2aD4dH398ZrwXVLLAjcXFGJFtjeXgx+Tf5+tjvwWuJMX5d39O/wnK+JsW5GprRAIzi+8hZcUyp9M9EujHaJN/Mk5d8xbCNIZU" Oct 13 12:08:12 player go-librespot[12171]: time="2024-10-13T12:08:12+08:00" level=info msg="connected to ap-gae2.spotify.com:4070" Oct 13 12:08:12 player go-librespot[12171]: time="2024-10-13T12:08:12+08:00" level=debug msg="completed keyexchange" Oct 13 12:08:13 player go-librespot[12171]: time="2024-10-13T12:08:13+08:00" level=debug msg="completed challenge" Oct 13 12:08:13 player go-librespot[12171]: time="2024-10-13T12:08:13+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 13 12:08:13 player systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 13 12:08:13 player systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 13 12:08:13 player volumio[6293]: info: Initializing connection to go-librespot Websocket Oct 13 12:08:13 player volumio[6293]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 13 12:08:13 player volumio[6293]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 13 12:08:13 player volumio[6293]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 13 12:08:16 player systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 13 12:08:16 player systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2210. Oct 13 12:08:16 player systemd[1]: Stopped go-librespot Daemon. Oct 13 12:08:16 player systemd[1]: Started go-librespot Daemon. Oct 13 12:08:16 player go-librespot[12223]: Librespot-go daemon starting... Oct 13 12:08:16 player go-librespot[12223]: time="2024-10-13T12:08:16+08:00" level=info msg="generated new device id: e058d4e6913f60d892fa967a24d686a0eb86196e" Oct 13 12:08:16 player go-librespot[12223]: time="2024-10-13T12:08:16+08:00" level=debug msg="stored credentials not found" Oct 13 12:08:16 player volumio[6293]: info: Initializing connection to go-librespot Websocket Oct 13 12:08:16 player go-librespot[12223]: time="2024-10-13T12:08:16+08:00" level=debug msg="new websocket client" Oct 13 12:08:16 player volumio[6293]: info: Connection to go-librespot Websocket established Oct 13 12:08:17 player go-librespot[12223]: time="2024-10-13T12:08:17+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 13 12:08:17 player go-librespot[12223]: time="2024-10-13T12:08:17+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 13 12:08:17 player go-librespot[12223]: time="2024-10-13T12:08:17+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 13 12:08:17 player go-librespot[12223]: time="2024-10-13T12:08:17+08:00" level=debug msg="zeroconf server listening on port 42819" Oct 13 12:08:18 player go-librespot[12223]: time="2024-10-13T12:08:18+08:00" level=debug msg="obtained new client token: AABcRAHijf2uV7VplfbilCNIzENfa86wfhxa27M4Zb9iqJm4b0SJ5FiS2AeB52TkGNnsqV847HG84Jhq0CdEvsnWEgdQQz7ff//n1eVKOXAQAhA2diimpvj/GfokG5cCXdAGlwZprNQkPLN0m2WlvWbjyNNxyf+/BesEyPzF52LmFvhsdhTinZcCkw2JUOQQwnY9Mn4oym0LxZZ9DmbOCKQtdgLuS0R0IwEqhdC+vwPb3sSD6DcUp5BRAx4luFrp" Oct 13 12:08:18 player go-librespot[12223]: time="2024-10-13T12:08:18+08:00" level=info msg="connected to ap-gae2.spotify.com:4070" Oct 13 12:08:18 player go-librespot[12223]: time="2024-10-13T12:08:18+08:00" level=debug msg="completed keyexchange" Oct 13 12:08:19 player go-librespot[12223]: time="2024-10-13T12:08:19+08:00" level=debug msg="completed challenge" Oct 13 12:08:19 player go-librespot[12223]: time="2024-10-13T12:08:19+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 13 12:08:19 player systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 13 12:08:19 player systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 13 12:08:19 player volumio[6293]: info: Connection to go-librespot Websocket closed Oct 13 12:08:19 player volumio[6293]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Oct 13 12:08:20 player volumio[6293]: info: Getting Spotify volume Oct 13 12:08:20 player volumio[6293]: (node:6293) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 13 12:08:20 player volumio[6293]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Oct 13 12:08:20 player volumio[6293]: (node:6293) 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: 1057) Oct 13 12:08:20 player volumio[6293]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Oct 13 12:08:20 player volumio[6293]: info: CoreCommandRouter::volumioGetState Oct 13 12:08:20 player volumio[6293]: info: CorePlayQueue::getTrack 9 Oct 13 12:08:20 player volumio[6293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Oct 13 12:08:22 player volumio[6293]: info: Initializing connection to go-librespot Websocket Oct 13 12:08:22 player volumio[6293]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 13 12:08:22 player systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 13 12:08:22 player systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2211. Oct 13 12:08:22 player systemd[1]: Stopped go-librespot Daemon. Oct 13 12:08:22 player systemd[1]: Started go-librespot Daemon. Oct 13 12:08:22 player go-librespot[12231]: Librespot-go daemon starting... Oct 13 12:08:22 player go-librespot[12231]: time="2024-10-13T12:08:22+08:00" level=info msg="generated new device id: bbc52d596d7494f7bdee4b519b53f9242a9878d9" Oct 13 12:08:22 player go-librespot[12231]: time="2024-10-13T12:08:22+08:00" level=debug msg="stored credentials not found" Oct 13 12:08:23 player go-librespot[12231]: time="2024-10-13T12:08:23+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 13 12:08:23 player go-librespot[12231]: time="2024-10-13T12:08:23+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 13 12:08:23 player go-librespot[12231]: time="2024-10-13T12:08:23+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 13 12:08:23 player go-librespot[12231]: time="2024-10-13T12:08:23+08:00" level=debug msg="zeroconf server listening on port 34113" Oct 13 12:08:24 player go-librespot[12231]: time="2024-10-13T12:08:24+08:00" level=debug msg="obtained new client token: AADbWPJFrQf6BJiZa8SqAbZZZ6T6FtxjJkQg1AHcr0Z7cZp7bLT8d1Drs6upMebJZRdcojBRZ6K/7uGXZFWm5HI3olpRTYn0pu4PT1X2zqtdJ8Gc7MLvDZpsD799FqZafp7XTlvWhOBcA8uFRDUAGXewvovcGa23YbTM6EvA0WxQMuMgayoLwZ/ThoCfpI9BleVItlt+bgX4joaitebED8hmbYxO/FxvFFXYHri3tJ8dEkvAJ7OtEGRNnx/MVLpJ" Oct 13 12:08:24 player go-librespot[12231]: time="2024-10-13T12:08:24+08:00" level=info msg="connected to ap-gae2.spotify.com:4070" Oct 13 12:08:24 player go-librespot[12231]: time="2024-10-13T12:08:24+08:00" level=debug msg="completed keyexchange" Oct 13 12:08:24 player go-librespot[12231]: time="2024-10-13T12:08:24+08:00" level=debug msg="completed challenge" Oct 13 12:08:24 player go-librespot[12231]: time="2024-10-13T12:08:24+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 13 12:08:24 player systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 13 12:08:24 player systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 13 12:08:25 player volumio[6293]: info: Initializing connection to go-librespot Websocket Oct 13 12:08:25 player volumio[6293]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 13 12:08:28 player systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 13 12:08:28 player systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2212. Oct 13 12:08:28 player systemd[1]: Stopped go-librespot Daemon. Oct 13 12:08:28 player systemd[1]: Started go-librespot Daemon. Oct 13 12:08:28 player go-librespot[12239]: Librespot-go daemon starting... Oct 13 12:08:28 player go-librespot[12239]: time="2024-10-13T12:08:28+08:00" level=info msg="generated new device id: 8c7bb55b8660b2d0e77e2c5596b95a409491c018" Oct 13 12:08:28 player go-librespot[12239]: time="2024-10-13T12:08:28+08:00" level=debug msg="stored credentials not found" Oct 13 12:08:28 player volumio[6293]: info: Initializing connection to go-librespot Websocket Oct 13 12:08:28 player go-librespot[12239]: time="2024-10-13T12:08:28+08:00" level=debug msg="new websocket client" Oct 13 12:08:28 player volumio[6293]: info: Connection to go-librespot Websocket established Oct 13 12:08:29 player go-librespot[12239]: time="2024-10-13T12:08:29+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 13 12:08:29 player go-librespot[12239]: time="2024-10-13T12:08:29+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 13 12:08:29 player go-librespot[12239]: time="2024-10-13T12:08:29+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 13 12:08:29 player go-librespot[12239]: time="2024-10-13T12:08:29+08:00" level=debug msg="zeroconf server listening on port 42009" Oct 13 12:08:29 player go-librespot[12239]: time="2024-10-13T12:08:29+08:00" level=debug msg="obtained new client token: AABGTTTDtExhZNQqzJHCVeSg1Vk1Q9a5z/KldK8TXqnLGUQqlnpSJqBThb0KcYGTVKnS+0POm8+e7hMZOCccIwB9Im85J2HsAK07X8cp6Y7pXBeX+zCon+2IX0u7WsJHbM2mhN4uHa9eWkdvwmLUXNDBgdJzCQOcUdAzdFquMSVd4mxsyEAPFqPxYJOXRpY60jyqCkLtEoLO5zI0QdpqEaqdcX8D1K1B2ahBc0l137a9z1VduIuuCEv7Dq49gO80" Oct 13 12:08:29 player go-librespot[12239]: time="2024-10-13T12:08:29+08:00" level=info msg="connected to ap-gae2.spotify.com:4070" Oct 13 12:08:29 player go-librespot[12239]: time="2024-10-13T12:08:29+08:00" level=debug msg="completed keyexchange" Oct 13 12:08:30 player go-librespot[12239]: time="2024-10-13T12:08:30+08:00" level=debug msg="completed challenge" Oct 13 12:08:30 player go-librespot[12239]: time="2024-10-13T12:08:30+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 13 12:08:30 player systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 13 12:08:30 player systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 13 12:08:30 player volumio[6293]: info: Connection to go-librespot Websocket closed Oct 13 12:08:31 player volumio[6293]: info: Getting Spotify volume Oct 13 12:08:31 player volumio[6293]: (node:6293) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 13 12:08:31 player volumio[6293]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Oct 13 12:08:31 player volumio[6293]: (node:6293) 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: 1058) Oct 13 12:08:31 player volumio[6293]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Oct 13 12:08:31 player volumio[6293]: info: CoreCommandRouter::volumioGetState Oct 13 12:08:31 player volumio[6293]: info: CorePlayQueue::getTrack 9 Oct 13 12:08:31 player volumio[6293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Oct 13 12:08:33 player volumio[6293]: info: Initializing connection to go-librespot Websocket Oct 13 12:08:33 player volumio[6293]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 13 12:08:33 player systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 13 12:08:33 player systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2213. Oct 13 12:08:33 player systemd[1]: Stopped go-librespot Daemon. Oct 13 12:08:33 player systemd[1]: Started go-librespot Daemon. Oct 13 12:08:33 player go-librespot[12247]: Librespot-go daemon starting... Oct 13 12:08:33 player go-librespot[12247]: time="2024-10-13T12:08:33+08:00" level=info msg="generated new device id: 6b55e96454f2e263b691d9ba0b33d37e56761491" Oct 13 12:08:33 player go-librespot[12247]: time="2024-10-13T12:08:33+08:00" level=debug msg="stored credentials not found" Oct 13 12:08:34 player go-librespot[12247]: time="2024-10-13T12:08:34+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Oct 13 12:08:34 player go-librespot[12247]: time="2024-10-13T12:08:34+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 13 12:08:34 player go-librespot[12247]: time="2024-10-13T12:08:34+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 13 12:08:34 player go-librespot[12247]: time="2024-10-13T12:08:34+08:00" level=debug msg="zeroconf server listening on port 35403" Oct 13 12:08:35 player go-librespot[12247]: time="2024-10-13T12:08:35+08:00" level=debug msg="obtained new client token: AAD88HI6c5CxC6de+UXcU4G+Jja7IogmsV22GQEotfw/2sWS/CXcQ7XjnvA4zk21+Fc3RUy/05XujNRT0MzncMmBEaQGb/JNbP0jxBpzOSfIS19l1SMTXq20Fj7xfRhV/PznemwhMRiQfa8csIzbLQSOEcSVV/Atr5HdxxXObXDQp59i9capoxUqncIfWoWLtg23y/FwTDod/40o1ZnMqm/0uQVAAVe++SR+ayVIrJ5ZI/1obJoDrDWQ5ZKJgg==" Oct 13 12:08:35 player go-librespot[12247]: time="2024-10-13T12:08:35+08:00" level=info msg="connected to ap-gae2.spotify.com:4070" Oct 13 12:08:35 player go-librespot[12247]: time="2024-10-13T12:08:35+08:00" level=debug msg="completed keyexchange" Oct 13 12:08:35 player volumio[6293]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 13 12:08:35 player volumio[6293]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 13 12:08:35 player volumio[6293]: info: Discovery: Getting this device information Oct 13 12:08:35 player volumio[6293]: info: CoreCommandRouter::volumioGetState Oct 13 12:08:35 player volumio[6293]: info: CorePlayQueue::getTrack 9 Oct 13 12:08:35 player volumio[6293]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 13 12:08:36 player go-librespot[12247]: time="2024-10-13T12:08:36+08:00" level=debug msg="completed challenge" Oct 13 12:08:36 player go-librespot[12247]: time="2024-10-13T12:08:36+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 13 12:08:36 player systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 13 12:08:36 player systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 13 12:08:36 player volumio[6293]: info: Initializing connection to go-librespot Websocket Oct 13 12:08:36 player volumio[6293]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 13 12:08:39 player systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 13 12:08:39 player systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2214. Oct 13 12:08:39 player systemd[1]: Stopped go-librespot Daemon. Oct 13 12:08:39 player systemd[1]: Started go-librespot Daemon. Oct 13 12:08:39 player go-librespot[12256]: Librespot-go daemon starting... Oct 13 12:08:39 player go-librespot[12256]: time="2024-10-13T12:08:39+08:00" level=info msg="generated new device id: 668b01ce38161b9f67d17a0541f58851396d4b36" Oct 13 12:08:39 player go-librespot[12256]: time="2024-10-13T12:08:39+08:00" level=debug msg="stored credentials not found" Oct 13 12:08:39 player volumio[6293]: info: Initializing connection to go-librespot Websocket Oct 13 12:08:39 player go-librespot[12256]: time="2024-10-13T12:08:39+08:00" level=debug msg="new websocket client" Oct 13 12:08:39 player volumio[6293]: info: Connection to go-librespot Websocket established Oct 13 12:08:40 player go-librespot[12256]: time="2024-10-13T12:08:40+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 13 12:08:40 player go-librespot[12256]: time="2024-10-13T12:08:40+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 13 12:08:40 player go-librespot[12256]: time="2024-10-13T12:08:40+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 13 12:08:40 player go-librespot[12256]: time="2024-10-13T12:08:40+08:00" level=debug msg="zeroconf server listening on port 41217" Oct 13 12:08:41 player go-librespot[12256]: time="2024-10-13T12:08:41+08:00" level=debug msg="obtained new client token: AAC9+7wphFUMhl6xP8ZlMgV5ypbQYR2E1WZfI8wpCQ8dvVzGPEXx56uNDDSmK3YvkTPgcLWadsfPXA2D/U48I0M4MRTaiVWwcWnz0EkIScWqtFoHrX4luf2nY/HCBi41Pe/vLSgo4mH0q2mkosRP/tfFmhdKMwsqSKomv0sMVQHmQZQnfglyuiVO6QdKzdB2KCCMD49uvvJSI9l3wBmKr9DGvl0MleO5l4q6m+jfYCFpjmBJ05TLutHyGu0yNQ==" Oct 13 12:08:41 player volumio[6293]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 13 12:08:41 player volumio[6293]: [t [Error]: A network error (such as timeout, interrupted connection or unreachable host) has occurred.] { Oct 13 12:08:41 player volumio[6293]: code: 'auth/network-request-failed', Oct 13 12:08:41 player volumio[6293]: a: null Oct 13 12:08:41 player volumio[6293]: } Oct 13 12:08:41 player volumio[6293]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 13 12:08:41 player go-librespot[12256]: time="2024-10-13T12:08:41+08:00" level=info msg="connected to ap-gae2.spotify.com:4070" Oct 13 12:08:41 player go-librespot[12256]: time="2024-10-13T12:08:41+08:00" level=debug msg="completed keyexchange" Oct 13 12:08:41 player sudo[12274]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-13 12:07 Oct 13 12:08:41 player sudo[12274]: 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="bba9e3185e150dd0995f9a49355b34fc6218d5a2" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 05:33:09 PM CEST" VOLUMIO_VERSION="3.757" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="ee834e1c2a28de3c5d8c48611ecf1167"