-- Logs begin at Tue 2024-06-25 16:50:57 -03, end at Thu 2024-11-21 15:43:16 -03. -- Nov 21 15:42:00 volumio go-librespot[22274]: time="2024-11-21T15:42:00-03:00" level=debug msg="completed keyexchange" Nov 21 15:42:00 volumio go-librespot[22274]: time="2024-11-21T15:42:00-03:00" level=debug msg="completed challenge" Nov 21 15:42:00 volumio volumio[943]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 21 15:42:00 volumio go-librespot[22274]: time="2024-11-21T15:42:00-03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 15:42:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 15:42:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 15:42:01 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Nov 21 15:42:01 volumio volumio[943]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 15:42:03 volumio wpa_supplicant[867]: wlan0: Failed to initiate sched scan Nov 21 15:42:03 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 15:42:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1844. Nov 21 15:42:03 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 15:42:03 volumio systemd[1]: Started go-librespot Daemon. Nov 21 15:42:03 volumio go-librespot[22282]: Librespot-go daemon starting... Nov 21 15:42:04 volumio go-librespot[22282]: time="2024-11-21T15:42:04-03:00" level=info msg="generated new device id: eedef58611f88f88a8eb9b85503d56fe5ae85425" Nov 21 15:42:04 volumio go-librespot[22282]: time="2024-11-21T15:42:04-03:00" level=debug msg="stored credentials found for 31cybqphgdep7z6rmbplp2d4cyym" Nov 21 15:42:04 volumio go-librespot[22282]: time="2024-11-21T15:42:04-03:00" level=debug msg="obtained new client token: AADmbEDrZduEqH3iDeEpfkmF9yL3M0EYIvDLX8FAMrxCBRqNJsr3nPD9xEsoiJI+AVCEO4j8qXBpbP5AH6ctMcaGMoqrZc9JVd5khgNpzul8nYBvYhNxD1+U5leY7By24EgWdrI5cfznzVvas83Su9qFNcUOrKzNkCbWxd7Sc/FuEkU1NIrbJ/q9Vvi3OTIkjoSpnaxuR6NuEJgfEViFAaAS3GDdCbrehTs8ByQ73XtlAvf2DMah2k+5MHe/jA==" Nov 21 15:42:04 volumio go-librespot[22282]: time="2024-11-21T15:42:04-03:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 21 15:42:04 volumio volumio[943]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 21 15:42:04 volumio go-librespot[22282]: time="2024-11-21T15:42:04-03:00" level=debug msg="completed keyexchange" Nov 21 15:42:04 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Nov 21 15:42:04 volumio volumio[943]: info: Connection to go-librespot Websocket established Nov 21 15:42:04 volumio go-librespot[22282]: time="2024-11-21T15:42:04-03:00" level=debug msg="new websocket client" Nov 21 15:42:05 volumio go-librespot[22282]: time="2024-11-21T15:42:05-03:00" level=debug msg="completed challenge" Nov 21 15:42:05 volumio go-librespot[22282]: time="2024-11-21T15:42:05-03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 15:42:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 15:42:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 15:42:05 volumio volumio[943]: info: Connection to go-librespot Websocket closed Nov 21 15:42:07 volumio volumio[943]: info: Getting Spotify volume Nov 21 15:42:07 volumio volumio[943]: (node:943) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 15:42:07 volumio volumio[943]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Nov 21 15:42:07 volumio volumio[943]: (node:943) 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: 588) Nov 21 15:42:07 volumio volumio[943]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Nov 21 15:42:07 volumio volumio[943]: info: CoreCommandRouter::volumioGetState Nov 21 15:42:07 volumio volumio[943]: info: CorePlayQueue::getTrack 44 Nov 21 15:42:07 volumio volumio[943]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Nov 21 15:42:08 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Nov 21 15:42:08 volumio volumio[943]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 15:42:08 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 15:42:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1845. Nov 21 15:42:08 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 15:42:08 volumio systemd[1]: Started go-librespot Daemon. Nov 21 15:42:08 volumio go-librespot[22290]: Librespot-go daemon starting... Nov 21 15:42:08 volumio go-librespot[22290]: time="2024-11-21T15:42:08-03:00" level=info msg="generated new device id: 9fe2b9d81264fc67fce6c83aff5c4a6700eab6bb" Nov 21 15:42:08 volumio go-librespot[22290]: time="2024-11-21T15:42:08-03:00" level=debug msg="stored credentials found for 31cybqphgdep7z6rmbplp2d4cyym" Nov 21 15:42:08 volumio volumio[943]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 21 15:42:09 volumio go-librespot[22290]: time="2024-11-21T15:42:09-03:00" level=debug msg="obtained new client token: AADeJE8apYguq5e59+H4vq9+ZV/y/QgpVvoR7+mnoTtNQEcxTDpjM9MArOXHNm23cDXiuOL5mg4auogHeAlJPcUqPBe5ZC2ZmeY9/cd2q+/vxN8zoLJvH0EQURUwqJofNFKyVa+wI10pwtlE2XEuTY6JmLi19NxA++sdUKBbU7SyZ4rD1oav+mSO48gmgAm2fzd5wKLUdHb2jaeGYn1rY+6TkbyOHj2StDV8/0/sWt3f5m6ttKnhZLUx3HIbMA==" Nov 21 15:42:09 volumio go-librespot[22290]: time="2024-11-21T15:42:09-03:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Nov 21 15:42:09 volumio go-librespot[22290]: time="2024-11-21T15:42:09-03:00" level=debug msg="completed keyexchange" Nov 21 15:42:10 volumio go-librespot[22290]: time="2024-11-21T15:42:10-03:00" level=debug msg="completed challenge" Nov 21 15:42:10 volumio go-librespot[22290]: time="2024-11-21T15:42:10-03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 15:42:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 15:42:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 15:42:10 volumio wpa_supplicant[867]: wlan0: Failed to initiate sched scan Nov 21 15:42:11 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Nov 21 15:42:11 volumio volumio[943]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 15:42:12 volumio volumio[943]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 21 15:42:13 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 15:42:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1846. Nov 21 15:42:13 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 15:42:13 volumio systemd[1]: Started go-librespot Daemon. Nov 21 15:42:13 volumio go-librespot[22298]: Librespot-go daemon starting... Nov 21 15:42:13 volumio go-librespot[22298]: time="2024-11-21T15:42:13-03:00" level=info msg="generated new device id: 427d4eaa2495fa48473691ea07baf3423bba90e4" Nov 21 15:42:13 volumio go-librespot[22298]: time="2024-11-21T15:42:13-03:00" level=debug msg="stored credentials found for 31cybqphgdep7z6rmbplp2d4cyym" Nov 21 15:42:13 volumio go-librespot[22298]: time="2024-11-21T15:42:13-03:00" level=debug msg="obtained new client token: AADPTdqjoU+HdhYnyPQtfLNcsRGtVDp/iTeZD/YvcKOxwjkV2SA7rKHmr3KJqX+yBy33v9X6srFw1CncQSt56oA7mYRKx41hVQOo7z7eH5eMAC/9/RnitvAvl9v5CwyWdEBi7+vucYKwgjXvVnyzgH5BFyA7hVpRpWbLF0vw6+f+NtOoz6ELM7taLNae44BrvxYLKurb3MYX3byYVCxcFxedeF6EdDPMFdAtTRkKbukKULLrF40eYp8VeTyEpplK" Nov 21 15:42:14 volumio go-librespot[22298]: time="2024-11-21T15:42:14-03:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Nov 21 15:42:14 volumio go-librespot[22298]: time="2024-11-21T15:42:14-03:00" level=debug msg="completed keyexchange" Nov 21 15:42:14 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Nov 21 15:42:14 volumio go-librespot[22298]: time="2024-11-21T15:42:14-03:00" level=debug msg="new websocket client" Nov 21 15:42:14 volumio volumio[943]: info: Connection to go-librespot Websocket established Nov 21 15:42:15 volumio go-librespot[22298]: time="2024-11-21T15:42:15-03:00" level=debug msg="completed challenge" Nov 21 15:42:15 volumio go-librespot[22298]: time="2024-11-21T15:42:15-03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 15:42:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 15:42:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 15:42:15 volumio volumio[943]: info: Connection to go-librespot Websocket closed Nov 21 15:42:16 volumio volumio[943]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 21 15:42:17 volumio volumio[943]: info: Getting Spotify volume Nov 21 15:42:17 volumio volumio[943]: (node:943) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 15:42:17 volumio volumio[943]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Nov 21 15:42:17 volumio volumio[943]: (node:943) 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: 589) Nov 21 15:42:17 volumio volumio[943]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Nov 21 15:42:17 volumio volumio[943]: info: CoreCommandRouter::volumioGetState Nov 21 15:42:17 volumio volumio[943]: info: CorePlayQueue::getTrack 44 Nov 21 15:42:17 volumio volumio[943]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Nov 21 15:42:18 volumio wpa_supplicant[867]: wlan0: Failed to initiate sched scan Nov 21 15:42:18 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Nov 21 15:42:18 volumio volumio[943]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 15:42:18 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 15:42:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1847. Nov 21 15:42:18 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 15:42:18 volumio systemd[1]: Started go-librespot Daemon. Nov 21 15:42:18 volumio go-librespot[22306]: Librespot-go daemon starting... Nov 21 15:42:18 volumio go-librespot[22306]: time="2024-11-21T15:42:18-03:00" level=info msg="generated new device id: 0b56ccb12d3fc396628448c991134a104629a2da" Nov 21 15:42:18 volumio go-librespot[22306]: time="2024-11-21T15:42:18-03:00" level=debug msg="stored credentials found for 31cybqphgdep7z6rmbplp2d4cyym" Nov 21 15:42:18 volumio go-librespot[22306]: time="2024-11-21T15:42:18-03:00" level=debug msg="obtained new client token: AADhkpkhq8EXjEnmSVHXEKhNbp1jz9ll+p7JH/sgFnfZ5IjjVTBP/Fw4p3e2DY7UXaKNyPXZB6GgZwDEydE2SCYfCH76/St/32GhU8UWtCY1swKPx62qlaKJpoVqlptn9GZBZkzEBS2J+UeEglwIhlG5q2V+wL3Xcuoubs6lFsQ9U8xErZUlQDnoArrJVY3bl/BR3O5H4W+gfQXkYbtO6qIPYWsIn7OORYaCtnaqHMX7iw5fFWc3DEY1u20MWC/d" Nov 21 15:42:19 volumio go-librespot[22306]: time="2024-11-21T15:42:19-03:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 21 15:42:19 volumio go-librespot[22306]: time="2024-11-21T15:42:19-03:00" level=debug msg="completed keyexchange" Nov 21 15:42:19 volumio go-librespot[22306]: time="2024-11-21T15:42:19-03:00" level=debug msg="completed challenge" Nov 21 15:42:20 volumio go-librespot[22306]: time="2024-11-21T15:42:20-03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 15:42:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 15:42:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 15:42:20 volumio volumio[943]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 21 15:42:21 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Nov 21 15:42:21 volumio volumio[943]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 15:42:23 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 15:42:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1848. Nov 21 15:42:23 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 15:42:23 volumio systemd[1]: Started go-librespot Daemon. Nov 21 15:42:23 volumio go-librespot[22314]: Librespot-go daemon starting... Nov 21 15:42:23 volumio go-librespot[22314]: time="2024-11-21T15:42:23-03:00" level=info msg="generated new device id: a8458e46140ff8c3f3ab647fbd9ae9bf8e78381d" Nov 21 15:42:23 volumio go-librespot[22314]: time="2024-11-21T15:42:23-03:00" level=debug msg="stored credentials found for 31cybqphgdep7z6rmbplp2d4cyym" Nov 21 15:42:23 volumio go-librespot[22314]: time="2024-11-21T15:42:23-03:00" level=debug msg="obtained new client token: AADVdMTMneCl4wON8CEZ/XFxEmqqR/ED8xNo0yMuBjXFzvb0OdJq6HUeIogscy1TZMnl9qnNTyi9TDLCnlYwFxu4jBzfNcUA8U/9fq/z9lGTjxqz/J7cgCBusIz7go/KpjoJ+LEqX6Pjb80H/mwN/wkJOC0BouBWZuMTuCohO845gyDEZ7oPLC+lz78VtjMu4qzOGIXf/oxMVnTbk/M/1UM32Ns04H0xTtmqFjJmB5wA3ZB5KFB+0BR/FzK1rRxb" Nov 21 15:42:24 volumio go-librespot[22314]: time="2024-11-21T15:42:24-03:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Nov 21 15:42:24 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Nov 21 15:42:24 volumio go-librespot[22314]: time="2024-11-21T15:42:24-03:00" level=debug msg="new websocket client" Nov 21 15:42:24 volumio volumio[943]: info: Connection to go-librespot Websocket established Nov 21 15:42:24 volumio go-librespot[22314]: time="2024-11-21T15:42:24-03:00" level=debug msg="completed keyexchange" Nov 21 15:42:24 volumio volumio[943]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 21 15:42:24 volumio go-librespot[22314]: time="2024-11-21T15:42:24-03:00" level=debug msg="completed challenge" Nov 21 15:42:25 volumio go-librespot[22314]: time="2024-11-21T15:42:25-03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 15:42:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 15:42:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 15:42:25 volumio volumio[943]: info: Connection to go-librespot Websocket closed Nov 21 15:42:25 volumio wpa_supplicant[867]: wlan0: Failed to initiate sched scan Nov 21 15:42:27 volumio volumio[943]: info: Getting Spotify volume Nov 21 15:42:27 volumio volumio[943]: (node:943) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 15:42:27 volumio volumio[943]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Nov 21 15:42:27 volumio volumio[943]: (node:943) 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: 590) Nov 21 15:42:27 volumio volumio[943]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Nov 21 15:42:27 volumio volumio[943]: info: CoreCommandRouter::volumioGetState Nov 21 15:42:27 volumio volumio[943]: info: CorePlayQueue::getTrack 44 Nov 21 15:42:27 volumio volumio[943]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Nov 21 15:42:28 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Nov 21 15:42:28 volumio volumio[943]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 15:42:28 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 15:42:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1849. Nov 21 15:42:28 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 15:42:28 volumio systemd[1]: Started go-librespot Daemon. Nov 21 15:42:28 volumio go-librespot[22322]: Librespot-go daemon starting... Nov 21 15:42:28 volumio go-librespot[22322]: time="2024-11-21T15:42:28-03:00" level=info msg="generated new device id: d1b8c2e18654d2bf5c2ff4da8dac5f649f948dcd" Nov 21 15:42:28 volumio go-librespot[22322]: time="2024-11-21T15:42:28-03:00" level=debug msg="stored credentials found for 31cybqphgdep7z6rmbplp2d4cyym" Nov 21 15:42:28 volumio go-librespot[22322]: time="2024-11-21T15:42:28-03:00" level=debug msg="obtained new client token: AAD6KsSC3d1mnTUVqcN8Qi4tKs7nTstrg3hvSptMqaNkcZyiZwgz2obwTg9IBLuHL41Tf5p3HCdo2NTt0+aqT/QodLZqvRxzZUoMDE6CO8rG00aNfVSzgAQWqPget335hBf6sFRprJfaXcHwJvm+fQ71UpEvTAU527HYi3craYKhhxQVtA7wqLrez4rGalpNZ7IDr8NMWFYrpt0zq7srk9Ow6uPA+uwDMo7GUQZea02BzNoYni/dJX0RwTpvHaXA" Nov 21 15:42:28 volumio go-librespot[22322]: time="2024-11-21T15:42:28-03:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 21 15:42:28 volumio volumio[943]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 21 15:42:29 volumio go-librespot[22322]: time="2024-11-21T15:42:29-03:00" level=debug msg="completed keyexchange" Nov 21 15:42:29 volumio go-librespot[22322]: time="2024-11-21T15:42:29-03:00" level=debug msg="completed challenge" Nov 21 15:42:29 volumio go-librespot[22322]: time="2024-11-21T15:42:29-03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 15:42:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 15:42:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 15:42:31 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Nov 21 15:42:31 volumio volumio[943]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 15:42:32 volumio volumio[943]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 21 15:42:32 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 15:42:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1850. Nov 21 15:42:32 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 15:42:32 volumio systemd[1]: Started go-librespot Daemon. Nov 21 15:42:32 volumio go-librespot[22330]: Librespot-go daemon starting... Nov 21 15:42:33 volumio go-librespot[22330]: time="2024-11-21T15:42:33-03:00" level=info msg="generated new device id: 45227277cfd81d3ac3df5791463eaf2816560221" Nov 21 15:42:33 volumio go-librespot[22330]: time="2024-11-21T15:42:33-03:00" level=debug msg="stored credentials found for 31cybqphgdep7z6rmbplp2d4cyym" Nov 21 15:42:33 volumio wpa_supplicant[867]: wlan0: Failed to initiate sched scan Nov 21 15:42:33 volumio go-librespot[22330]: time="2024-11-21T15:42:33-03:00" level=debug msg="obtained new client token: AADFKu3/CWQ5ittnp34y4gOwroN3jucG7UiQvxYitc56EW6QCjIr4cEdWewIOvw4ShTQXDm+/oylamrDPRdK95j8SsUvfR0OZSHJneRwuYdw0CF+XoSRWd3olpsH7LCFMwAmfuWxrxc/zf5HcIwaqV3LP6t4rKYYADANcJ6CYA4nXeEZEwVkdtfxjOJhv7YQJOrGT6ODWcoDTKqGDSpnegrrVMEyN9lVr9fIH2wFvVnHAKxXE43v2RD5aeegTUqE" Nov 21 15:42:33 volumio go-librespot[22330]: time="2024-11-21T15:42:33-03:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Nov 21 15:42:34 volumio go-librespot[22330]: time="2024-11-21T15:42:34-03:00" level=debug msg="completed keyexchange" Nov 21 15:42:34 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Nov 21 15:42:34 volumio go-librespot[22330]: time="2024-11-21T15:42:34-03:00" level=debug msg="new websocket client" Nov 21 15:42:34 volumio volumio[943]: info: Connection to go-librespot Websocket established Nov 21 15:42:34 volumio go-librespot[22330]: time="2024-11-21T15:42:34-03:00" level=debug msg="completed challenge" Nov 21 15:42:34 volumio go-librespot[22330]: time="2024-11-21T15:42:34-03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 15:42:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 15:42:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 15:42:34 volumio volumio[943]: info: Connection to go-librespot Websocket closed Nov 21 15:42:37 volumio volumio[943]: info: Getting Spotify volume Nov 21 15:42:37 volumio volumio[943]: (node:943) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 15:42:37 volumio volumio[943]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Nov 21 15:42:37 volumio volumio[943]: (node:943) 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: 591) Nov 21 15:42:37 volumio volumio[943]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Nov 21 15:42:37 volumio volumio[943]: info: CoreCommandRouter::volumioGetState Nov 21 15:42:37 volumio volumio[943]: info: CorePlayQueue::getTrack 44 Nov 21 15:42:37 volumio volumio[943]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Nov 21 15:42:37 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Nov 21 15:42:37 volumio volumio[943]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 15:42:37 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 15:42:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1851. Nov 21 15:42:37 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 15:42:37 volumio systemd[1]: Started go-librespot Daemon. Nov 21 15:42:37 volumio go-librespot[22376]: Librespot-go daemon starting... Nov 21 15:42:38 volumio go-librespot[22376]: time="2024-11-21T15:42:38-03:00" level=info msg="generated new device id: f4b2b85770bf034b8ebb219c66534847b19b7686" Nov 21 15:42:38 volumio go-librespot[22376]: time="2024-11-21T15:42:38-03:00" level=debug msg="stored credentials found for 31cybqphgdep7z6rmbplp2d4cyym" Nov 21 15:42:38 volumio go-librespot[22376]: time="2024-11-21T15:42:38-03:00" level=debug msg="obtained new client token: AACfTw97zsfK31yMFSo6JmIXTTav8CYQO4cWKe/Nt6/vGuPHYTpai3oxdLSdtOciFPWdS10OfSglbzGs0LbTqW3UHp9s/TRVXBNSOFwCbUvs+/ofqI1gdG0TlJnw3pWCzRzYdkzTtN+ptCek+LI963lUQExH4zp3ASUGB5nbmRQnjRNxwosXWdnxSbFOoCnL3Z0d1gmBRdPSUBasOZ1hXRPM+B7n7X7F7Ikul0cRJr+2FE+E0baavW7QV+cPfw==" Nov 21 15:42:38 volumio go-librespot[22376]: time="2024-11-21T15:42:38-03:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 21 15:42:38 volumio go-librespot[22376]: time="2024-11-21T15:42:38-03:00" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 104.154.127.247:4070: connect: connection refused" Nov 21 15:42:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 15:42:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 15:42:40 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Nov 21 15:42:40 volumio volumio[943]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 15:42:40 volumio wpa_supplicant[867]: wlan0: Failed to initiate sched scan Nov 21 15:42:41 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 15:42:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1852. Nov 21 15:42:41 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 15:42:41 volumio systemd[1]: Started go-librespot Daemon. Nov 21 15:42:41 volumio go-librespot[22384]: Librespot-go daemon starting... Nov 21 15:42:42 volumio go-librespot[22384]: time="2024-11-21T15:42:42-03:00" level=info msg="generated new device id: 3285b6e506f65643a04024f8b0939ac4cbdcdb34" Nov 21 15:42:42 volumio go-librespot[22384]: time="2024-11-21T15:42:42-03:00" level=debug msg="stored credentials found for 31cybqphgdep7z6rmbplp2d4cyym" Nov 21 15:42:42 volumio go-librespot[22384]: time="2024-11-21T15:42:42-03:00" level=debug msg="obtained new client token: AACETuIljxBK7ThquON47xVkCTmFtvA4dSl54gkSU5dlWFXI81AVfHHqYzBZs6g/u1Kk9k8cnUtZyPC6u3OeaqIwpWm9z74kchvJKfYD0wcIBx+bNce00uDKeB/eKO2g1lmhJoViMXJLNFyd0qD9H8du14MeMtGqqQtO93rARTq/SVnAmizf2OvGb4ZGO5CBhoObkwRa/3feryauvOZW7xPOaSkc3xD5BeF2TT6ts2kDPioJ7CjXm0Bu9MlcdQ==" Nov 21 15:42:42 volumio go-librespot[22384]: time="2024-11-21T15:42:42-03:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 21 15:42:42 volumio go-librespot[22384]: time="2024-11-21T15:42:42-03:00" level=debug msg="completed keyexchange" Nov 21 15:42:43 volumio go-librespot[22384]: time="2024-11-21T15:42:43-03:00" level=debug msg="completed challenge" Nov 21 15:42:43 volumio go-librespot[22384]: time="2024-11-21T15:42:43-03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 15:42:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 15:42:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 15:42:43 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Nov 21 15:42:43 volumio volumio[943]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 15:42:46 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 15:42:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1853. Nov 21 15:42:46 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 15:42:46 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Nov 21 15:42:46 volumio volumio[943]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 15:42:46 volumio systemd[1]: Started go-librespot Daemon. Nov 21 15:42:46 volumio go-librespot[22392]: Librespot-go daemon starting... Nov 21 15:42:46 volumio go-librespot[22392]: time="2024-11-21T15:42:46-03:00" level=info msg="generated new device id: 096c4a4f4b458dca7ddd6bd6cd20fa04f750048f" Nov 21 15:42:46 volumio go-librespot[22392]: time="2024-11-21T15:42:46-03:00" level=debug msg="stored credentials found for 31cybqphgdep7z6rmbplp2d4cyym" Nov 21 15:42:46 volumio volumio[943]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 21 15:42:47 volumio go-librespot[22392]: time="2024-11-21T15:42:47-03:00" level=debug msg="obtained new client token: AAB75OdLYTBalHV/59FhXiQHZ/jOEKy36eUx7Q97G/iFBbAmbBCa3JODyQfuNV//uVRCqS97C5lnM5l8bA3h88tBo+orRtu67u3FX+NKxTuJYwHlnERU2wYNEXHDVt+MivWWCylj1BOH9VgXMTkt04B1UYPwrfFgp+pOq13G59jZ+oWaefJN65eLaSiFJQZtGhQv7XfR3PVgGwQwQYhObNK1DYvIqTOREYbeBDYAYSd/2JFUcjwObVnWtN8=" Nov 21 15:42:47 volumio go-librespot[22392]: time="2024-11-21T15:42:47-03:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 21 15:42:47 volumio go-librespot[22392]: time="2024-11-21T15:42:47-03:00" level=debug msg="completed keyexchange" Nov 21 15:42:48 volumio go-librespot[22392]: time="2024-11-21T15:42:48-03:00" level=debug msg="completed challenge" Nov 21 15:42:48 volumio wpa_supplicant[867]: wlan0: Failed to initiate sched scan Nov 21 15:42:48 volumio go-librespot[22392]: time="2024-11-21T15:42:48-03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 15:42:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 15:42:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 15:42:49 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Nov 21 15:42:49 volumio volumio[943]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 15:42:51 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 15:42:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1854. Nov 21 15:42:51 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 15:42:51 volumio systemd[1]: Started go-librespot Daemon. Nov 21 15:42:51 volumio go-librespot[22400]: Librespot-go daemon starting... Nov 21 15:42:51 volumio go-librespot[22400]: time="2024-11-21T15:42:51-03:00" level=info msg="generated new device id: a4ce6acd1ce6dd39ed3d94ce25d0b7ee1f720ff8" Nov 21 15:42:51 volumio go-librespot[22400]: time="2024-11-21T15:42:51-03:00" level=debug msg="stored credentials found for 31cybqphgdep7z6rmbplp2d4cyym" Nov 21 15:42:51 volumio go-librespot[22400]: time="2024-11-21T15:42:51-03:00" level=debug msg="obtained new client token: AACH195tZ00GUMd1tyiO1xt1dTO4TlnrRLZIRJz54aUvUHa28t/y1y1iC1ydI6Kra7IMsIJCSM4QQ/5YVfR0WQ2y/A4N8QlekSxHOZuMxgT/0mQgZxh7gStfpqdN31KGgdUUz94+TzBhTLnbxnhsB8iLT7MZbAqBoxAtyYVNYDjM/1cQ64UyZ43PHhgDIK2B9A91BdYyMSO9rZfOuAy+Hmxr7O9ed42FOAUEjp+aSOukkyqhd3D7iIyGQys6kbn0" Nov 21 15:42:52 volumio go-librespot[22400]: time="2024-11-21T15:42:52-03:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 21 15:42:52 volumio go-librespot[22400]: time="2024-11-21T15:42:52-03:00" level=debug msg="completed keyexchange" Nov 21 15:42:52 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Nov 21 15:42:52 volumio volumio[943]: info: Connection to go-librespot Websocket established Nov 21 15:42:52 volumio go-librespot[22400]: time="2024-11-21T15:42:52-03:00" level=debug msg="new websocket client" Nov 21 15:42:52 volumio go-librespot[22400]: time="2024-11-21T15:42:52-03:00" level=debug msg="completed challenge" Nov 21 15:42:53 volumio go-librespot[22400]: time="2024-11-21T15:42:53-03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 15:42:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 15:42:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 15:42:53 volumio volumio[943]: info: Connection to go-librespot Websocket closed Nov 21 15:42:55 volumio volumio[943]: info: Getting Spotify volume Nov 21 15:42:55 volumio volumio[943]: (node:943) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 15:42:55 volumio volumio[943]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Nov 21 15:42:55 volumio volumio[943]: (node:943) 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: 592) Nov 21 15:42:55 volumio volumio[943]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Nov 21 15:42:55 volumio volumio[943]: info: CoreCommandRouter::volumioGetState Nov 21 15:42:55 volumio volumio[943]: info: CorePlayQueue::getTrack 44 Nov 21 15:42:55 volumio volumio[943]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Nov 21 15:42:55 volumio wpa_supplicant[867]: wlan0: Failed to initiate sched scan Nov 21 15:42:56 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Nov 21 15:42:56 volumio volumio[943]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 15:42:56 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 15:42:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1855. Nov 21 15:42:56 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 15:42:56 volumio systemd[1]: Started go-librespot Daemon. Nov 21 15:42:56 volumio go-librespot[22409]: Librespot-go daemon starting... Nov 21 15:42:56 volumio go-librespot[22409]: time="2024-11-21T15:42:56-03:00" level=info msg="generated new device id: 726869681d5a49642db337f1118af2d406274337" Nov 21 15:42:56 volumio go-librespot[22409]: time="2024-11-21T15:42:56-03:00" level=debug msg="stored credentials found for 31cybqphgdep7z6rmbplp2d4cyym" Nov 21 15:42:56 volumio go-librespot[22409]: time="2024-11-21T15:42:56-03:00" level=debug msg="obtained new client token: AABstwA0eWuxWc3Gfiy1XAqLbIB+37gIyEpKLmmpn3nMMRRZh2/o9RHv1JMEpGexSNW6acwitRNr2rHnMH7dMYFmppEkGyRTPC70ObJTU4Nkclzw4mQIsn9F34cnIO3Kcvlk+g2Pb5fezcXGGy1dOJC8srK1GpjFcyiuv36hlXQCe3Gm++cwcPvCrilW3Pu7QkK78ys+R40U9/fvWymvsw8X3X5YrhUsUNvpuz+yegQ1KuyZ5tcMITS36aW5VxfE" Nov 21 15:42:57 volumio go-librespot[22409]: time="2024-11-21T15:42:57-03:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 21 15:42:57 volumio go-librespot[22409]: time="2024-11-21T15:42:57-03:00" level=debug msg="completed keyexchange" Nov 21 15:42:57 volumio go-librespot[22409]: time="2024-11-21T15:42:57-03:00" level=debug msg="completed challenge" Nov 21 15:42:58 volumio go-librespot[22409]: time="2024-11-21T15:42:58-03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 15:42:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 15:42:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 15:42:59 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Nov 21 15:42:59 volumio volumio[943]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 15:43:01 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 15:43:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1856. Nov 21 15:43:01 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 15:43:01 volumio systemd[1]: Started go-librespot Daemon. Nov 21 15:43:01 volumio go-librespot[22417]: Librespot-go daemon starting... Nov 21 15:43:01 volumio go-librespot[22417]: time="2024-11-21T15:43:01-03:00" level=info msg="generated new device id: 2c98607f244ebcb5953b5d8e3dd6d7d58503eca3" Nov 21 15:43:01 volumio go-librespot[22417]: time="2024-11-21T15:43:01-03:00" level=debug msg="stored credentials found for 31cybqphgdep7z6rmbplp2d4cyym" Nov 21 15:43:01 volumio go-librespot[22417]: time="2024-11-21T15:43:01-03:00" level=debug msg="obtained new client token: AABtJyxhBBYa/glmvwnfxF4s9BYuwk5yIVIZeQTkJbfeZ7Ef3e/TQo/QOz9tWK01tuZkKrTW5svPpBEH4/QqbV8Qrr1oJBzJW/PNCLk4vCsNhSNm2YCd/5ogAI0jl2wWiVr0GWCk1OLhHtzoH2Whi/lupwArIZPvtYAsu1Ug5JRaIO2ws1yK3driqcLpsTswxvJ0NE8WRiUzTWYsFjoE85aFbqJDNw3elN7r5VvPtQ91w4AQv2tWGLmzLdkhg5ee" Nov 21 15:43:01 volumio go-librespot[22417]: time="2024-11-21T15:43:01-03:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 21 15:43:02 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Nov 21 15:43:02 volumio go-librespot[22417]: time="2024-11-21T15:43:02-03:00" level=debug msg="new websocket client" Nov 21 15:43:02 volumio volumio[943]: info: Connection to go-librespot Websocket established Nov 21 15:43:02 volumio go-librespot[22417]: time="2024-11-21T15:43:02-03:00" level=debug msg="completed keyexchange" Nov 21 15:43:02 volumio go-librespot[22417]: time="2024-11-21T15:43:02-03:00" level=debug msg="completed challenge" Nov 21 15:43:03 volumio go-librespot[22417]: time="2024-11-21T15:43:03-03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 15:43:03 volumio volumio[943]: info: Connection to go-librespot Websocket closed Nov 21 15:43:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 15:43:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 15:43:03 volumio wpa_supplicant[867]: wlan0: Failed to initiate sched scan Nov 21 15:43:05 volumio volumio[943]: info: Getting Spotify volume Nov 21 15:43:05 volumio volumio[943]: (node:943) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 15:43:05 volumio volumio[943]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Nov 21 15:43:05 volumio volumio[943]: (node:943) 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: 593) Nov 21 15:43:05 volumio volumio[943]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Nov 21 15:43:05 volumio volumio[943]: info: CoreCommandRouter::volumioGetState Nov 21 15:43:05 volumio volumio[943]: info: CorePlayQueue::getTrack 44 Nov 21 15:43:05 volumio volumio[943]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Nov 21 15:43:06 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Nov 21 15:43:06 volumio volumio[943]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 15:43:06 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 15:43:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1857. Nov 21 15:43:06 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 15:43:06 volumio systemd[1]: Started go-librespot Daemon. Nov 21 15:43:06 volumio go-librespot[22425]: Librespot-go daemon starting... Nov 21 15:43:06 volumio go-librespot[22425]: time="2024-11-21T15:43:06-03:00" level=info msg="generated new device id: 2b8fe3c060af55df9e54d12096c2814ffc9c7ecd" Nov 21 15:43:06 volumio go-librespot[22425]: time="2024-11-21T15:43:06-03:00" level=debug msg="stored credentials found for 31cybqphgdep7z6rmbplp2d4cyym" Nov 21 15:43:06 volumio go-librespot[22425]: time="2024-11-21T15:43:06-03:00" level=debug msg="obtained new client token: AABDgcIrtVbSamNI1d9Hh+EHF7vE2hqPZ40z9zxFg4gBVYAW+LLmuXyy7afOK7IlDXpbk3WCSTbq9sVcRBJJ50VXGMXCWAgfmAxqz9Fpjj2GA6BomE2NW12qyZEzOLZE2IbKXXSIZgw+FkEf7WI8hueMaD4LJG1MFuVm6LApb7EfP8h4J8CUX3zvOTTcQhCEcJx8b/w8zxAuQjISnv251/OFg+I9Sk9G4YbondrIwHcOL9KEv6oBSNP0R+MxJWaF" Nov 21 15:43:06 volumio go-librespot[22425]: time="2024-11-21T15:43:06-03:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Nov 21 15:43:07 volumio go-librespot[22425]: time="2024-11-21T15:43:07-03:00" level=debug msg="completed keyexchange" Nov 21 15:43:07 volumio go-librespot[22425]: time="2024-11-21T15:43:07-03:00" level=debug msg="completed challenge" Nov 21 15:43:07 volumio go-librespot[22425]: time="2024-11-21T15:43:07-03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 15:43:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 15:43:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 15:43:09 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Nov 21 15:43:09 volumio volumio[943]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 15:43:11 volumio wpa_supplicant[867]: wlan0: Failed to initiate sched scan Nov 21 15:43:11 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 15:43:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1858. Nov 21 15:43:11 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 15:43:11 volumio systemd[1]: Started go-librespot Daemon. Nov 21 15:43:11 volumio go-librespot[22433]: Librespot-go daemon starting... Nov 21 15:43:11 volumio go-librespot[22433]: time="2024-11-21T15:43:11-03:00" level=info msg="generated new device id: 967a64ab8730f6836c93c2ed79100b05b4f680d2" Nov 21 15:43:11 volumio go-librespot[22433]: time="2024-11-21T15:43:11-03:00" level=debug msg="stored credentials found for 31cybqphgdep7z6rmbplp2d4cyym" Nov 21 15:43:11 volumio go-librespot[22433]: time="2024-11-21T15:43:11-03:00" level=debug msg="obtained new client token: AADEVPBQJe+VOZIMD/a3eQ+8BlCJHLxOjeI9h4o2yzxGlhV0s9ivOkUm/wa5PY79tS4h8/J89ZAeD95umhJJUyKdUroKqGQdB0z7FJK2GaUprYS97is0cmERpHJellZpBcG/IOnpKdmBaz6XCVURLarKNPvJZpIAd051UE/TLFWeMZae01OMYjwNF7oVaBUtSk/vMsRgWw5J8iGoDqrJJJ8dKMLPX+tuaFbfpFAOXc0cSNL1XmPj9CxR0FQ/vesF" Nov 21 15:43:11 volumio go-librespot[22433]: time="2024-11-21T15:43:11-03:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 21 15:43:12 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Nov 21 15:43:12 volumio go-librespot[22433]: time="2024-11-21T15:43:12-03:00" level=debug msg="new websocket client" Nov 21 15:43:12 volumio volumio[943]: info: Connection to go-librespot Websocket established Nov 21 15:43:12 volumio go-librespot[22433]: time="2024-11-21T15:43:12-03:00" level=debug msg="completed keyexchange" Nov 21 15:43:12 volumio go-librespot[22433]: time="2024-11-21T15:43:12-03:00" level=debug msg="completed challenge" Nov 21 15:43:12 volumio go-librespot[22433]: time="2024-11-21T15:43:12-03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 21 15:43:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 21 15:43:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 21 15:43:12 volumio volumio[943]: info: Connection to go-librespot Websocket closed Nov 21 15:43:15 volumio volumio[943]: info: Getting Spotify volume Nov 21 15:43:15 volumio volumio[943]: (node:943) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 21 15:43:15 volumio volumio[943]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Nov 21 15:43:15 volumio volumio[943]: (node:943) 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: 594) Nov 21 15:43:15 volumio volumio[943]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Nov 21 15:43:15 volumio volumio[943]: info: CoreCommandRouter::volumioGetState Nov 21 15:43:15 volumio volumio[943]: info: CorePlayQueue::getTrack 44 Nov 21 15:43:15 volumio volumio[943]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Nov 21 15:43:15 volumio volumio[943]: verbose: New Socket.io Connection to 172.17.102.58 from 172.17.102.100 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/131.0.0.0 Safari/537.36 Edg/131.0.0.0 Engine version: 3 Transport: polling Total Clients: 5 Nov 21 15:43:15 volumio volumio[943]: info: CoreCommandRouter::volumioGetState Nov 21 15:43:15 volumio volumio[943]: info: CorePlayQueue::getTrack 44 Nov 21 15:43:15 volumio volumio[943]: info: Received Get System Info Nov 21 15:43:15 volumio volumio[943]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 21 15:43:15 volumio volumio[943]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 21 15:43:15 volumio volumio[943]: info: Discovery: Getting this device information Nov 21 15:43:15 volumio volumio[943]: info: CoreCommandRouter::volumioGetState Nov 21 15:43:15 volumio volumio[943]: info: CorePlayQueue::getTrack 44 Nov 21 15:43:15 volumio volumio[943]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 21 15:43:15 volumio volumio[943]: info: CoreCommandRouter::volumioGetState Nov 21 15:43:15 volumio volumio[943]: info: CorePlayQueue::getTrack 44 Nov 21 15:43:15 volumio volumio[943]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 21 15:43:15 volumio volumio[943]: Error: EIO: i/o error, scandir '/data/plugins/' Nov 21 15:43:15 volumio volumio[943]: at Object.readdirSync (fs.js:1021:3) Nov 21 15:43:15 volumio volumio[943]: at PluginManager.getInstalledPlugins (/volumio/app/pluginmanager.js:1627:30) Nov 21 15:43:15 volumio volumio[943]: at CoreCommandRouter.getInstalledPlugins (/volumio/app/index.js:1521:29) Nov 21 15:43:15 volumio volumio[943]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1321:45) Nov 21 15:43:15 volumio volumio[943]: at Socket.emit (events.js:315:20) Nov 21 15:43:15 volumio volumio[943]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Nov 21 15:43:15 volumio volumio[943]: at processTicksAndRejections (internal/process/task_queues.js:75:11) { Nov 21 15:43:15 volumio volumio[943]: errno: -5, Nov 21 15:43:15 volumio volumio[943]: syscall: 'scandir', Nov 21 15:43:15 volumio volumio[943]: code: 'EIO', Nov 21 15:43:15 volumio volumio[943]: path: '/data/plugins/' Nov 21 15:43:15 volumio volumio[943]: } Nov 21 15:43:15 volumio volumio[943]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 21 15:43:15 volumio kernel: EXT4-fs warning (device mmcblk0p3): htree_dirblock_to_tree:1082: inode #524389: lblock 0: comm node: error -5 reading directory block Nov 21 15:43:15 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 21 15:43:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1859. Nov 21 15:43:15 volumio systemd[1]: Stopped go-librespot Daemon. Nov 21 15:43:16 volumio systemd[1]: Started go-librespot Daemon. Nov 21 15:43:16 volumio go-librespot[22448]: Librespot-go daemon starting... Nov 21 15:43:16 volumio go-librespot[22448]: time="2024-11-21T15:43:16-03:00" level=info msg="generated new device id: 5d36697672ed402e54ef1901dcbba769a7b212fd" Nov 21 15:43:16 volumio go-librespot[22448]: time="2024-11-21T15:43:16-03:00" level=debug msg="stored credentials found for 31cybqphgdep7z6rmbplp2d4cyym" Nov 21 15:43:16 volumio sudo[22458]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-21 15:42 Nov 21 15:43:16 volumio sudo[22458]: 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="4b122b2365bb8c09786cd63b50d1ea6db780eb4e" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="49f98390f2d84c6549f33dc85b694fbd99e4c720" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 04 Jun 2024 08:41:12 PM CEST" VOLUMIO_VERSION="3.703" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="8e78a6e3f56f1bcbbd1760812129a8e9"