-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Sat 2025-02-15 10:31:42 CET. -- Feb 15 10:30:00 volumio go-librespot[4357]: time="2025-02-15T10:30:00+01:00" level=info msg="generated new device id: 093ea12caa8e01d380541770963fa74a33c3422f" Feb 15 10:30:00 volumio go-librespot[4357]: time="2025-02-15T10:30:00+01:00" level=debug msg="stored credentials found for motobowaq" Feb 15 10:30:00 volumio go-librespot[4357]: time="2025-02-15T10:30:00+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 15 10:30:00 volumio go-librespot[4357]: time="2025-02-15T10:30:00+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 15 10:30:00 volumio go-librespot[4357]: time="2025-02-15T10:30:00+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 15 10:30:00 volumio go-librespot[4357]: time="2025-02-15T10:30:00+01:00" level=debug msg="zeroconf server listening on port 34699" Feb 15 10:30:00 volumio go-librespot[4357]: time="2025-02-15T10:30:00+01:00" level=debug msg="obtained new client token: AABeRmiIaHUKIImnIa9WW5EhleG+LxSLBeceAhDD5Q4aEJ9FCzbNLegOaMrZeJcO2Li2ZE8yUOYWDwG0shHxQlPkrqgRUA4YJJTVEHuoR2qiSWSkf5QJUCcNkDh85sms1io1Kng2UDQD97JKU27z29FrWULqv24PIPogvrZiUBS0ATeECKQXvqICfdWpjZ0TgDGfDt4IJ4SvrfNMP+SWZ05lCVAk+VI6gmfH09azsNFoiJD8SOMx7mHyS5k=" Feb 15 10:30:00 volumio go-librespot[4357]: time="2025-02-15T10:30:00+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 15 10:30:00 volumio go-librespot[4357]: time="2025-02-15T10:30:00+01:00" level=debug msg="completed keyexchange" Feb 15 10:30:01 volumio volumio[963]: info: Initializing connection to go-librespot Websocket Feb 15 10:30:01 volumio go-librespot[4357]: time="2025-02-15T10:30:01+01:00" level=debug msg="new websocket client" Feb 15 10:30:01 volumio volumio[963]: info: Connection to go-librespot Websocket established Feb 15 10:30:01 volumio go-librespot[4357]: time="2025-02-15T10:30:01+01:00" level=debug msg="completed challenge" Feb 15 10:30:01 volumio go-librespot[4357]: time="2025-02-15T10:30:01+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 15 10:30:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 15 10:30:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 15 10:30:01 volumio volumio[963]: info: Connection to go-librespot Websocket closed Feb 15 10:30:04 volumio volumio[963]: info: Getting Spotify volume Feb 15 10:30:04 volumio volumio[963]: (node:963) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 15 10:30:04 volumio volumio[963]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Feb 15 10:30:04 volumio volumio[963]: (node:963) 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: 58) Feb 15 10:30:04 volumio volumio[963]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Feb 15 10:30:04 volumio volumio[963]: info: CoreCommandRouter::volumioGetState Feb 15 10:30:04 volumio volumio[963]: info: CorePlayQueue::getTrack 0 Feb 15 10:30:04 volumio volumio[963]: SPOTIFY: RECEIVED VOLUMIO VOLUME 57 Feb 15 10:30:04 volumio volumio[963]: info: Initializing connection to go-librespot Websocket Feb 15 10:30:04 volumio volumio[963]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 15 10:30:04 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 15 10:30:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 136. Feb 15 10:30:04 volumio systemd[1]: Stopped go-librespot Daemon. Feb 15 10:30:04 volumio systemd[1]: Started go-librespot Daemon. Feb 15 10:30:04 volumio go-librespot[4379]: Librespot-go daemon starting... Feb 15 10:30:04 volumio go-librespot[4379]: time="2025-02-15T10:30:04+01:00" level=info msg="generated new device id: 87d16528f37aad9d26af64fc1f34557eda84aa8e" Feb 15 10:30:04 volumio go-librespot[4379]: time="2025-02-15T10:30:04+01:00" level=debug msg="stored credentials found for motobowaq" Feb 15 10:30:05 volumio go-librespot[4379]: time="2025-02-15T10:30:05+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 15 10:30:05 volumio go-librespot[4379]: time="2025-02-15T10:30:05+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 15 10:30:05 volumio go-librespot[4379]: time="2025-02-15T10:30:05+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 15 10:30:05 volumio go-librespot[4379]: time="2025-02-15T10:30:05+01:00" level=debug msg="zeroconf server listening on port 38485" Feb 15 10:30:05 volumio go-librespot[4379]: time="2025-02-15T10:30:05+01:00" level=debug msg="obtained new client token: AACUlHiHyPkQqB1uw/1sVNHZnW/aZT/gEIYwp6bKf9NjnpiiVwL+xP4W4YU+BxXTX8etS+jj5bayPp1W5XMkVEk8kB2DOu4xOoMACVN11GWAy59JA7BNGUQFOJI/a19WJUXZ4xdKotVciWXp0uRy3BaTKd7hD0FeQEtL8s+TIFGODT1VCOw6bV2Iw8WRa6ogdsUPXA99mdk0Mbn8tqq7hzvUZ/UIbi8SqAc5QwYJmjWv7936JTEpNrJF44o=" Feb 15 10:30:05 volumio go-librespot[4379]: time="2025-02-15T10:30:05+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 15 10:30:05 volumio go-librespot[4379]: time="2025-02-15T10:30:05+01:00" level=debug msg="completed keyexchange" Feb 15 10:30:06 volumio go-librespot[4379]: time="2025-02-15T10:30:06+01:00" level=debug msg="completed challenge" Feb 15 10:30:06 volumio go-librespot[4379]: time="2025-02-15T10:30:06+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 15 10:30:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 15 10:30:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 15 10:30:07 volumio volumio[963]: info: Initializing connection to go-librespot Websocket Feb 15 10:30:07 volumio volumio[963]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 15 10:30:09 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 15 10:30:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 137. Feb 15 10:30:09 volumio systemd[1]: Stopped go-librespot Daemon. Feb 15 10:30:09 volumio systemd[1]: Started go-librespot Daemon. Feb 15 10:30:09 volumio go-librespot[4428]: Librespot-go daemon starting... Feb 15 10:30:09 volumio go-librespot[4428]: time="2025-02-15T10:30:09+01:00" level=info msg="generated new device id: be117d6dbc91ff3d14828f313e6120aa381b3a54" Feb 15 10:30:09 volumio go-librespot[4428]: time="2025-02-15T10:30:09+01:00" level=debug msg="stored credentials found for motobowaq" Feb 15 10:30:10 volumio go-librespot[4428]: time="2025-02-15T10:30:10+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 15 10:30:10 volumio go-librespot[4428]: time="2025-02-15T10:30:10+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 15 10:30:10 volumio go-librespot[4428]: time="2025-02-15T10:30:10+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 15 10:30:10 volumio go-librespot[4428]: time="2025-02-15T10:30:10+01:00" level=debug msg="zeroconf server listening on port 44139" Feb 15 10:30:10 volumio go-librespot[4428]: time="2025-02-15T10:30:10+01:00" level=debug msg="obtained new client token: AAB3Vv1XACbvBzTnTqZatEOECetJ4DL+BcJbVgXp9xmznJirPWo+uOk0hGf1e6yyhq7t/XSQwG4uzZo9GNG/jzdEooaPYAQ3WL2KdtxcsP7KgBJNKENmG4c0uipnQ/D1GkRrh8FWOWn2Q8jy+LujXkwULjkHjBS+CzHYkCqeE/1ObvTcjwg4d2VJ9HGxlbza9RPK9RA87ScMeVeELEjVRt1UJaZj9ZzH24UGx6J9ld2wFS2/TCxAxSFQE40=" Feb 15 10:30:10 volumio go-librespot[4428]: time="2025-02-15T10:30:10+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 15 10:30:10 volumio go-librespot[4428]: time="2025-02-15T10:30:10+01:00" level=debug msg="completed keyexchange" Feb 15 10:30:10 volumio volumio[963]: info: Initializing connection to go-librespot Websocket Feb 15 10:30:10 volumio go-librespot[4428]: time="2025-02-15T10:30:10+01:00" level=debug msg="new websocket client" Feb 15 10:30:10 volumio volumio[963]: info: Connection to go-librespot Websocket established Feb 15 10:30:11 volumio go-librespot[4428]: time="2025-02-15T10:30:11+01:00" level=debug msg="completed challenge" Feb 15 10:30:11 volumio go-librespot[4428]: time="2025-02-15T10:30:11+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 15 10:30:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 15 10:30:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 15 10:30:11 volumio volumio[963]: info: Connection to go-librespot Websocket closed Feb 15 10:30:13 volumio volumio[963]: info: Getting Spotify volume Feb 15 10:30:13 volumio volumio[963]: (node:963) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 15 10:30:13 volumio volumio[963]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Feb 15 10:30:13 volumio volumio[963]: (node:963) 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: 59) Feb 15 10:30:13 volumio volumio[963]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Feb 15 10:30:13 volumio volumio[963]: info: CoreCommandRouter::volumioGetState Feb 15 10:30:13 volumio volumio[963]: info: CorePlayQueue::getTrack 0 Feb 15 10:30:13 volumio volumio[963]: SPOTIFY: RECEIVED VOLUMIO VOLUME 57 Feb 15 10:30:14 volumio volumio[963]: info: Initializing connection to go-librespot Websocket Feb 15 10:30:14 volumio volumio[963]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 15 10:30:14 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 15 10:30:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 138. Feb 15 10:30:14 volumio systemd[1]: Stopped go-librespot Daemon. Feb 15 10:30:14 volumio systemd[1]: Started go-librespot Daemon. Feb 15 10:30:14 volumio go-librespot[4450]: Librespot-go daemon starting... Feb 15 10:30:14 volumio go-librespot[4450]: time="2025-02-15T10:30:14+01:00" level=info msg="generated new device id: 8ddb1be0d113cfd9a3d2a58d93534d293722758b" Feb 15 10:30:14 volumio go-librespot[4450]: time="2025-02-15T10:30:14+01:00" level=debug msg="stored credentials found for motobowaq" Feb 15 10:30:14 volumio go-librespot[4450]: time="2025-02-15T10:30:14+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 15 10:30:14 volumio go-librespot[4450]: time="2025-02-15T10:30:14+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 15 10:30:14 volumio go-librespot[4450]: time="2025-02-15T10:30:14+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 15 10:30:14 volumio go-librespot[4450]: time="2025-02-15T10:30:14+01:00" level=debug msg="zeroconf server listening on port 40097" Feb 15 10:30:15 volumio go-librespot[4450]: time="2025-02-15T10:30:15+01:00" level=debug msg="obtained new client token: AAAfX/g/sFgEyTkV0RA6L7IKP53av0CekLBQg4A3viY3+CvF3HsabVUydQUdPERIfNlMfzHrcOtCxkYRl8laZhSuEvLSgAhTPmHym0JG+4lv9vN8kDRPFOzAfkQh74WSlo5lkbK6d3ljIffzRn17YNM2SoIeQlLwt5fhLUBg8w27VkOsGUjPGeXG0WsrP7YJKcT+DTBl8J2gxp9Dsz1XGq084BWBknehdJbo+6H/YdWzihtWDn7SLsC3" Feb 15 10:30:15 volumio go-librespot[4450]: time="2025-02-15T10:30:15+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 15 10:30:15 volumio go-librespot[4450]: time="2025-02-15T10:30:15+01:00" level=debug msg="completed keyexchange" Feb 15 10:30:15 volumio go-librespot[4450]: time="2025-02-15T10:30:15+01:00" level=debug msg="completed challenge" Feb 15 10:30:16 volumio go-librespot[4450]: time="2025-02-15T10:30:16+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 15 10:30:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 15 10:30:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 15 10:30:17 volumio volumio[963]: info: Initializing connection to go-librespot Websocket Feb 15 10:30:17 volumio volumio[963]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 15 10:30:19 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 15 10:30:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 139. Feb 15 10:30:19 volumio systemd[1]: Stopped go-librespot Daemon. Feb 15 10:30:19 volumio systemd[1]: Started go-librespot Daemon. Feb 15 10:30:19 volumio go-librespot[4462]: Librespot-go daemon starting... Feb 15 10:30:19 volumio go-librespot[4462]: time="2025-02-15T10:30:19+01:00" level=info msg="generated new device id: c54faae1d6ac95ff46e72ae085b521709d3f2d4f" Feb 15 10:30:19 volumio go-librespot[4462]: time="2025-02-15T10:30:19+01:00" level=debug msg="stored credentials found for motobowaq" Feb 15 10:30:20 volumio go-librespot[4462]: time="2025-02-15T10:30:20+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 15 10:30:20 volumio go-librespot[4462]: time="2025-02-15T10:30:20+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 15 10:30:20 volumio go-librespot[4462]: time="2025-02-15T10:30:20+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 15 10:30:20 volumio go-librespot[4462]: time="2025-02-15T10:30:20+01:00" level=debug msg="zeroconf server listening on port 46209" Feb 15 10:30:20 volumio go-librespot[4462]: time="2025-02-15T10:30:20+01:00" level=debug msg="obtained new client token: AAB/BbD8zJCfsoOOw++rsiDtZbvBsDCcCEI+pkKqGNwmxSZur49IPUg6amCDMPW1j636cu4dfn+22SKMeHpklf8F/0qp3TTmfyYF056kduTWQWcugFeMZMmwQlDfBLcHcPQdLDOR+3YDn19ndGlBtzultQCnsdjGAlXei3J5q0s8KRHNUFA/mnSa+AvoFUkZnrZamWSj86rjAnLqTHOUkXWq+NNjn2lo8MiTr0NTSNANo0GZan94BNx+" Feb 15 10:30:20 volumio volumio[963]: info: Initializing connection to go-librespot Websocket Feb 15 10:30:20 volumio go-librespot[4462]: time="2025-02-15T10:30:20+01:00" level=debug msg="new websocket client" Feb 15 10:30:20 volumio volumio[963]: info: Connection to go-librespot Websocket established Feb 15 10:30:20 volumio go-librespot[4462]: time="2025-02-15T10:30:20+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 15 10:30:20 volumio go-librespot[4462]: time="2025-02-15T10:30:20+01:00" level=debug msg="completed keyexchange" Feb 15 10:30:20 volumio go-librespot[4462]: time="2025-02-15T10:30:20+01:00" level=debug msg="completed challenge" Feb 15 10:30:21 volumio go-librespot[4462]: time="2025-02-15T10:30:21+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 15 10:30:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 15 10:30:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 15 10:30:21 volumio volumio[963]: info: Connection to go-librespot Websocket closed Feb 15 10:30:23 volumio volumio[963]: info: Getting Spotify volume Feb 15 10:30:23 volumio volumio[963]: (node:963) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 15 10:30:23 volumio volumio[963]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Feb 15 10:30:23 volumio volumio[963]: (node:963) 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: 60) Feb 15 10:30:23 volumio volumio[963]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Feb 15 10:30:23 volumio volumio[963]: info: CoreCommandRouter::volumioGetState Feb 15 10:30:23 volumio volumio[963]: info: CorePlayQueue::getTrack 0 Feb 15 10:30:23 volumio volumio[963]: SPOTIFY: RECEIVED VOLUMIO VOLUME 57 Feb 15 10:30:24 volumio volumio[963]: info: Initializing connection to go-librespot Websocket Feb 15 10:30:24 volumio volumio[963]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 15 10:30:24 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 15 10:30:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 140. Feb 15 10:30:24 volumio systemd[1]: Stopped go-librespot Daemon. Feb 15 10:30:24 volumio systemd[1]: Started go-librespot Daemon. Feb 15 10:30:24 volumio go-librespot[4484]: Librespot-go daemon starting... Feb 15 10:30:24 volumio go-librespot[4484]: time="2025-02-15T10:30:24+01:00" level=info msg="generated new device id: 4c26dd40c5353ee998864affe4520ad3a1e46e96" Feb 15 10:30:24 volumio go-librespot[4484]: time="2025-02-15T10:30:24+01:00" level=debug msg="stored credentials found for motobowaq" Feb 15 10:30:24 volumio go-librespot[4484]: time="2025-02-15T10:30:24+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 15 10:30:24 volumio go-librespot[4484]: time="2025-02-15T10:30:24+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 15 10:30:24 volumio go-librespot[4484]: time="2025-02-15T10:30:24+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 15 10:30:24 volumio go-librespot[4484]: time="2025-02-15T10:30:24+01:00" level=debug msg="zeroconf server listening on port 40473" Feb 15 10:30:25 volumio go-librespot[4484]: time="2025-02-15T10:30:25+01:00" level=debug msg="obtained new client token: AACYG6YC1OzcWDmfkUFzQxl7lRNB9dbaNSYpnw14wDnS0hYmgfrS14P82GAS7kNNLYTKxqj1Ngrcn48wmSUHE6Qktv7cJTYIoI/+v5V9tiUB9354qWkZvdqMmm+E/OlOMBRD+vNiS9NueQSAQiUC4HZUrJLDF3Lg5hodxZKD1XDPJXlOC+SUwCJa+o6V+/kDjBWCrPGGbhWZXbI2XRXnF/Nu7Me/0scAc+1CBKAsVJMmZyhihzCC30Bp" Feb 15 10:30:25 volumio go-librespot[4484]: time="2025-02-15T10:30:25+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 15 10:30:25 volumio go-librespot[4484]: time="2025-02-15T10:30:25+01:00" level=debug msg="completed keyexchange" Feb 15 10:30:25 volumio go-librespot[4484]: time="2025-02-15T10:30:25+01:00" level=debug msg="completed challenge" Feb 15 10:30:26 volumio go-librespot[4484]: time="2025-02-15T10:30:26+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 15 10:30:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 15 10:30:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 15 10:30:27 volumio volumio[963]: info: Initializing connection to go-librespot Websocket Feb 15 10:30:27 volumio volumio[963]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 15 10:30:29 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 15 10:30:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 141. Feb 15 10:30:29 volumio systemd[1]: Stopped go-librespot Daemon. Feb 15 10:30:29 volumio systemd[1]: Started go-librespot Daemon. Feb 15 10:30:29 volumio go-librespot[4495]: Librespot-go daemon starting... Feb 15 10:30:29 volumio go-librespot[4495]: time="2025-02-15T10:30:29+01:00" level=info msg="generated new device id: cd8e89a36ec3c73470597d4edd03531ec9aca931" Feb 15 10:30:29 volumio go-librespot[4495]: time="2025-02-15T10:30:29+01:00" level=debug msg="stored credentials found for motobowaq" Feb 15 10:30:29 volumio go-librespot[4495]: time="2025-02-15T10:30:29+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 15 10:30:29 volumio go-librespot[4495]: time="2025-02-15T10:30:29+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 15 10:30:29 volumio go-librespot[4495]: time="2025-02-15T10:30:29+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 15 10:30:29 volumio go-librespot[4495]: time="2025-02-15T10:30:29+01:00" level=debug msg="zeroconf server listening on port 43225" Feb 15 10:30:29 volumio go-librespot[4495]: time="2025-02-15T10:30:29+01:00" level=debug msg="obtained new client token: AADZlzV1//xs86SAhsuOhJ8qR50BggevEyz/TNwCTyrg/TsT36jyikcsS/rYu1pQxpnwu3sakKfrdSHm+xAyDCBv1mlDkH4V8X8XiRSHH6FQircQpUexl3ZgRVpaKAvnmofLm8YvXm+427au6AjAi5bVGeIRLdxVkopio0j3BrTC7DKRVQBAelJS4ulbviCDTUZ0/mr4aDWaHXpjfCihH0qWzhX9W+qenS5h43OXKhs0kJdEvYNWrJOVoT4=" Feb 15 10:30:29 volumio go-librespot[4495]: time="2025-02-15T10:30:29+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 15 10:30:30 volumio go-librespot[4495]: time="2025-02-15T10:30:30+01:00" level=debug msg="completed keyexchange" Feb 15 10:30:30 volumio volumio[963]: info: Initializing connection to go-librespot Websocket Feb 15 10:30:30 volumio go-librespot[4495]: time="2025-02-15T10:30:30+01:00" level=debug msg="new websocket client" Feb 15 10:30:30 volumio volumio[963]: info: Connection to go-librespot Websocket established Feb 15 10:30:30 volumio go-librespot[4495]: time="2025-02-15T10:30:30+01:00" level=debug msg="completed challenge" Feb 15 10:30:30 volumio go-librespot[4495]: time="2025-02-15T10:30:30+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 15 10:30:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 15 10:30:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 15 10:30:30 volumio volumio[963]: info: Connection to go-librespot Websocket closed Feb 15 10:30:33 volumio volumio[963]: info: Getting Spotify volume Feb 15 10:30:33 volumio volumio[963]: (node:963) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 15 10:30:33 volumio volumio[963]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Feb 15 10:30:33 volumio volumio[963]: (node:963) 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: 61) Feb 15 10:30:33 volumio volumio[963]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Feb 15 10:30:33 volumio volumio[963]: info: CoreCommandRouter::volumioGetState Feb 15 10:30:33 volumio volumio[963]: info: CorePlayQueue::getTrack 0 Feb 15 10:30:33 volumio volumio[963]: SPOTIFY: RECEIVED VOLUMIO VOLUME 57 Feb 15 10:30:33 volumio volumio[963]: info: Initializing connection to go-librespot Websocket Feb 15 10:30:33 volumio volumio[963]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 15 10:30:33 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 15 10:30:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 142. Feb 15 10:30:33 volumio systemd[1]: Stopped go-librespot Daemon. Feb 15 10:30:33 volumio systemd[1]: Started go-librespot Daemon. Feb 15 10:30:33 volumio go-librespot[4518]: Librespot-go daemon starting... Feb 15 10:30:34 volumio go-librespot[4518]: time="2025-02-15T10:30:34+01:00" level=info msg="generated new device id: bc0a5fa750c6ff4ff91dce58abee3dcb662d8021" Feb 15 10:30:34 volumio go-librespot[4518]: time="2025-02-15T10:30:34+01:00" level=debug msg="stored credentials found for motobowaq" Feb 15 10:30:34 volumio go-librespot[4518]: time="2025-02-15T10:30:34+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 15 10:30:34 volumio go-librespot[4518]: time="2025-02-15T10:30:34+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 15 10:30:34 volumio go-librespot[4518]: time="2025-02-15T10:30:34+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 15 10:30:34 volumio go-librespot[4518]: time="2025-02-15T10:30:34+01:00" level=debug msg="zeroconf server listening on port 45961" Feb 15 10:30:34 volumio go-librespot[4518]: time="2025-02-15T10:30:34+01:00" level=debug msg="obtained new client token: AADASN8NgR4fEx9sPSpVbaOxMytfgHn4YcW1HvfQjxBu1tmOgDtfT14bKeysDIA7ETDYnBgxDEjevxPHGkqMrT5S2Vg4RFQbRr99+3pD7X/6q+zPCHqSjJ6SdHJE2xTSwOm3bU6Oo1I2vlw1+4zEL3DKqwQc6kf+qGHa9aFx6OOUvuazYcX+bMQD+ZgKLrTNvNnLgZnQJ1Ox/2gqy8fPZ0viQ3rsVySuKVnX6Ygy2KTDZT6KXdHSflP/9xs=" Feb 15 10:30:34 volumio go-librespot[4518]: time="2025-02-15T10:30:34+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 15 10:30:34 volumio go-librespot[4518]: time="2025-02-15T10:30:34+01:00" level=debug msg="completed keyexchange" Feb 15 10:30:35 volumio go-librespot[4518]: time="2025-02-15T10:30:35+01:00" level=debug msg="completed challenge" Feb 15 10:30:35 volumio go-librespot[4518]: time="2025-02-15T10:30:35+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 15 10:30:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 15 10:30:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 15 10:30:36 volumio volumio[963]: info: Initializing connection to go-librespot Websocket Feb 15 10:30:36 volumio volumio[963]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 15 10:30:38 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 15 10:30:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 143. Feb 15 10:30:38 volumio systemd[1]: Stopped go-librespot Daemon. Feb 15 10:30:38 volumio systemd[1]: Started go-librespot Daemon. Feb 15 10:30:38 volumio go-librespot[4527]: Librespot-go daemon starting... Feb 15 10:30:38 volumio go-librespot[4527]: time="2025-02-15T10:30:38+01:00" level=info msg="generated new device id: 5c302c5501d23c75029b9dd09bbe77e1f1dab22c" Feb 15 10:30:38 volumio go-librespot[4527]: time="2025-02-15T10:30:38+01:00" level=debug msg="stored credentials found for motobowaq" Feb 15 10:30:39 volumio go-librespot[4527]: time="2025-02-15T10:30:39+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 15 10:30:39 volumio go-librespot[4527]: time="2025-02-15T10:30:39+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 15 10:30:39 volumio go-librespot[4527]: time="2025-02-15T10:30:39+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 15 10:30:39 volumio go-librespot[4527]: time="2025-02-15T10:30:39+01:00" level=debug msg="zeroconf server listening on port 36327" Feb 15 10:30:39 volumio go-librespot[4527]: time="2025-02-15T10:30:39+01:00" level=debug msg="obtained new client token: AAASJIOUob0IRIs+VYeiXFXKzDkKmMDvCnkEDjS9GpZHotxwuLT7yGuNqj8lO8X3ypu/7Tfx6mJTFFxuTjTYYLphXUfjS4YNWJ+4ZG4xbZ4eGHJhXTR8nibEU20VRr086yUf9xMsEfvPBhFXvaaSnuiXuo1JsZuCSB2IRFSN6Eyc2bWSrOVjpd84ao4ogizDk3O8ji7hGTPq4TVLJg+BYxr7+sbuQjJdaTtDQqQQoxPsJe4kd4VYJ2RYkPA=" Feb 15 10:30:39 volumio go-librespot[4527]: time="2025-02-15T10:30:39+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 15 10:30:39 volumio go-librespot[4527]: time="2025-02-15T10:30:39+01:00" level=debug msg="completed keyexchange" Feb 15 10:30:39 volumio volumio[963]: info: Initializing connection to go-librespot Websocket Feb 15 10:30:39 volumio go-librespot[4527]: time="2025-02-15T10:30:39+01:00" level=debug msg="new websocket client" Feb 15 10:30:39 volumio volumio[963]: info: Connection to go-librespot Websocket established Feb 15 10:30:40 volumio go-librespot[4527]: time="2025-02-15T10:30:40+01:00" level=debug msg="completed challenge" Feb 15 10:30:40 volumio go-librespot[4527]: time="2025-02-15T10:30:40+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 15 10:30:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 15 10:30:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 15 10:30:40 volumio volumio[963]: info: Connection to go-librespot Websocket closed Feb 15 10:30:42 volumio volumio[963]: info: Getting Spotify volume Feb 15 10:30:42 volumio volumio[963]: (node:963) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 15 10:30:42 volumio volumio[963]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Feb 15 10:30:42 volumio volumio[963]: (node:963) 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: 62) Feb 15 10:30:42 volumio volumio[963]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Feb 15 10:30:42 volumio volumio[963]: info: CoreCommandRouter::volumioGetState Feb 15 10:30:42 volumio volumio[963]: info: CorePlayQueue::getTrack 0 Feb 15 10:30:42 volumio volumio[963]: SPOTIFY: RECEIVED VOLUMIO VOLUME 57 Feb 15 10:30:43 volumio volumio[963]: info: Initializing connection to go-librespot Websocket Feb 15 10:30:43 volumio volumio[963]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 15 10:30:43 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 15 10:30:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 144. Feb 15 10:30:43 volumio systemd[1]: Stopped go-librespot Daemon. Feb 15 10:30:43 volumio systemd[1]: Started go-librespot Daemon. Feb 15 10:30:43 volumio go-librespot[4553]: Librespot-go daemon starting... Feb 15 10:30:43 volumio go-librespot[4553]: time="2025-02-15T10:30:43+01:00" level=info msg="generated new device id: 8a07ef1f2ef8100a3b9580afcf8832f8e728ca95" Feb 15 10:30:43 volumio go-librespot[4553]: time="2025-02-15T10:30:43+01:00" level=debug msg="stored credentials found for motobowaq" Feb 15 10:30:43 volumio go-librespot[4553]: time="2025-02-15T10:30:43+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 15 10:30:43 volumio go-librespot[4553]: time="2025-02-15T10:30:43+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 15 10:30:43 volumio go-librespot[4553]: time="2025-02-15T10:30:43+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 15 10:30:43 volumio go-librespot[4553]: time="2025-02-15T10:30:43+01:00" level=debug msg="zeroconf server listening on port 33045" Feb 15 10:30:44 volumio go-librespot[4553]: time="2025-02-15T10:30:44+01:00" level=debug msg="obtained new client token: AADJDhz/m+hC6dK6vDX1RY8psQxuEjAtKMoHTN67qUK/dRUzbCAoaHn6umGwBOy1PIZRgn6uBhifYoOs5sRF9pS/sUet0lQGC0iQtMXdHfSq69bjOx64lmj2ce3SzGqQ0pNQHG5w60TCt2vKURDzZlSff2oQHn+pqSVJi8AIxbnHfU8ixWPU1Bxg8pFtVNNKmQOkYJjFzwO5X8GqhhPQWBf45d+UdiodxdNmsg6qRhmvL5cgn/rMIuM9" Feb 15 10:30:44 volumio go-librespot[4553]: time="2025-02-15T10:30:44+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 15 10:30:44 volumio go-librespot[4553]: time="2025-02-15T10:30:44+01:00" level=debug msg="completed keyexchange" Feb 15 10:30:44 volumio go-librespot[4553]: time="2025-02-15T10:30:44+01:00" level=debug msg="completed challenge" Feb 15 10:30:45 volumio go-librespot[4553]: time="2025-02-15T10:30:45+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 15 10:30:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 15 10:30:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 15 10:30:46 volumio volumio[963]: info: Initializing connection to go-librespot Websocket Feb 15 10:30:46 volumio volumio[963]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 15 10:30:48 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 15 10:30:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 145. Feb 15 10:30:48 volumio systemd[1]: Stopped go-librespot Daemon. Feb 15 10:30:48 volumio systemd[1]: Started go-librespot Daemon. Feb 15 10:30:48 volumio go-librespot[4564]: Librespot-go daemon starting... Feb 15 10:30:49 volumio go-librespot[4564]: time="2025-02-15T10:30:49+01:00" level=info msg="generated new device id: bdd616870017e01805cff0829932ededa7e9e2b3" Feb 15 10:30:49 volumio go-librespot[4564]: time="2025-02-15T10:30:49+01:00" level=debug msg="stored credentials found for motobowaq" Feb 15 10:30:49 volumio volumio[963]: info: Initializing connection to go-librespot Websocket Feb 15 10:30:49 volumio go-librespot[4564]: time="2025-02-15T10:30:49+01:00" level=debug msg="new websocket client" Feb 15 10:30:49 volumio volumio[963]: info: Connection to go-librespot Websocket established Feb 15 10:30:49 volumio go-librespot[4564]: time="2025-02-15T10:30:49+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 15 10:30:49 volumio go-librespot[4564]: time="2025-02-15T10:30:49+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 15 10:30:49 volumio go-librespot[4564]: time="2025-02-15T10:30:49+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 15 10:30:49 volumio go-librespot[4564]: time="2025-02-15T10:30:49+01:00" level=debug msg="zeroconf server listening on port 38147" Feb 15 10:30:49 volumio go-librespot[4564]: time="2025-02-15T10:30:49+01:00" level=debug msg="obtained new client token: AABfpSOOxV0RyC0jp0ctZgwltaWksMDZ1Yto+/lEPjRs/ucRLN+T1pqVBLVHnBElscWDWbUAcYzcHa7Ov/byk5xFLVaxGWy5rzXgQiw9waTUclucgTRh5kBPqGHK04Nn+YtLxEh0cbvGD9Q3r1Bih8XclvKfaSF2TEYDcaxTJJWBMr8oGKEfWynvf5NAzv7HftpkSdxY8STh85aCfaRiq2bq+65cFRByDXPNUA6mqjrhY5cqVM+5Zg2v0BI=" Feb 15 10:30:49 volumio go-librespot[4564]: time="2025-02-15T10:30:49+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 15 10:30:49 volumio go-librespot[4564]: time="2025-02-15T10:30:49+01:00" level=debug msg="completed keyexchange" Feb 15 10:30:50 volumio go-librespot[4564]: time="2025-02-15T10:30:50+01:00" level=debug msg="completed challenge" Feb 15 10:30:50 volumio go-librespot[4564]: time="2025-02-15T10:30:50+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 15 10:30:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 15 10:30:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 15 10:30:50 volumio volumio[963]: info: Connection to go-librespot Websocket closed Feb 15 10:30:52 volumio volumio[963]: info: Getting Spotify volume Feb 15 10:30:52 volumio volumio[963]: (node:963) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 15 10:30:52 volumio volumio[963]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Feb 15 10:30:52 volumio volumio[963]: (node:963) 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: 63) Feb 15 10:30:52 volumio volumio[963]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Feb 15 10:30:52 volumio volumio[963]: info: CoreCommandRouter::volumioGetState Feb 15 10:30:52 volumio volumio[963]: info: CorePlayQueue::getTrack 0 Feb 15 10:30:52 volumio volumio[963]: SPOTIFY: RECEIVED VOLUMIO VOLUME 57 Feb 15 10:30:53 volumio volumio[963]: info: Initializing connection to go-librespot Websocket Feb 15 10:30:53 volumio volumio[963]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 15 10:30:53 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 15 10:30:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 146. Feb 15 10:30:53 volumio systemd[1]: Stopped go-librespot Daemon. Feb 15 10:30:53 volumio systemd[1]: Started go-librespot Daemon. Feb 15 10:30:53 volumio go-librespot[4587]: Librespot-go daemon starting... Feb 15 10:30:53 volumio go-librespot[4587]: time="2025-02-15T10:30:53+01:00" level=info msg="generated new device id: 2fb5a6318a55cc3f3b123976bda10c9aac20e634" Feb 15 10:30:53 volumio go-librespot[4587]: time="2025-02-15T10:30:53+01:00" level=debug msg="stored credentials found for motobowaq" Feb 15 10:30:54 volumio go-librespot[4587]: time="2025-02-15T10:30:54+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 15 10:30:54 volumio go-librespot[4587]: time="2025-02-15T10:30:54+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 15 10:30:54 volumio go-librespot[4587]: time="2025-02-15T10:30:54+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 15 10:30:54 volumio go-librespot[4587]: time="2025-02-15T10:30:54+01:00" level=debug msg="zeroconf server listening on port 41191" Feb 15 10:30:54 volumio go-librespot[4587]: time="2025-02-15T10:30:54+01:00" level=debug msg="obtained new client token: AADIbb66kGQS55n5H6YtOTh1P8qQh4auz52PZ4e/8QkwajoTWLEJJS/9I7zcFG6hGQgyCNgOaQbfeJ+sFjEFHT3QMxJuexIqjGQIXiHuFkipGpGH06KRSkbQaTgSZE4SRLpkiQqub0gQHkhCK03/oZPJYK48r84mluTSJs17pr3bAyZxKDtMGwTfUgttTeUpq/pXXshi8EFqe57KBUlPQX8yGfJNblL23MTHluyzSNXo8RIYOLxXF3ehOZg=" Feb 15 10:30:54 volumio go-librespot[4587]: time="2025-02-15T10:30:54+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 15 10:30:54 volumio go-librespot[4587]: time="2025-02-15T10:30:54+01:00" level=debug msg="completed keyexchange" Feb 15 10:30:55 volumio go-librespot[4587]: time="2025-02-15T10:30:55+01:00" level=debug msg="completed challenge" Feb 15 10:30:55 volumio go-librespot[4587]: time="2025-02-15T10:30:55+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 15 10:30:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 15 10:30:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 15 10:30:56 volumio volumio[963]: info: Initializing connection to go-librespot Websocket Feb 15 10:30:56 volumio volumio[963]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 15 10:30:58 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 15 10:30:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 147. Feb 15 10:30:58 volumio systemd[1]: Stopped go-librespot Daemon. Feb 15 10:30:58 volumio systemd[1]: Started go-librespot Daemon. Feb 15 10:30:58 volumio go-librespot[4596]: Librespot-go daemon starting... Feb 15 10:30:58 volumio go-librespot[4596]: time="2025-02-15T10:30:58+01:00" level=info msg="generated new device id: ee3f5c585ec7e54245593ade7a66432c48f26da6" Feb 15 10:30:58 volumio go-librespot[4596]: time="2025-02-15T10:30:58+01:00" level=debug msg="stored credentials found for motobowaq" Feb 15 10:30:59 volumio go-librespot[4596]: time="2025-02-15T10:30:59+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 15 10:30:59 volumio go-librespot[4596]: time="2025-02-15T10:30:59+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 15 10:30:59 volumio go-librespot[4596]: time="2025-02-15T10:30:59+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 15 10:30:59 volumio go-librespot[4596]: time="2025-02-15T10:30:59+01:00" level=debug msg="zeroconf server listening on port 38333" Feb 15 10:30:59 volumio go-librespot[4596]: time="2025-02-15T10:30:59+01:00" level=debug msg="obtained new client token: AAAZJqjZoxNRJ3NBxlx25GuuMb6QSjkKNP9H46L2VwwGw+8B0xf/UB9mENB7BP3T8jP5YP1QM68Xdh226coXzk/0T1Qxz/0ZjzJztsRqewrnmNMsNhKIcR8QqapiCHr3Ivt0wDddBJWN5y8bEDKScQS678gslecNmaHV/pFoCDDv1W5iFHWvkNaspV2Iu95AfEMY9k+7n5CJesVmxHgaNo2SPxu1W4ggu4A+N4kGRHU5oDwCstlV+Y6Pbdk=" Feb 15 10:30:59 volumio go-librespot[4596]: time="2025-02-15T10:30:59+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 15 10:30:59 volumio volumio[963]: info: Initializing connection to go-librespot Websocket Feb 15 10:30:59 volumio go-librespot[4596]: time="2025-02-15T10:30:59+01:00" level=debug msg="new websocket client" Feb 15 10:30:59 volumio volumio[963]: info: Connection to go-librespot Websocket established Feb 15 10:30:59 volumio go-librespot[4596]: time="2025-02-15T10:30:59+01:00" level=debug msg="completed keyexchange" Feb 15 10:31:00 volumio go-librespot[4596]: time="2025-02-15T10:31:00+01:00" level=debug msg="completed challenge" Feb 15 10:31:00 volumio go-librespot[4596]: time="2025-02-15T10:31:00+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 15 10:31:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 15 10:31:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 15 10:31:00 volumio volumio[963]: info: Connection to go-librespot Websocket closed Feb 15 10:31:02 volumio volumio[963]: info: Getting Spotify volume Feb 15 10:31:02 volumio volumio[963]: (node:963) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 15 10:31:02 volumio volumio[963]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Feb 15 10:31:02 volumio volumio[963]: (node:963) 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: 64) Feb 15 10:31:02 volumio volumio[963]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Feb 15 10:31:02 volumio volumio[963]: info: CoreCommandRouter::volumioGetState Feb 15 10:31:02 volumio volumio[963]: info: CorePlayQueue::getTrack 0 Feb 15 10:31:02 volumio volumio[963]: SPOTIFY: RECEIVED VOLUMIO VOLUME 57 Feb 15 10:31:03 volumio volumio[963]: info: Initializing connection to go-librespot Websocket Feb 15 10:31:03 volumio volumio[963]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 15 10:31:03 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 15 10:31:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 148. Feb 15 10:31:03 volumio systemd[1]: Stopped go-librespot Daemon. Feb 15 10:31:03 volumio systemd[1]: Started go-librespot Daemon. Feb 15 10:31:03 volumio go-librespot[4621]: Librespot-go daemon starting... Feb 15 10:31:03 volumio go-librespot[4621]: time="2025-02-15T10:31:03+01:00" level=info msg="generated new device id: a607d1865a31df53048c64410a80864f94dc1a98" Feb 15 10:31:03 volumio go-librespot[4621]: time="2025-02-15T10:31:03+01:00" level=debug msg="stored credentials found for motobowaq" Feb 15 10:31:04 volumio go-librespot[4621]: time="2025-02-15T10:31:04+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 15 10:31:04 volumio go-librespot[4621]: time="2025-02-15T10:31:04+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 15 10:31:04 volumio go-librespot[4621]: time="2025-02-15T10:31:04+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 15 10:31:04 volumio go-librespot[4621]: time="2025-02-15T10:31:04+01:00" level=debug msg="zeroconf server listening on port 43879" Feb 15 10:31:04 volumio go-librespot[4621]: time="2025-02-15T10:31:04+01:00" level=debug msg="obtained new client token: AACE0XSb7qyAObNbDkhI/kuzYk5xjOl8VUelpSMDSrhK0dxdK9BPxypCufXoSGLCZlY5BurE0rTsBaemBSMyFBPqXCO85rML9ULfVVRnNoiKvBkvUjmBVfpFNi/Uyn+XH+C5EB42yp4V88dnq7rsf0gvrvWerFYPTuFF2QBSy2QgfbR8RdTshvaa46DnfAhpaAnvz7EYxamCuYmMNJfpeZwD/ZDore2GU4LMCEhZFoaLgvIxvAYJwaXe" Feb 15 10:31:04 volumio go-librespot[4621]: time="2025-02-15T10:31:04+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 15 10:31:04 volumio go-librespot[4621]: time="2025-02-15T10:31:04+01:00" level=debug msg="completed keyexchange" Feb 15 10:31:04 volumio go-librespot[4621]: time="2025-02-15T10:31:04+01:00" level=debug msg="completed challenge" Feb 15 10:31:05 volumio go-librespot[4621]: time="2025-02-15T10:31:05+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 15 10:31:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 15 10:31:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 15 10:31:06 volumio volumio[963]: info: Initializing connection to go-librespot Websocket Feb 15 10:31:06 volumio volumio[963]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 15 10:31:08 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 15 10:31:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 149. Feb 15 10:31:08 volumio systemd[1]: Stopped go-librespot Daemon. Feb 15 10:31:08 volumio systemd[1]: Started go-librespot Daemon. Feb 15 10:31:08 volumio go-librespot[4668]: Librespot-go daemon starting... Feb 15 10:31:08 volumio go-librespot[4668]: time="2025-02-15T10:31:08+01:00" level=info msg="generated new device id: 12ac25e9c3c8fed9c9a63f9a5ae9786bab9932ba" Feb 15 10:31:08 volumio go-librespot[4668]: time="2025-02-15T10:31:08+01:00" level=debug msg="stored credentials found for motobowaq" Feb 15 10:31:08 volumio go-librespot[4668]: time="2025-02-15T10:31:08+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 15 10:31:08 volumio go-librespot[4668]: time="2025-02-15T10:31:08+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 15 10:31:08 volumio go-librespot[4668]: time="2025-02-15T10:31:08+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 15 10:31:08 volumio go-librespot[4668]: time="2025-02-15T10:31:08+01:00" level=debug msg="zeroconf server listening on port 46495" Feb 15 10:31:08 volumio go-librespot[4668]: time="2025-02-15T10:31:08+01:00" level=debug msg="obtained new client token: AAA31UP4zSQx/MHSMPeEBsrADWL70DvfGwSdRnb0Vc398cuiBak2iOFhWi6O/URyasKaw+M1AKADEGBm8owNivWesFSzCQzrxxnv42xSp46m2Jf4L8GZ0zzzU/H9qX+zgZAlwdVYOyRsTUwK4DGsEvvBkfaTL3i4MrzOzMf/zFX+RKveyXYI0wMwtrJjeMYRyEOohmxV4Uxve9JLS8hIAq/VzrYu0wc4ZwKA6X2Hd4h+DbYPLf7ZYaJGUw4=" Feb 15 10:31:08 volumio go-librespot[4668]: time="2025-02-15T10:31:08+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 15 10:31:09 volumio go-librespot[4668]: time="2025-02-15T10:31:09+01:00" level=debug msg="completed keyexchange" Feb 15 10:31:09 volumio volumio[963]: info: Initializing connection to go-librespot Websocket Feb 15 10:31:09 volumio go-librespot[4668]: time="2025-02-15T10:31:09+01:00" level=debug msg="new websocket client" Feb 15 10:31:09 volumio volumio[963]: info: Connection to go-librespot Websocket established Feb 15 10:31:09 volumio go-librespot[4668]: time="2025-02-15T10:31:09+01:00" level=debug msg="completed challenge" Feb 15 10:31:10 volumio go-librespot[4668]: time="2025-02-15T10:31:10+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 15 10:31:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 15 10:31:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 15 10:31:10 volumio volumio[963]: info: Connection to go-librespot Websocket closed Feb 15 10:31:12 volumio volumio[963]: info: Getting Spotify volume Feb 15 10:31:12 volumio volumio[963]: (node:963) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 15 10:31:12 volumio volumio[963]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Feb 15 10:31:12 volumio volumio[963]: (node:963) 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: 65) Feb 15 10:31:12 volumio volumio[963]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Feb 15 10:31:12 volumio volumio[963]: info: CoreCommandRouter::volumioGetState Feb 15 10:31:12 volumio volumio[963]: info: CorePlayQueue::getTrack 0 Feb 15 10:31:12 volumio volumio[963]: SPOTIFY: RECEIVED VOLUMIO VOLUME 57 Feb 15 10:31:13 volumio volumio[963]: info: Initializing connection to go-librespot Websocket Feb 15 10:31:13 volumio volumio[963]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 15 10:31:13 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 15 10:31:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 150. Feb 15 10:31:13 volumio systemd[1]: Stopped go-librespot Daemon. Feb 15 10:31:13 volumio systemd[1]: Started go-librespot Daemon. Feb 15 10:31:13 volumio go-librespot[4693]: Librespot-go daemon starting... Feb 15 10:31:13 volumio go-librespot[4693]: time="2025-02-15T10:31:13+01:00" level=info msg="generated new device id: 817af8f939be875fcce0176a43f3cb8580b56609" Feb 15 10:31:13 volumio go-librespot[4693]: time="2025-02-15T10:31:13+01:00" level=debug msg="stored credentials found for motobowaq" Feb 15 10:31:13 volumio go-librespot[4693]: time="2025-02-15T10:31:13+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 15 10:31:13 volumio go-librespot[4693]: time="2025-02-15T10:31:13+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 15 10:31:13 volumio go-librespot[4693]: time="2025-02-15T10:31:13+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 15 10:31:13 volumio go-librespot[4693]: time="2025-02-15T10:31:13+01:00" level=debug msg="zeroconf server listening on port 45913" Feb 15 10:31:13 volumio go-librespot[4693]: time="2025-02-15T10:31:13+01:00" level=debug msg="obtained new client token: AACt9PIpyMmMwy/6xwgPchzU/NVvXbwFEBBu0kcqxGnNXAhLL9fqgHuAwHYyx6LLgjt4eNLDtIy5GzG8OVvda9w/OcxNFo6HyjYegyhIkDvd+Idi8Mi3Na1LY8jIf1RmUiRdbgLUB3f7beB1Qh4KPbDz0klSQRai1YgUWp+mv5yJKDH7tge2yyH006ZcWEcPzpJVr1t7P24NBZnB5/BnKzSxfL959yZ0p6rOyU2ltCvAkWU0K+j7UZb+eRE=" Feb 15 10:31:13 volumio go-librespot[4693]: time="2025-02-15T10:31:13+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 15 10:31:13 volumio go-librespot[4693]: time="2025-02-15T10:31:13+01:00" level=debug msg="completed keyexchange" Feb 15 10:31:14 volumio go-librespot[4693]: time="2025-02-15T10:31:14+01:00" level=debug msg="completed challenge" Feb 15 10:31:14 volumio go-librespot[4693]: time="2025-02-15T10:31:14+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 15 10:31:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 15 10:31:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 15 10:31:16 volumio volumio[963]: info: Initializing connection to go-librespot Websocket Feb 15 10:31:16 volumio volumio[963]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 15 10:31:17 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 15 10:31:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 151. Feb 15 10:31:17 volumio systemd[1]: Stopped go-librespot Daemon. Feb 15 10:31:17 volumio systemd[1]: Started go-librespot Daemon. Feb 15 10:31:17 volumio go-librespot[4702]: Librespot-go daemon starting... Feb 15 10:31:18 volumio go-librespot[4702]: time="2025-02-15T10:31:18+01:00" level=info msg="generated new device id: c7e4babd8afa6f7d3bd10526bbb43ff8e6c50d6f" Feb 15 10:31:18 volumio go-librespot[4702]: time="2025-02-15T10:31:18+01:00" level=debug msg="stored credentials found for motobowaq" Feb 15 10:31:18 volumio go-librespot[4702]: time="2025-02-15T10:31:18+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 15 10:31:18 volumio go-librespot[4702]: time="2025-02-15T10:31:18+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 15 10:31:18 volumio go-librespot[4702]: time="2025-02-15T10:31:18+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 15 10:31:18 volumio go-librespot[4702]: time="2025-02-15T10:31:18+01:00" level=debug msg="zeroconf server listening on port 44755" Feb 15 10:31:18 volumio go-librespot[4702]: time="2025-02-15T10:31:18+01:00" level=debug msg="obtained new client token: AACB86a7cwW+pESCZQuPBUL6aocrA/Jrp+TVnYLRVFIJbRPbEHIvyGWo6wR97eiaFcFe3Mcg+3KvsjXZqeJ+8UrFrSKaig/8r3JSvi+T/xTPh+/xxaLzuVUCvn/45iSNMqn6Nn+amfTJWl/BYsO6TS8FEXYApXQOFoUJ+RXwusSdlrGyYTHTH68dZXl0xubd/Zcd44gcOLI5+FTuvu46lJCUd45XHw7qWFdS6SF+Wsg2iNBNZ+yOQrRafXU=" Feb 15 10:31:18 volumio go-librespot[4702]: time="2025-02-15T10:31:18+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 15 10:31:18 volumio go-librespot[4702]: time="2025-02-15T10:31:18+01:00" level=debug msg="completed keyexchange" Feb 15 10:31:19 volumio volumio[963]: info: Initializing connection to go-librespot Websocket Feb 15 10:31:19 volumio go-librespot[4702]: time="2025-02-15T10:31:19+01:00" level=debug msg="new websocket client" Feb 15 10:31:19 volumio volumio[963]: info: Connection to go-librespot Websocket established Feb 15 10:31:19 volumio go-librespot[4702]: time="2025-02-15T10:31:19+01:00" level=debug msg="completed challenge" Feb 15 10:31:19 volumio go-librespot[4702]: time="2025-02-15T10:31:19+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 15 10:31:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 15 10:31:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 15 10:31:19 volumio volumio[963]: info: Connection to go-librespot Websocket closed Feb 15 10:31:22 volumio volumio[963]: info: Getting Spotify volume Feb 15 10:31:22 volumio volumio[963]: (node:963) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 15 10:31:22 volumio volumio[963]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Feb 15 10:31:22 volumio volumio[963]: (node:963) 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: 66) Feb 15 10:31:22 volumio volumio[963]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Feb 15 10:31:22 volumio volumio[963]: info: CoreCommandRouter::volumioGetState Feb 15 10:31:22 volumio volumio[963]: info: CorePlayQueue::getTrack 0 Feb 15 10:31:22 volumio volumio[963]: SPOTIFY: RECEIVED VOLUMIO VOLUME 57 Feb 15 10:31:22 volumio volumio[963]: info: Initializing connection to go-librespot Websocket Feb 15 10:31:22 volumio volumio[963]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 15 10:31:22 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 15 10:31:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 152. Feb 15 10:31:22 volumio systemd[1]: Stopped go-librespot Daemon. Feb 15 10:31:22 volumio systemd[1]: Started go-librespot Daemon. Feb 15 10:31:22 volumio go-librespot[4728]: Librespot-go daemon starting... Feb 15 10:31:22 volumio go-librespot[4728]: time="2025-02-15T10:31:22+01:00" level=info msg="generated new device id: 44ec93840183344c100c02cff5e279b213a76810" Feb 15 10:31:22 volumio go-librespot[4728]: time="2025-02-15T10:31:22+01:00" level=debug msg="stored credentials found for motobowaq" Feb 15 10:31:22 volumio sudo[4737]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 15 10:31:22 volumio sudo[4737]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 15 10:31:22 volumio sudo[4737]: pam_unix(sudo:session): session closed for user root Feb 15 10:31:22 volumio sudo[4739]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 15 10:31:22 volumio sudo[4739]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 15 10:31:22 volumio sudo[4739]: pam_unix(sudo:session): session closed for user root Feb 15 10:31:22 volumio go-librespot[4728]: time="2025-02-15T10:31:22+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 15 10:31:22 volumio go-librespot[4728]: time="2025-02-15T10:31:22+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 15 10:31:22 volumio go-librespot[4728]: time="2025-02-15T10:31:22+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 15 10:31:22 volumio go-librespot[4728]: time="2025-02-15T10:31:22+01:00" level=debug msg="zeroconf server listening on port 34955" Feb 15 10:31:22 volumio volumio[963]: verbose: New Socket.io Connection to 192.168.0.50 from 192.168.0.54 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/132.0.0.0 Mobile Safari/537.36 OPR/87.0.0.0 Engine version: 3 Transport: polling Total Clients: 6 Feb 15 10:31:23 volumio go-librespot[4728]: time="2025-02-15T10:31:23+01:00" level=debug msg="obtained new client token: AAA8WkgQgNvvR7cOorLsPAaEHYlkBE1p5f8rPS4koinY6SQGwOSYwV7TWY6M+qTh4OouhYY3HQym78tf8jimgX7g1SyMpZcGklF4xKTjYagrOlN3ZwAA5uO4pd7wWjcI6smxIhPeoldSnqkTd4sTOboGSNTx7652wwkOrwKBiZpS/mKw5YVvzPCxCkH0mVa7rZpRCAX+tr/89iJP+ZGH03gXEKWG5o0X6lrnbEujOJJ/MJoPxQtGN/uE" Feb 15 10:31:23 volumio go-librespot[4728]: time="2025-02-15T10:31:23+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 15 10:31:23 volumio go-librespot[4728]: time="2025-02-15T10:31:23+01:00" level=debug msg="completed keyexchange" Feb 15 10:31:23 volumio sudo[4743]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 15 10:31:23 volumio sudo[4743]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 15 10:31:23 volumio sudo[4743]: pam_unix(sudo:session): session closed for user root Feb 15 10:31:23 volumio sudo[4745]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 15 10:31:23 volumio sudo[4745]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 15 10:31:23 volumio sudo[4745]: pam_unix(sudo:session): session closed for user root Feb 15 10:31:23 volumio volumio[963]: verbose: New Socket.io Connection to 192.168.0.50 from 192.168.0.54 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/132.0.0.0 Mobile Safari/537.36 OPR/87.0.0.0 Engine version: 3 Transport: polling Total Clients: 7 Feb 15 10:31:23 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 15 10:31:23 volumio go-librespot[4728]: time="2025-02-15T10:31:23+01:00" level=debug msg="completed challenge" Feb 15 10:31:23 volumio go-librespot[4728]: time="2025-02-15T10:31:23+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 15 10:31:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 15 10:31:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 15 10:31:23 volumio volumio[963]: info: CoreCommandRouter::volumioGetVisibleSources Feb 15 10:31:23 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 15 10:31:23 volumio volumio[963]: info: CoreCommandRouter::volumioGetState Feb 15 10:31:23 volumio volumio[963]: info: CorePlayQueue::getTrack 0 Feb 15 10:31:23 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Feb 15 10:31:23 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 15 10:31:23 volumio volumio[963]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Feb 15 10:31:23 volumio volumio[963]: info: Received Get System Info Feb 15 10:31:23 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 15 10:31:23 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 15 10:31:23 volumio volumio[963]: info: Discovery: Getting this device information Feb 15 10:31:23 volumio volumio[963]: info: CoreCommandRouter::volumioGetState Feb 15 10:31:23 volumio volumio[963]: info: CorePlayQueue::getTrack 0 Feb 15 10:31:23 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 15 10:31:23 volumio volumio[963]: info: CoreCommandRouter::volumioGetState Feb 15 10:31:23 volumio volumio[963]: info: CorePlayQueue::getTrack 0 Feb 15 10:31:23 volumio volumio[963]: info: Listing playlists Feb 15 10:31:23 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Feb 15 10:31:23 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 15 10:31:25 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 15 10:31:25 volumio volumio[963]: info: Received Get System Info Feb 15 10:31:25 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 15 10:31:25 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 15 10:31:25 volumio volumio[963]: info: Discovery: Getting this device information Feb 15 10:31:25 volumio volumio[963]: info: CoreCommandRouter::volumioGetState Feb 15 10:31:25 volumio volumio[963]: info: CorePlayQueue::getTrack 0 Feb 15 10:31:25 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 15 10:31:25 volumio volumio[963]: info: Initializing connection to go-librespot Websocket Feb 15 10:31:25 volumio volumio[963]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 15 10:31:25 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Feb 15 10:31:26 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 15 10:31:26 volumio volumio[963]: info: Received Get System Info Feb 15 10:31:26 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 15 10:31:26 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 15 10:31:26 volumio volumio[963]: info: Discovery: Getting this device information Feb 15 10:31:26 volumio volumio[963]: info: CoreCommandRouter::volumioGetState Feb 15 10:31:26 volumio volumio[963]: info: CorePlayQueue::getTrack 0 Feb 15 10:31:26 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 15 10:31:26 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 15 10:31:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 153. Feb 15 10:31:26 volumio systemd[1]: Stopped go-librespot Daemon. Feb 15 10:31:26 volumio systemd[1]: Started go-librespot Daemon. Feb 15 10:31:26 volumio go-librespot[4748]: Librespot-go daemon starting... Feb 15 10:31:27 volumio go-librespot[4748]: time="2025-02-15T10:31:27+01:00" level=info msg="generated new device id: d4d12717e0d52146dd9c508a10293cbd46b86032" Feb 15 10:31:27 volumio go-librespot[4748]: time="2025-02-15T10:31:27+01:00" level=debug msg="stored credentials found for motobowaq" Feb 15 10:31:27 volumio go-librespot[4748]: time="2025-02-15T10:31:27+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 15 10:31:27 volumio go-librespot[4748]: time="2025-02-15T10:31:27+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 15 10:31:27 volumio go-librespot[4748]: time="2025-02-15T10:31:27+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 15 10:31:27 volumio go-librespot[4748]: time="2025-02-15T10:31:27+01:00" level=debug msg="zeroconf server listening on port 34293" Feb 15 10:31:27 volumio go-librespot[4748]: time="2025-02-15T10:31:27+01:00" level=debug msg="obtained new client token: AADjgr/GCRsOeiU2iLN4HeaOgZCbOGUs0VRbQW5X/x3YZ7hmlTzLf1AB13WRs8gu4miBPq3KQanYr9FGrj8RVfxYYU2rQdSf8QlzlV/DUyrSWhP2as6dojLOwwCGQNeGDKhY8jG/4VATvQNeE1AVt5+/MJ4+EWljIJ5bNVDlQKyIaN7pPIOZmkfQeFDZl9m3nQ/UomSh3qMAbe7Vi00E/N/H/aD4qKO3eLSn9bm9I0O84uv9IUeNZhWZfWo=" Feb 15 10:31:27 volumio go-librespot[4748]: time="2025-02-15T10:31:27+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 15 10:31:27 volumio go-librespot[4748]: time="2025-02-15T10:31:27+01:00" level=debug msg="completed keyexchange" Feb 15 10:31:28 volumio go-librespot[4748]: time="2025-02-15T10:31:28+01:00" level=debug msg="completed challenge" Feb 15 10:31:28 volumio go-librespot[4748]: time="2025-02-15T10:31:28+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 15 10:31:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 15 10:31:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 15 10:31:28 volumio volumio[963]: info: Initializing connection to go-librespot Websocket Feb 15 10:31:28 volumio volumio[963]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 15 10:31:29 volumio volumio[963]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 15 10:31:29 volumio volumio[963]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 15 10:31:29 volumio volumio[963]: info: Retrieving Cloud Streaming UI Feb 15 10:31:29 volumio volumio[963]: info: Getting Tidal Cloud Configuration Feb 15 10:31:29 volumio volumio[963]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 15 10:31:29 volumio volumio[963]: info: Getting Qobuz Cloud Configuration Feb 15 10:31:29 volumio volumio[963]: info: Asking plugin for UI Config Feb 15 10:31:29 volumio volumio[963]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 15 10:31:29 volumio volumio[963]: info: Getting Spotify Cloud Configuration Feb 15 10:31:29 volumio volumio[963]: info: Asking plugin for UI Config Feb 15 10:31:29 volumio volumio[963]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 15 10:31:29 volumio volumio[963]: info: Saving Spotify Acccount Feb 15 10:31:29 volumio volumio[963]: info: Got it Feb 15 10:31:29 volumio volumio[963]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Feb 15 10:31:29 volumio volumio[963]: info: Got Tidal Cloud Configuration Feb 15 10:31:29 volumio volumio[963]: info: Got it Feb 15 10:31:29 volumio volumio[963]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 15 10:31:29 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Feb 15 10:31:29 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Feb 15 10:31:29 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Feb 15 10:31:29 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Feb 15 10:31:29 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 15 10:31:29 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 15 10:31:29 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 15 10:31:29 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 15 10:31:29 volumio volumio[963]: info: CoreCommandRouter::volumioGetBrowseSources Feb 15 10:31:29 volumio volumio[963]: info: CoreCommandRouter::volumioGetBrowseSources Feb 15 10:31:29 volumio volumio[963]: info: CoreCommandRouter::volumioGetBrowseSources Feb 15 10:31:30 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 15 10:31:30 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Feb 15 10:31:31 volumio volumio[963]: info: Initializing connection to go-librespot Websocket Feb 15 10:31:31 volumio volumio[963]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 15 10:31:31 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 15 10:31:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 154. Feb 15 10:31:31 volumio systemd[1]: Stopped go-librespot Daemon. Feb 15 10:31:31 volumio systemd[1]: Started go-librespot Daemon. Feb 15 10:31:31 volumio go-librespot[4774]: Librespot-go daemon starting... Feb 15 10:31:31 volumio go-librespot[4774]: time="2025-02-15T10:31:31+01:00" level=info msg="generated new device id: 9ff382b29b6b55ecfb13c0277671a57021f990be" Feb 15 10:31:31 volumio go-librespot[4774]: time="2025-02-15T10:31:31+01:00" level=debug msg="stored credentials found for motobowaq" Feb 15 10:31:32 volumio go-librespot[4774]: time="2025-02-15T10:31:32+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 15 10:31:32 volumio go-librespot[4774]: time="2025-02-15T10:31:32+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 15 10:31:32 volumio go-librespot[4774]: time="2025-02-15T10:31:32+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 15 10:31:32 volumio go-librespot[4774]: time="2025-02-15T10:31:32+01:00" level=debug msg="zeroconf server listening on port 36865" Feb 15 10:31:32 volumio go-librespot[4774]: time="2025-02-15T10:31:32+01:00" level=debug msg="obtained new client token: AABbMpRAJaARlIxmm+ORMQj7SGWfl3Jm22GF2eU6aEfAFgiudLJ/9AeVuMbPG5INhmSxc9sMgyVugOWrR07CNzl8DT+E2rzed48y2x3LmeCw1/smHiDkWaznMEwnWJFZ9GHH+xXGlxEyt7DaKM3W0UOQwsboRUc5hU57GiibnEH0uBl0CTgyS3UjVW+5k23DrqhCu/GLO1m2ynXyoThzZV2FdN2cFj8Mms5PkXpxpNqdWpkI6nhrHe186LU=" Feb 15 10:31:32 volumio go-librespot[4774]: time="2025-02-15T10:31:32+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 15 10:31:32 volumio go-librespot[4774]: time="2025-02-15T10:31:32+01:00" level=debug msg="completed keyexchange" Feb 15 10:31:33 volumio go-librespot[4774]: time="2025-02-15T10:31:33+01:00" level=debug msg="completed challenge" Feb 15 10:31:33 volumio go-librespot[4774]: time="2025-02-15T10:31:33+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 15 10:31:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 15 10:31:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 15 10:31:33 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Feb 15 10:31:34 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 15 10:31:34 volumio volumio[963]: info: Initializing connection to go-librespot Websocket Feb 15 10:31:34 volumio volumio[963]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 15 10:31:36 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 15 10:31:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 155. Feb 15 10:31:36 volumio systemd[1]: Stopped go-librespot Daemon. Feb 15 10:31:36 volumio systemd[1]: Started go-librespot Daemon. Feb 15 10:31:36 volumio go-librespot[4782]: Librespot-go daemon starting... Feb 15 10:31:36 volumio go-librespot[4782]: time="2025-02-15T10:31:36+01:00" level=info msg="generated new device id: e61234dc2d2aadeb93ffed99fd8ffac4b3994460" Feb 15 10:31:36 volumio go-librespot[4782]: time="2025-02-15T10:31:36+01:00" level=debug msg="stored credentials found for motobowaq" Feb 15 10:31:36 volumio go-librespot[4782]: time="2025-02-15T10:31:36+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 15 10:31:36 volumio go-librespot[4782]: time="2025-02-15T10:31:36+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 15 10:31:36 volumio go-librespot[4782]: time="2025-02-15T10:31:36+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 15 10:31:36 volumio go-librespot[4782]: time="2025-02-15T10:31:36+01:00" level=debug msg="zeroconf server listening on port 40861" Feb 15 10:31:37 volumio go-librespot[4782]: time="2025-02-15T10:31:37+01:00" level=debug msg="obtained new client token: AACjeJNBx+kP02XkxhyFx/VhpZAtFJ/wFTx9OeHjDz541zZUwPy7h15RXzlU//x5X5CGPq9lPaqwu5qn8LzqBjVmwe3yKK6pLp4uHPWcr/BU9UuHKTkvyHOilxf89QFIvhR9VX5V/tI+lM3ZYHMdlFgk6qrVORxv2lMbYdH+f/qloPKyOGCSrAHsKnEPynAnx+ZGi0RN1KCrXVparHBzGwNjGmdX8s+F1vJWGg85I6YoXSLg+6SVAN42" Feb 15 10:31:37 volumio go-librespot[4782]: time="2025-02-15T10:31:37+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 15 10:31:37 volumio go-librespot[4782]: time="2025-02-15T10:31:37+01:00" level=debug msg="completed keyexchange" Feb 15 10:31:37 volumio volumio[963]: info: Initializing connection to go-librespot Websocket Feb 15 10:31:37 volumio go-librespot[4782]: time="2025-02-15T10:31:37+01:00" level=debug msg="new websocket client" Feb 15 10:31:37 volumio volumio[963]: info: Connection to go-librespot Websocket established Feb 15 10:31:37 volumio go-librespot[4782]: time="2025-02-15T10:31:37+01:00" level=debug msg="completed challenge" Feb 15 10:31:38 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 15 10:31:38 volumio go-librespot[4782]: time="2025-02-15T10:31:38+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 15 10:31:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 15 10:31:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 15 10:31:38 volumio volumio[963]: info: Connection to go-librespot Websocket closed Feb 15 10:31:40 volumio volumio[963]: info: Getting Spotify volume Feb 15 10:31:40 volumio volumio[963]: (node:963) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 15 10:31:40 volumio volumio[963]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Feb 15 10:31:40 volumio volumio[963]: (node:963) 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: 67) Feb 15 10:31:40 volumio volumio[963]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Feb 15 10:31:40 volumio volumio[963]: info: CoreCommandRouter::volumioGetState Feb 15 10:31:40 volumio volumio[963]: info: CorePlayQueue::getTrack 0 Feb 15 10:31:40 volumio volumio[963]: SPOTIFY: RECEIVED VOLUMIO VOLUME 57 Feb 15 10:31:40 volumio volumio[963]: info: Disabling MyMusic plugin upnp Feb 15 10:31:40 volumio sudo[4795]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Feb 15 10:31:40 volumio sudo[4795]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 15 10:31:40 volumio systemd[1]: Stopping UPnP Renderer front-end to MPD... Feb 15 10:31:40 volumio volumio[963]: error: Upnp client error: Error: This socket has been ended by the other party Feb 15 10:31:40 volumio volumio[963]: ------------------------------------ BT MESSAGE: BT STATUS: running Feb 15 10:31:41 volumio volumio[963]: info: Initializing connection to go-librespot Websocket Feb 15 10:31:41 volumio volumio[963]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 15 10:31:41 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 15 10:31:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 156. Feb 15 10:31:41 volumio systemd[1]: Stopped go-librespot Daemon. Feb 15 10:31:41 volumio systemd[1]: Started go-librespot Daemon. Feb 15 10:31:41 volumio volumio[963]: info: Enabling MyMusic plugin upnp Feb 15 10:31:41 volumio volumio[963]: info: Enabling plugin upnp Feb 15 10:31:41 volumio volumio[963]: info: Loading plugin "upnp"... Feb 15 10:31:41 volumio go-librespot[4811]: Librespot-go daemon starting... Feb 15 10:31:41 volumio volumio[963]: info: [1739611901491] Starting Upmpd Daemon Feb 15 10:31:41 volumio volumio[963]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 15 10:31:41 volumio volumio[963]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 15 10:31:41 volumio go-librespot[4811]: time="2025-02-15T10:31:41+01:00" level=info msg="generated new device id: fbb7a984efebfdb7e708fbaf80e09b9f1f27ebdc" Feb 15 10:31:41 volumio go-librespot[4811]: time="2025-02-15T10:31:41+01:00" level=debug msg="stored credentials found for motobowaq" Feb 15 10:31:41 volumio volumio[963]: Error: listen EADDRINUSE: address already in use :::6599 Feb 15 10:31:41 volumio volumio[963]: at Server.setupListenHandle [as _listen2] (net.js:1318:16) Feb 15 10:31:41 volumio volumio[963]: at listenInCluster (net.js:1366:12) Feb 15 10:31:41 volumio volumio[963]: at Server.listen (net.js:1452:7) Feb 15 10:31:41 volumio volumio[963]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Feb 15 10:31:41 volumio volumio[963]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Feb 15 10:31:41 volumio volumio[963]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Feb 15 10:31:41 volumio volumio[963]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Feb 15 10:31:41 volumio volumio[963]: at processTicksAndRejections (internal/process/task_queues.js:75:11) { Feb 15 10:31:41 volumio volumio[963]: code: 'EADDRINUSE', Feb 15 10:31:41 volumio volumio[963]: errno: -98, Feb 15 10:31:41 volumio volumio[963]: syscall: 'listen', Feb 15 10:31:41 volumio volumio[963]: address: '::', Feb 15 10:31:41 volumio volumio[963]: port: 6599 Feb 15 10:31:41 volumio volumio[963]: } Feb 15 10:31:41 volumio volumio[963]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 15 10:31:41 volumio go-librespot[4811]: time="2025-02-15T10:31:41+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 15 10:31:41 volumio go-librespot[4811]: time="2025-02-15T10:31:41+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 15 10:31:41 volumio go-librespot[4811]: time="2025-02-15T10:31:41+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 15 10:31:41 volumio go-librespot[4811]: time="2025-02-15T10:31:41+01:00" level=debug msg="zeroconf server listening on port 41295" Feb 15 10:31:42 volumio go-librespot[4811]: time="2025-02-15T10:31:42+01:00" level=debug msg="obtained new client token: AAAHXV0cuDsj1g2GBedLyjLRSNCT17fx7T5UwzeXZUexRDiqy6E7eBpsj2wYFmWAp8YvmCfmw6i9GBEtysr8JU1GIkvdS8VKn1OY5b53p2CgPRCHpqZZJDs2MUxHXEfTnwpNpj8hbJKsukcfeSiohzBa1NgB8trdL1qdTtNUSb2njegTQgcl2TGI0qQfW2jrDracMe500z6dPQQ04U/Saeo/vjovFxjaUM5ffmj0qdcHcKy9sGjqWUfr" Feb 15 10:31:42 volumio sudo[4828]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-02-15 10:30 Feb 15 10:31:42 volumio sudo[4828]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 15 10:31:42 volumio go-librespot[4811]: time="2025-02-15T10:31:42+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" 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="f6610a1100d2380eef33bd3004af43153c786f96" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="1c0e5daee99fe3a72cc38b0d1fe6cd78d7f001fe" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 16 Dec 2024 09:30:04 AM CET" VOLUMIO_VERSION="3.785" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fe0ac4b79aed19ccde4b5bd83d468193"