-- Logs begin at Fri 2025-02-21 09:07:51 EST, end at Fri 2025-02-21 11:35:11 EST. -- Feb 21 11:34:01 volumio-office volumio[1144]: info: Getting Spotify volume Feb 21 11:34:01 volumio-office volumio[1144]: (node:1144) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 21 11:34:01 volumio-office volumio[1144]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Feb 21 11:34:01 volumio-office volumio[1144]: (node:1144) 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: 4421) Feb 21 11:34:01 volumio-office volumio[1144]: 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 21 11:34:01 volumio-office volumio[1144]: info: CoreCommandRouter::volumioGetState Feb 21 11:34:01 volumio-office volumio[1144]: info: CorePlayQueue::getTrack 0 Feb 21 11:34:01 volumio-office volumio[1144]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Feb 21 11:34:01 volumio-office volumio[1144]: info: Initializing connection to go-librespot Websocket Feb 21 11:34:01 volumio-office volumio[1144]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 21 11:34:01 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 21 11:34:01 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1467. Feb 21 11:34:01 volumio-office systemd[1]: Stopped go-librespot Daemon. Feb 21 11:34:01 volumio-office systemd[1]: Started go-librespot Daemon. Feb 21 11:34:01 volumio-office go-librespot[8570]: go-librespot daemon starting... Feb 21 11:34:01 volumio-office go-librespot[8570]: time="2025-02-21T11:34:01-05:00" level=info msg="running go-librespot 0.1.3" Feb 21 11:34:01 volumio-office go-librespot[8570]: time="2025-02-21T11:34:01-05:00" level=debug msg="app state loaded" Feb 21 11:34:01 volumio-office go-librespot[8570]: time="2025-02-21T11:34:01-05:00" level=debug msg="stored credentials not found" Feb 21 11:34:01 volumio-office go-librespot[8570]: time="2025-02-21T11:34:01-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 11:34:02 volumio-office go-librespot[8570]: time="2025-02-21T11:34:02-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Feb 21 11:34:02 volumio-office go-librespot[8570]: time="2025-02-21T11:34:02-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 21 11:34:02 volumio-office go-librespot[8570]: time="2025-02-21T11:34:02-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 21 11:34:02 volumio-office go-librespot[8570]: time="2025-02-21T11:34:02-05:00" level=info msg="zeroconf server listening on port 38323" Feb 21 11:34:02 volumio-office go-librespot[8570]: time="2025-02-21T11:34:02-05:00" level=debug msg="obtained new client token: AACsMlfEv9OhnZ1lE4uutfE5XUGiCK/IxG1PzCiZrsW3jNxuksOmPRUypIAzpVkDSwTrMjpQVzSvW/Jd/Gy+Z7MhhkuRSt9vo3bhmAfJo2870BZOt33NH4SaZWKTjZrHPWUH/pwcKSg2yYDk+D7lMoj10FNAxhUQbtFOBi1JP6ZpqYpa9L5YJ58zrNjJdJHwrHNkwWvsVacmgixdXAXromnT2aikB23TN+XABMM4cIcCblvKWyO35tg=" Feb 21 11:34:02 volumio-office go-librespot[8570]: time="2025-02-21T11:34:02-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 21 11:34:02 volumio-office go-librespot[8570]: time="2025-02-21T11:34:02-05:00" level=debug msg="completed keyexchange" Feb 21 11:34:02 volumio-office go-librespot[8570]: time="2025-02-21T11:34:02-05:00" level=debug msg="completed challenge" Feb 21 11:34:02 volumio-office go-librespot[8570]: time="2025-02-21T11:34:02-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Feb 21 11:34:02 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 21 11:34:02 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 21 11:34:03 volumio-office volumio[1144]: info: CoreCommandRouter::volumioGetState Feb 21 11:34:03 volumio-office volumio[1144]: info: CorePlayQueue::getTrack 0 Feb 21 11:34:04 volumio-office volumio[1144]: info: Initializing connection to go-librespot Websocket Feb 21 11:34:04 volumio-office volumio[1144]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 21 11:34:05 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 21 11:34:05 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1468. Feb 21 11:34:05 volumio-office systemd[1]: Stopped go-librespot Daemon. Feb 21 11:34:05 volumio-office systemd[1]: Started go-librespot Daemon. Feb 21 11:34:05 volumio-office go-librespot[8586]: go-librespot daemon starting... Feb 21 11:34:05 volumio-office go-librespot[8586]: time="2025-02-21T11:34:05-05:00" level=info msg="running go-librespot 0.1.3" Feb 21 11:34:05 volumio-office go-librespot[8586]: time="2025-02-21T11:34:05-05:00" level=debug msg="app state loaded" Feb 21 11:34:05 volumio-office go-librespot[8586]: time="2025-02-21T11:34:05-05:00" level=debug msg="stored credentials not found" Feb 21 11:34:05 volumio-office go-librespot[8586]: time="2025-02-21T11:34:05-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 11:34:06 volumio-office go-librespot[8586]: time="2025-02-21T11:34:06-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 21 11:34:06 volumio-office go-librespot[8586]: time="2025-02-21T11:34:06-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 21 11:34:06 volumio-office go-librespot[8586]: time="2025-02-21T11:34:06-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 21 11:34:06 volumio-office go-librespot[8586]: time="2025-02-21T11:34:06-05:00" level=info msg="zeroconf server listening on port 44579" Feb 21 11:34:06 volumio-office go-librespot[8586]: time="2025-02-21T11:34:06-05:00" level=debug msg="obtained new client token: AAAXjufcAdrKVRn6VIJ/Kf3duB79lVmO1a+c2i3LTiSAGgMVs/ODoWcQsspcgWNVkQ7x791d5UQYNI9fH+4Qwss8b6iJWaM3a/uAa96onlI6mzV2JGXafsGO2yUpK8OJV5TWMVb4/egzSdHE06yKX50xQx3RoNRFSsnv7r+YMzsA0UhExTWVsFhl3OOJoPve0B1syjOdA9CRyx2RSbN8/GFpsMNbJQVTUV30eLhYJeDC4JD97MW6cKQ=" Feb 21 11:34:06 volumio-office go-librespot[8586]: time="2025-02-21T11:34:06-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 21 11:34:06 volumio-office go-librespot[8586]: time="2025-02-21T11:34:06-05:00" level=debug msg="completed keyexchange" Feb 21 11:34:06 volumio-office go-librespot[8586]: time="2025-02-21T11:34:06-05:00" level=debug msg="completed challenge" Feb 21 11:34:06 volumio-office go-librespot[8586]: time="2025-02-21T11:34:06-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Feb 21 11:34:06 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 21 11:34:06 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 21 11:34:07 volumio-office volumio[1144]: info: Initializing connection to go-librespot Websocket Feb 21 11:34:07 volumio-office volumio[1144]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 21 11:34:09 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 21 11:34:09 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1469. Feb 21 11:34:09 volumio-office systemd[1]: Stopped go-librespot Daemon. Feb 21 11:34:09 volumio-office systemd[1]: Started go-librespot Daemon. Feb 21 11:34:09 volumio-office go-librespot[8602]: go-librespot daemon starting... Feb 21 11:34:09 volumio-office go-librespot[8602]: time="2025-02-21T11:34:09-05:00" level=info msg="running go-librespot 0.1.3" Feb 21 11:34:09 volumio-office go-librespot[8602]: time="2025-02-21T11:34:09-05:00" level=debug msg="app state loaded" Feb 21 11:34:09 volumio-office go-librespot[8602]: time="2025-02-21T11:34:09-05:00" level=debug msg="stored credentials not found" Feb 21 11:34:09 volumio-office go-librespot[8602]: time="2025-02-21T11:34:09-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 11:34:10 volumio-office go-librespot[8602]: time="2025-02-21T11:34:10-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 21 11:34:10 volumio-office go-librespot[8602]: time="2025-02-21T11:34:10-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 21 11:34:10 volumio-office go-librespot[8602]: time="2025-02-21T11:34:10-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 21 11:34:10 volumio-office go-librespot[8602]: time="2025-02-21T11:34:10-05:00" level=info msg="zeroconf server listening on port 38109" Feb 21 11:34:10 volumio-office go-librespot[8602]: time="2025-02-21T11:34:10-05:00" level=debug msg="obtained new client token: AADt2Xr9aV+ZdrYHbbVQa6ziLDIHvVPIV36J7tkAEvWtJfAw0VhiBus7FyS6cJ/8X6wunA+5JsJRSeh8cq4FGyALEHJAMSCuw7nm9uQpkQ8IPVuVRJiaU7zdyVwg5BGYrCuy7ipU3WivOW/4G1SWc8iPLhvuxwBDjzObqBITyuXMy6fD08O478BQtmpR7j1+70y0wCK+tKriqjGc1+5lC7Ddn0hpdEqXzXzoYKlFkR0cpE2ieXxBIYA=" Feb 21 11:34:10 volumio-office go-librespot[8602]: time="2025-02-21T11:34:10-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 21 11:34:10 volumio-office go-librespot[8602]: time="2025-02-21T11:34:10-05:00" level=debug msg="completed keyexchange" Feb 21 11:34:10 volumio-office go-librespot[8602]: time="2025-02-21T11:34:10-05:00" level=debug msg="completed challenge" Feb 21 11:34:10 volumio-office go-librespot[8602]: time="2025-02-21T11:34:10-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Feb 21 11:34:10 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 21 11:34:10 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 21 11:34:10 volumio-office volumio[1144]: info: Initializing connection to go-librespot Websocket Feb 21 11:34:10 volumio-office volumio[1144]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 21 11:34:13 volumio-office volumio[1144]: info: CoreCommandRouter::volumioGetState Feb 21 11:34:13 volumio-office volumio[1144]: info: CorePlayQueue::getTrack 0 Feb 21 11:34:13 volumio-office volumio[1144]: info: Listing playlists Feb 21 11:34:13 volumio-office volumio[1144]: info: Listing playlists Feb 21 11:34:13 volumio-office volumio[1144]: info: Initializing connection to go-librespot Websocket Feb 21 11:34:13 volumio-office volumio[1144]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 21 11:34:13 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 21 11:34:13 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1470. Feb 21 11:34:13 volumio-office systemd[1]: Stopped go-librespot Daemon. Feb 21 11:34:13 volumio-office systemd[1]: Started go-librespot Daemon. Feb 21 11:34:13 volumio-office go-librespot[8619]: go-librespot daemon starting... Feb 21 11:34:13 volumio-office go-librespot[8619]: time="2025-02-21T11:34:13-05:00" level=info msg="running go-librespot 0.1.3" Feb 21 11:34:13 volumio-office go-librespot[8619]: time="2025-02-21T11:34:13-05:00" level=debug msg="app state loaded" Feb 21 11:34:13 volumio-office go-librespot[8619]: time="2025-02-21T11:34:13-05:00" level=debug msg="stored credentials not found" Feb 21 11:34:13 volumio-office go-librespot[8619]: time="2025-02-21T11:34:13-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 11:34:14 volumio-office go-librespot[8619]: time="2025-02-21T11:34:14-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Feb 21 11:34:14 volumio-office go-librespot[8619]: time="2025-02-21T11:34:14-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 21 11:34:14 volumio-office go-librespot[8619]: time="2025-02-21T11:34:14-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 21 11:34:14 volumio-office go-librespot[8619]: time="2025-02-21T11:34:14-05:00" level=info msg="zeroconf server listening on port 44713" Feb 21 11:34:14 volumio-office go-librespot[8619]: time="2025-02-21T11:34:14-05:00" level=debug msg="obtained new client token: AABW2BkAeFlyslcQ9/vgORrnhqbSCGLRDB6b+iJRO0LOeSvnDs8yvMOrhoyckKtOoWeGbsmb27OqWVkkpEnQzAFztq9t2oOcahRJ8/6Dnx7IHvyLMt+FzVw78YXIdalum8aeo75Is2nvEdGJINdd8BVWyc31DZLUlOXSq9J0nLvmF1C7NysJqSsB1hgC1seuLRO5pgTCxuGoxgJJlRpgKwhLTJQVBQ9gwEf33C32qisYRzS5H7g8yPk=" Feb 21 11:34:14 volumio-office go-librespot[8619]: time="2025-02-21T11:34:14-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 21 11:34:14 volumio-office go-librespot[8619]: time="2025-02-21T11:34:14-05:00" level=debug msg="completed keyexchange" Feb 21 11:34:14 volumio-office go-librespot[8619]: time="2025-02-21T11:34:14-05:00" level=debug msg="completed challenge" Feb 21 11:34:14 volumio-office go-librespot[8619]: time="2025-02-21T11:34:14-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Feb 21 11:34:14 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 21 11:34:14 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 21 11:34:16 volumio-office volumio[1144]: info: Initializing connection to go-librespot Websocket Feb 21 11:34:16 volumio-office volumio[1144]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 21 11:34:17 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 21 11:34:17 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1471. Feb 21 11:34:17 volumio-office systemd[1]: Stopped go-librespot Daemon. Feb 21 11:34:17 volumio-office systemd[1]: Started go-librespot Daemon. Feb 21 11:34:17 volumio-office go-librespot[8636]: go-librespot daemon starting... Feb 21 11:34:17 volumio-office go-librespot[8636]: time="2025-02-21T11:34:17-05:00" level=info msg="running go-librespot 0.1.3" Feb 21 11:34:17 volumio-office go-librespot[8636]: time="2025-02-21T11:34:17-05:00" level=debug msg="app state loaded" Feb 21 11:34:17 volumio-office go-librespot[8636]: time="2025-02-21T11:34:17-05:00" level=debug msg="stored credentials not found" Feb 21 11:34:17 volumio-office go-librespot[8636]: time="2025-02-21T11:34:17-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 11:34:18 volumio-office go-librespot[8636]: time="2025-02-21T11:34:18-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 21 11:34:18 volumio-office go-librespot[8636]: time="2025-02-21T11:34:18-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 21 11:34:18 volumio-office go-librespot[8636]: time="2025-02-21T11:34:18-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 21 11:34:18 volumio-office go-librespot[8636]: time="2025-02-21T11:34:18-05:00" level=info msg="zeroconf server listening on port 45663" Feb 21 11:34:18 volumio-office go-librespot[8636]: time="2025-02-21T11:34:18-05:00" level=debug msg="obtained new client token: AAA6vvJCytnnoDKTthos6LthkuXJSX+OkHdUqh7m9ONCzdTGW9K7xRGAzvWtWsvRSUcuXuMLu694HKBY62Jj38cJhS6KhflAH2tcqH+zlQvRa/VI2cSXPwr7j0drHEjiPRpVoyKjaXK/Nel/OUGzWMbKBLGZ4AAgXLkmaoa6llRD+dm7fXepGF5II5BV6tQwHrvjiNNsdfupKQzveB5wFADFdfXzrtP3uCbqdG3qCgZbG7cijDxnjQY=" Feb 21 11:34:18 volumio-office go-librespot[8636]: time="2025-02-21T11:34:18-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 21 11:34:18 volumio-office go-librespot[8636]: time="2025-02-21T11:34:18-05:00" level=debug msg="completed keyexchange" Feb 21 11:34:18 volumio-office go-librespot[8636]: time="2025-02-21T11:34:18-05:00" level=debug msg="completed challenge" Feb 21 11:34:18 volumio-office go-librespot[8636]: time="2025-02-21T11:34:18-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Feb 21 11:34:18 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 21 11:34:18 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 21 11:34:19 volumio-office volumio[1144]: info: Initializing connection to go-librespot Websocket Feb 21 11:34:19 volumio-office volumio[1144]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 21 11:34:21 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 21 11:34:21 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1472. Feb 21 11:34:21 volumio-office systemd[1]: Stopped go-librespot Daemon. Feb 21 11:34:21 volumio-office systemd[1]: Started go-librespot Daemon. Feb 21 11:34:21 volumio-office go-librespot[8652]: go-librespot daemon starting... Feb 21 11:34:21 volumio-office go-librespot[8652]: time="2025-02-21T11:34:21-05:00" level=info msg="running go-librespot 0.1.3" Feb 21 11:34:21 volumio-office go-librespot[8652]: time="2025-02-21T11:34:21-05:00" level=debug msg="app state loaded" Feb 21 11:34:21 volumio-office go-librespot[8652]: time="2025-02-21T11:34:21-05:00" level=debug msg="stored credentials not found" Feb 21 11:34:21 volumio-office go-librespot[8652]: time="2025-02-21T11:34:21-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 11:34:22 volumio-office go-librespot[8652]: time="2025-02-21T11:34:22-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 21 11:34:22 volumio-office go-librespot[8652]: time="2025-02-21T11:34:22-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 21 11:34:22 volumio-office go-librespot[8652]: time="2025-02-21T11:34:22-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 21 11:34:22 volumio-office go-librespot[8652]: time="2025-02-21T11:34:22-05:00" level=info msg="zeroconf server listening on port 45353" Feb 21 11:34:22 volumio-office go-librespot[8652]: time="2025-02-21T11:34:22-05:00" level=debug msg="obtained new client token: AABrWhBrX8ORWHB9ci9hOGY3b/trRo0eC3rAsQEXF/pXN8W+vbHAEIUnetWox+dV/J4o+InftZrNmLJz4zDMrJMW6l8IRFLQAfbk2XfMX3hJahAzPmkV53EZFFehcAMIt2wWOI9pTNDu3GBL8bgtTeKig5NPfcd1m+o3jVSRtVHMOM00z4myGP3I6qcPpQjvlUo44p87ffyoQ3Xq5zBlAoue8qysc1Pvt0HNr8w0GRCDX2KxSAwLzDs=" Feb 21 11:34:22 volumio-office go-librespot[8652]: time="2025-02-21T11:34:22-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 21 11:34:22 volumio-office go-librespot[8652]: time="2025-02-21T11:34:22-05:00" level=debug msg="completed keyexchange" Feb 21 11:34:22 volumio-office go-librespot[8652]: time="2025-02-21T11:34:22-05:00" level=debug msg="completed challenge" Feb 21 11:34:22 volumio-office go-librespot[8652]: time="2025-02-21T11:34:22-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Feb 21 11:34:22 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 21 11:34:22 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 21 11:34:22 volumio-office volumio[1144]: info: Initializing connection to go-librespot Websocket Feb 21 11:34:22 volumio-office volumio[1144]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 21 11:34:23 volumio-office volumio[1144]: info: CoreCommandRouter::volumioGetState Feb 21 11:34:23 volumio-office volumio[1144]: info: CorePlayQueue::getTrack 0 Feb 21 11:34:25 volumio-office volumio[1144]: info: Initializing connection to go-librespot Websocket Feb 21 11:34:25 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 21 11:34:25 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1473. Feb 21 11:34:25 volumio-office volumio[1144]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 21 11:34:25 volumio-office systemd[1]: Stopped go-librespot Daemon. Feb 21 11:34:25 volumio-office systemd[1]: Started go-librespot Daemon. Feb 21 11:34:25 volumio-office go-librespot[8706]: go-librespot daemon starting... Feb 21 11:34:25 volumio-office go-librespot[8706]: time="2025-02-21T11:34:25-05:00" level=info msg="running go-librespot 0.1.3" Feb 21 11:34:25 volumio-office go-librespot[8706]: time="2025-02-21T11:34:25-05:00" level=debug msg="app state loaded" Feb 21 11:34:25 volumio-office go-librespot[8706]: time="2025-02-21T11:34:25-05:00" level=debug msg="stored credentials not found" Feb 21 11:34:25 volumio-office go-librespot[8706]: time="2025-02-21T11:34:25-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 11:34:26 volumio-office go-librespot[8706]: time="2025-02-21T11:34:26-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Feb 21 11:34:26 volumio-office go-librespot[8706]: time="2025-02-21T11:34:26-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 21 11:34:26 volumio-office go-librespot[8706]: time="2025-02-21T11:34:26-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 21 11:34:26 volumio-office go-librespot[8706]: time="2025-02-21T11:34:26-05:00" level=info msg="zeroconf server listening on port 45395" Feb 21 11:34:26 volumio-office go-librespot[8706]: time="2025-02-21T11:34:26-05:00" level=debug msg="obtained new client token: AAB+bzRHYT6mQMmjzKDN6l6hGv6x0m+yY6V+VCBFnyUCohQb1TZ9dRGRACNsmXdeY2RR4vX6T7SyWz2z72dunpFDWxPn7osWP61rkoyBfo64mbUcci45xJ5gQ/+Fp4gu/iX5CBko2M2ZzpYPe07w+pQZkSQk9ALoj31KpLgjakrfG/GPYmybjM8cyEQeZVnH3hfcpT7wIUGJIuhv67Qi/4zpenrI/ygEejoGcT28u8N1ikhpiG0VvVk=" Feb 21 11:34:26 volumio-office go-librespot[8706]: time="2025-02-21T11:34:26-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 21 11:34:26 volumio-office go-librespot[8706]: time="2025-02-21T11:34:26-05:00" level=debug msg="completed keyexchange" Feb 21 11:34:26 volumio-office go-librespot[8706]: time="2025-02-21T11:34:26-05:00" level=debug msg="completed challenge" Feb 21 11:34:26 volumio-office go-librespot[8706]: time="2025-02-21T11:34:26-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Feb 21 11:34:26 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 21 11:34:26 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 21 11:34:28 volumio-office volumio[1144]: info: Initializing connection to go-librespot Websocket Feb 21 11:34:28 volumio-office volumio[1144]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 21 11:34:29 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 21 11:34:29 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1474. Feb 21 11:34:29 volumio-office systemd[1]: Stopped go-librespot Daemon. Feb 21 11:34:29 volumio-office systemd[1]: Started go-librespot Daemon. Feb 21 11:34:29 volumio-office go-librespot[8723]: go-librespot daemon starting... Feb 21 11:34:29 volumio-office go-librespot[8723]: time="2025-02-21T11:34:29-05:00" level=info msg="running go-librespot 0.1.3" Feb 21 11:34:29 volumio-office go-librespot[8723]: time="2025-02-21T11:34:29-05:00" level=debug msg="app state loaded" Feb 21 11:34:29 volumio-office go-librespot[8723]: time="2025-02-21T11:34:29-05:00" level=debug msg="stored credentials not found" Feb 21 11:34:29 volumio-office go-librespot[8723]: time="2025-02-21T11:34:29-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 11:34:30 volumio-office go-librespot[8723]: time="2025-02-21T11:34:30-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Feb 21 11:34:30 volumio-office go-librespot[8723]: time="2025-02-21T11:34:30-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 21 11:34:30 volumio-office go-librespot[8723]: time="2025-02-21T11:34:30-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 21 11:34:30 volumio-office go-librespot[8723]: time="2025-02-21T11:34:30-05:00" level=info msg="zeroconf server listening on port 38395" Feb 21 11:34:30 volumio-office go-librespot[8723]: time="2025-02-21T11:34:30-05:00" level=debug msg="obtained new client token: AAAo6g/qlY8F4HLqFZbQi7GcK9t7OgWJMF4G29fHr4F99tI53JrLnv5VbvPgVXDnxCDvyvINPHbswg0ZK/ujBPQk1XTsK6t5OhaYB+YoOrbjzJFOe9qpEZNeKeCi1zlNI0Atua9x3sx5iKL+SrROyMyNe1pkKWG2bqHuqWYvcpMj82z/LHgz9BuZtX/gppQyPuRW+fuNd1OVMylxAHAA9n8yG/EM7y3wPOwjgk5+ozG0htthZRATYIg=" Feb 21 11:34:30 volumio-office go-librespot[8723]: time="2025-02-21T11:34:30-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 21 11:34:30 volumio-office go-librespot[8723]: time="2025-02-21T11:34:30-05:00" level=debug msg="completed keyexchange" Feb 21 11:34:30 volumio-office go-librespot[8723]: time="2025-02-21T11:34:30-05:00" level=debug msg="completed challenge" Feb 21 11:34:30 volumio-office go-librespot[8723]: time="2025-02-21T11:34:30-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Feb 21 11:34:30 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 21 11:34:30 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 21 11:34:31 volumio-office volumio[1144]: info: Initializing connection to go-librespot Websocket Feb 21 11:34:31 volumio-office volumio[1144]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 21 11:34:33 volumio-office volumio[1144]: info: CoreCommandRouter::volumioGetState Feb 21 11:34:33 volumio-office volumio[1144]: info: CorePlayQueue::getTrack 0 Feb 21 11:34:33 volumio-office volumio[1144]: info: Listing playlists Feb 21 11:34:33 volumio-office volumio[1144]: info: Listing playlists Feb 21 11:34:33 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 21 11:34:33 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1475. Feb 21 11:34:33 volumio-office systemd[1]: Stopped go-librespot Daemon. Feb 21 11:34:33 volumio-office systemd[1]: Started go-librespot Daemon. Feb 21 11:34:33 volumio-office go-librespot[8739]: go-librespot daemon starting... Feb 21 11:34:33 volumio-office go-librespot[8739]: time="2025-02-21T11:34:33-05:00" level=info msg="running go-librespot 0.1.3" Feb 21 11:34:33 volumio-office go-librespot[8739]: time="2025-02-21T11:34:33-05:00" level=debug msg="app state loaded" Feb 21 11:34:33 volumio-office go-librespot[8739]: time="2025-02-21T11:34:33-05:00" level=debug msg="stored credentials not found" Feb 21 11:34:33 volumio-office go-librespot[8739]: time="2025-02-21T11:34:33-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 11:34:34 volumio-office go-librespot[8739]: time="2025-02-21T11:34:34-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 21 11:34:34 volumio-office go-librespot[8739]: time="2025-02-21T11:34:34-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 21 11:34:34 volumio-office go-librespot[8739]: time="2025-02-21T11:34:34-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 21 11:34:34 volumio-office go-librespot[8739]: time="2025-02-21T11:34:34-05:00" level=info msg="zeroconf server listening on port 38577" Feb 21 11:34:34 volumio-office go-librespot[8739]: time="2025-02-21T11:34:34-05:00" level=debug msg="obtained new client token: AACFaz4sojx7iahuzzFCEtdIS7H5dWlSnhstUiNfqQtKv3C34t+0KCYPaxG3a6BBFYhIDgaj9SNGVKIkN8HQHE3QQtpfKNvSa+Iq5V1O9L4tsxbToyPgVLp5trr7j6kzBAk9dMkcy7gqmKYVvAI7D7GiN9RfBBEgwCqjKhUO2txWbWzqY1F5f4ciU5NcewoQByAuOLWzXinOGECJW7b15LnXiSk8q23Gx0lyIYhSGaStiuDEBFwmXQQ=" Feb 21 11:34:34 volumio-office go-librespot[8739]: time="2025-02-21T11:34:34-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 21 11:34:34 volumio-office go-librespot[8739]: time="2025-02-21T11:34:34-05:00" level=debug msg="completed keyexchange" Feb 21 11:34:34 volumio-office go-librespot[8739]: time="2025-02-21T11:34:34-05:00" level=debug msg="completed challenge" Feb 21 11:34:34 volumio-office go-librespot[8739]: time="2025-02-21T11:34:34-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Feb 21 11:34:34 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 21 11:34:34 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 21 11:34:34 volumio-office volumio[1144]: info: Initializing connection to go-librespot Websocket Feb 21 11:34:34 volumio-office volumio[1144]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 21 11:34:37 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 21 11:34:37 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1476. Feb 21 11:34:37 volumio-office systemd[1]: Stopped go-librespot Daemon. Feb 21 11:34:37 volumio-office volumio[1144]: info: Initializing connection to go-librespot Websocket Feb 21 11:34:37 volumio-office volumio[1144]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 21 11:34:37 volumio-office systemd[1]: Started go-librespot Daemon. Feb 21 11:34:37 volumio-office go-librespot[8755]: go-librespot daemon starting... Feb 21 11:34:37 volumio-office go-librespot[8755]: time="2025-02-21T11:34:37-05:00" level=info msg="running go-librespot 0.1.3" Feb 21 11:34:37 volumio-office go-librespot[8755]: time="2025-02-21T11:34:37-05:00" level=debug msg="app state loaded" Feb 21 11:34:37 volumio-office go-librespot[8755]: time="2025-02-21T11:34:37-05:00" level=debug msg="stored credentials not found" Feb 21 11:34:37 volumio-office go-librespot[8755]: time="2025-02-21T11:34:37-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 11:34:38 volumio-office go-librespot[8755]: time="2025-02-21T11:34:38-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 21 11:34:38 volumio-office go-librespot[8755]: time="2025-02-21T11:34:38-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 21 11:34:38 volumio-office go-librespot[8755]: time="2025-02-21T11:34:38-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 21 11:34:38 volumio-office go-librespot[8755]: time="2025-02-21T11:34:38-05:00" level=info msg="zeroconf server listening on port 45227" Feb 21 11:34:38 volumio-office go-librespot[8755]: time="2025-02-21T11:34:38-05:00" level=debug msg="obtained new client token: AAD7KEFMEDvz33FxpECJOHGBpHW8MjhZUNiy6M0yQeKWZjRmKPz/cINmCXpo7dsNMKDsP3S40wsobrmP9hxa7PU+SpAnAYIRgYEiyPNhIrEFcOulSfJAo6WmAD3VK8Ipv3YdS3sB6s9NdCT6hpDZEkXLPhVmDdXfuSZHO5DVjofVrBlTHkKucfab4ZG4jkTStH1Pg85K+qB9m3YngLp9dMPlzwObixVwe49Gl1g5RzWAC5kpLdbT2pM=" Feb 21 11:34:38 volumio-office go-librespot[8755]: time="2025-02-21T11:34:38-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 21 11:34:38 volumio-office go-librespot[8755]: time="2025-02-21T11:34:38-05:00" level=debug msg="completed keyexchange" Feb 21 11:34:38 volumio-office go-librespot[8755]: time="2025-02-21T11:34:38-05:00" level=debug msg="completed challenge" Feb 21 11:34:38 volumio-office go-librespot[8755]: time="2025-02-21T11:34:38-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Feb 21 11:34:38 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 21 11:34:38 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 21 11:34:40 volumio-office volumio[1144]: info: Initializing connection to go-librespot Websocket Feb 21 11:34:40 volumio-office volumio[1144]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 21 11:34:41 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 21 11:34:41 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1477. Feb 21 11:34:41 volumio-office systemd[1]: Stopped go-librespot Daemon. Feb 21 11:34:41 volumio-office systemd[1]: Started go-librespot Daemon. Feb 21 11:34:41 volumio-office go-librespot[8772]: go-librespot daemon starting... Feb 21 11:34:41 volumio-office go-librespot[8772]: time="2025-02-21T11:34:41-05:00" level=info msg="running go-librespot 0.1.3" Feb 21 11:34:41 volumio-office go-librespot[8772]: time="2025-02-21T11:34:41-05:00" level=debug msg="app state loaded" Feb 21 11:34:41 volumio-office go-librespot[8772]: time="2025-02-21T11:34:41-05:00" level=debug msg="stored credentials not found" Feb 21 11:34:41 volumio-office go-librespot[8772]: time="2025-02-21T11:34:41-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 11:34:42 volumio-office go-librespot[8772]: time="2025-02-21T11:34:42-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 21 11:34:42 volumio-office go-librespot[8772]: time="2025-02-21T11:34:42-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 21 11:34:42 volumio-office go-librespot[8772]: time="2025-02-21T11:34:42-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 21 11:34:42 volumio-office go-librespot[8772]: time="2025-02-21T11:34:42-05:00" level=info msg="zeroconf server listening on port 38171" Feb 21 11:34:42 volumio-office go-librespot[8772]: time="2025-02-21T11:34:42-05:00" level=debug msg="obtained new client token: AACTIR1gyVmMJxDfnzGNRAh4EAUMEIAEyOcturBqnSuIu5Jw3HYNyeVJTsTsDxCg35STd+p9MIqcf4pLGRNxtjlmXcpXHhrfO3ti4LQsrxUtxamRGnbJzq3RH+s8lShM6IUVUlKWPP5gSCgePwmM/38e4H+VnDN1iTlq34H2dL5hWgc8VjGstQ8lgkhGy2YLJh78di+OjWP3DqKKDE3F7FVFhRlvmXm0Y6ogq6R9KQjVAtbY7XgeWro=" Feb 21 11:34:42 volumio-office go-librespot[8772]: time="2025-02-21T11:34:42-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 21 11:34:42 volumio-office go-librespot[8772]: time="2025-02-21T11:34:42-05:00" level=debug msg="completed keyexchange" Feb 21 11:34:42 volumio-office go-librespot[8772]: time="2025-02-21T11:34:42-05:00" level=debug msg="completed challenge" Feb 21 11:34:42 volumio-office go-librespot[8772]: time="2025-02-21T11:34:42-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Feb 21 11:34:42 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 21 11:34:42 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 21 11:34:43 volumio-office volumio[1144]: info: CoreCommandRouter::volumioGetState Feb 21 11:34:43 volumio-office volumio[1144]: info: CorePlayQueue::getTrack 0 Feb 21 11:34:43 volumio-office volumio[1144]: info: Initializing connection to go-librespot Websocket Feb 21 11:34:43 volumio-office volumio[1144]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 21 11:34:45 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 21 11:34:45 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1478. Feb 21 11:34:45 volumio-office systemd[1]: Stopped go-librespot Daemon. Feb 21 11:34:45 volumio-office systemd[1]: Started go-librespot Daemon. Feb 21 11:34:45 volumio-office go-librespot[8788]: go-librespot daemon starting... Feb 21 11:34:45 volumio-office go-librespot[8788]: time="2025-02-21T11:34:45-05:00" level=info msg="running go-librespot 0.1.3" Feb 21 11:34:45 volumio-office go-librespot[8788]: time="2025-02-21T11:34:45-05:00" level=debug msg="app state loaded" Feb 21 11:34:45 volumio-office go-librespot[8788]: time="2025-02-21T11:34:45-05:00" level=debug msg="stored credentials not found" Feb 21 11:34:45 volumio-office go-librespot[8788]: time="2025-02-21T11:34:45-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 11:34:46 volumio-office go-librespot[8788]: time="2025-02-21T11:34:46-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 21 11:34:46 volumio-office go-librespot[8788]: time="2025-02-21T11:34:46-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 21 11:34:46 volumio-office go-librespot[8788]: time="2025-02-21T11:34:46-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 21 11:34:46 volumio-office go-librespot[8788]: time="2025-02-21T11:34:46-05:00" level=info msg="zeroconf server listening on port 37799" Feb 21 11:34:46 volumio-office go-librespot[8788]: time="2025-02-21T11:34:46-05:00" level=debug msg="obtained new client token: AAC78kUFBYYwZXHzo+DCBsv4sIfeLQ2Nd6uTryhS4jP2pllr/AUQVxuGJVWia5qVh1M412H4HmPSzZb7Mbu3fD8F6Aj3AAeEnwhXExKR+HAlyj16beOUlxglUnP6NqgSpjyOxqLlG7bAVYo79gSWrywScwDqL8ASKqMmyjDeYCmZNlqdn1uA8Z4qkh4bJq6f8gPK8l16iDrw1P253jfvDBYtJH0LLd526CCMsDRNGeJ1CRHhptYrH1Q=" Feb 21 11:34:46 volumio-office go-librespot[8788]: time="2025-02-21T11:34:46-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 21 11:34:46 volumio-office go-librespot[8788]: time="2025-02-21T11:34:46-05:00" level=debug msg="completed keyexchange" Feb 21 11:34:46 volumio-office go-librespot[8788]: time="2025-02-21T11:34:46-05:00" level=debug msg="completed challenge" Feb 21 11:34:46 volumio-office go-librespot[8788]: time="2025-02-21T11:34:46-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Feb 21 11:34:46 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 21 11:34:46 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 21 11:34:46 volumio-office volumio[1144]: info: Initializing connection to go-librespot Websocket Feb 21 11:34:46 volumio-office volumio[1144]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 21 11:34:49 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 21 11:34:49 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1479. Feb 21 11:34:49 volumio-office systemd[1]: Stopped go-librespot Daemon. Feb 21 11:34:49 volumio-office volumio[1144]: info: Initializing connection to go-librespot Websocket Feb 21 11:34:49 volumio-office systemd[1]: Started go-librespot Daemon. Feb 21 11:34:49 volumio-office volumio[1144]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 21 11:34:49 volumio-office go-librespot[8804]: go-librespot daemon starting... Feb 21 11:34:49 volumio-office go-librespot[8804]: time="2025-02-21T11:34:49-05:00" level=info msg="running go-librespot 0.1.3" Feb 21 11:34:49 volumio-office go-librespot[8804]: time="2025-02-21T11:34:49-05:00" level=debug msg="app state loaded" Feb 21 11:34:49 volumio-office go-librespot[8804]: time="2025-02-21T11:34:49-05:00" level=debug msg="stored credentials not found" Feb 21 11:34:49 volumio-office go-librespot[8804]: time="2025-02-21T11:34:49-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 11:34:50 volumio-office go-librespot[8804]: time="2025-02-21T11:34:50-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 21 11:34:50 volumio-office go-librespot[8804]: time="2025-02-21T11:34:50-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 21 11:34:50 volumio-office go-librespot[8804]: time="2025-02-21T11:34:50-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 21 11:34:50 volumio-office go-librespot[8804]: time="2025-02-21T11:34:50-05:00" level=info msg="zeroconf server listening on port 33107" Feb 21 11:34:50 volumio-office go-librespot[8804]: time="2025-02-21T11:34:50-05:00" level=debug msg="obtained new client token: AABMAWvjBbNfyX4gpBEeoWOjTK8dK6WovDs3BnV8My/xB/0cip/ut4xFWmeXLTCzyVK0MNOhm5tnjsfK7yZfar8T3BX2J1/W0tIsuX8Q5E4RbiK8y6LNsUq4MfOOPe5TNNm1QXQCKQgwuBLxsWOYmGPljx+0bf7X96kgjwTrC4ejLT9O2sxuueJ06XxOHb8ML05h237m6+qfLGes0Pl+GL7xv30EgPcOtAPZDHbJs4cFiyFgqmykl1k=" Feb 21 11:34:50 volumio-office go-librespot[8804]: time="2025-02-21T11:34:50-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 21 11:34:50 volumio-office go-librespot[8804]: time="2025-02-21T11:34:50-05:00" level=debug msg="completed keyexchange" Feb 21 11:34:50 volumio-office go-librespot[8804]: time="2025-02-21T11:34:50-05:00" level=debug msg="completed challenge" Feb 21 11:34:50 volumio-office go-librespot[8804]: time="2025-02-21T11:34:50-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Feb 21 11:34:50 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 21 11:34:50 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 21 11:34:52 volumio-office volumio[1144]: info: Initializing connection to go-librespot Websocket Feb 21 11:34:52 volumio-office volumio[1144]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 21 11:34:53 volumio-office volumio[1144]: info: CoreCommandRouter::volumioGetState Feb 21 11:34:53 volumio-office volumio[1144]: info: CorePlayQueue::getTrack 0 Feb 21 11:34:53 volumio-office volumio[1144]: info: Listing playlists Feb 21 11:34:53 volumio-office volumio[1144]: info: Listing playlists Feb 21 11:34:53 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 21 11:34:53 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1480. Feb 21 11:34:53 volumio-office systemd[1]: Stopped go-librespot Daemon. Feb 21 11:34:53 volumio-office systemd[1]: Started go-librespot Daemon. Feb 21 11:34:53 volumio-office go-librespot[8820]: go-librespot daemon starting... Feb 21 11:34:53 volumio-office go-librespot[8820]: time="2025-02-21T11:34:53-05:00" level=info msg="running go-librespot 0.1.3" Feb 21 11:34:53 volumio-office go-librespot[8820]: time="2025-02-21T11:34:53-05:00" level=debug msg="app state loaded" Feb 21 11:34:53 volumio-office go-librespot[8820]: time="2025-02-21T11:34:53-05:00" level=debug msg="stored credentials not found" Feb 21 11:34:53 volumio-office go-librespot[8820]: time="2025-02-21T11:34:53-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 11:34:54 volumio-office go-librespot[8820]: time="2025-02-21T11:34:54-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Feb 21 11:34:54 volumio-office go-librespot[8820]: time="2025-02-21T11:34:54-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 21 11:34:54 volumio-office go-librespot[8820]: time="2025-02-21T11:34:54-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 21 11:34:54 volumio-office go-librespot[8820]: time="2025-02-21T11:34:54-05:00" level=info msg="zeroconf server listening on port 41211" Feb 21 11:34:54 volumio-office go-librespot[8820]: time="2025-02-21T11:34:54-05:00" level=debug msg="obtained new client token: AADKYL0AEdzTBmhhwrXsVa5v+Mc8H5a92zFLoRT+accqc9uwe2tx+rROdKQ/mVZhfhrkIQcfAfHKCiSK0tbenUQzP8zldFv4A6AVNUz2+CFDYqfhvTQkE4UjfCmUVA0vooX6Bsss00cNh4TZPti00Lvw/EiEWgfXj6Y3qKDZYPEY4px2x7pGXpQycjLIq2s0nwJzS068hhqoa/TmaoEMq9azqDwWc6NQp1+2QSglcgKWah3MRu39PAs=" Feb 21 11:34:54 volumio-office go-librespot[8820]: time="2025-02-21T11:34:54-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 21 11:34:54 volumio-office go-librespot[8820]: time="2025-02-21T11:34:54-05:00" level=debug msg="completed keyexchange" Feb 21 11:34:54 volumio-office go-librespot[8820]: time="2025-02-21T11:34:54-05:00" level=debug msg="completed challenge" Feb 21 11:34:54 volumio-office go-librespot[8820]: time="2025-02-21T11:34:54-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Feb 21 11:34:54 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 21 11:34:54 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 21 11:34:55 volumio-office volumio[1144]: info: Initializing connection to go-librespot Websocket Feb 21 11:34:55 volumio-office volumio[1144]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 21 11:34:57 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 21 11:34:57 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1481. Feb 21 11:34:57 volumio-office systemd[1]: Stopped go-librespot Daemon. Feb 21 11:34:57 volumio-office systemd[1]: Started go-librespot Daemon. Feb 21 11:34:57 volumio-office go-librespot[8836]: go-librespot daemon starting... Feb 21 11:34:57 volumio-office go-librespot[8836]: time="2025-02-21T11:34:57-05:00" level=info msg="running go-librespot 0.1.3" Feb 21 11:34:57 volumio-office go-librespot[8836]: time="2025-02-21T11:34:57-05:00" level=debug msg="app state loaded" Feb 21 11:34:57 volumio-office go-librespot[8836]: time="2025-02-21T11:34:57-05:00" level=debug msg="stored credentials not found" Feb 21 11:34:57 volumio-office go-librespot[8836]: time="2025-02-21T11:34:57-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 11:34:58 volumio-office go-librespot[8836]: time="2025-02-21T11:34:58-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Feb 21 11:34:58 volumio-office go-librespot[8836]: time="2025-02-21T11:34:58-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 21 11:34:58 volumio-office go-librespot[8836]: time="2025-02-21T11:34:58-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 21 11:34:58 volumio-office go-librespot[8836]: time="2025-02-21T11:34:58-05:00" level=info msg="zeroconf server listening on port 41611" Feb 21 11:34:58 volumio-office go-librespot[8836]: time="2025-02-21T11:34:58-05:00" level=debug msg="obtained new client token: AACX9t6nRrkSXtE2ZcxmPWcwGYcEnDxzAr789nFnwz4mTYXtakQHRlquZ8DOHvM7aQIySyIUd2Rh/kiJb4X4/6DwwHAvL/Hp2xQoKoxHUQUrH9zdmG9JZiZZS/M6qBoT5G/ZOJHg+f7LV2hMU0hxRWBm9i34vJW1StjcbmwqX8txnojbKDr9ruistkBd65AX8mk74fjR7SWblLrJ3kHcoDuJQLwmZJWTAvN2ZdshCgAkaH2AsTSUGqc=" Feb 21 11:34:58 volumio-office go-librespot[8836]: time="2025-02-21T11:34:58-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 21 11:34:58 volumio-office go-librespot[8836]: time="2025-02-21T11:34:58-05:00" level=debug msg="completed keyexchange" Feb 21 11:34:58 volumio-office go-librespot[8836]: time="2025-02-21T11:34:58-05:00" level=debug msg="completed challenge" Feb 21 11:34:58 volumio-office go-librespot[8836]: time="2025-02-21T11:34:58-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Feb 21 11:34:58 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 21 11:34:58 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 21 11:34:58 volumio-office volumio[1144]: info: Initializing connection to go-librespot Websocket Feb 21 11:34:58 volumio-office volumio[1144]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 21 11:35:01 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 21 11:35:01 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1482. Feb 21 11:35:01 volumio-office systemd[1]: Stopped go-librespot Daemon. Feb 21 11:35:01 volumio-office systemd[1]: Started go-librespot Daemon. Feb 21 11:35:01 volumio-office go-librespot[8853]: go-librespot daemon starting... Feb 21 11:35:01 volumio-office volumio[1144]: info: Initializing connection to go-librespot Websocket Feb 21 11:35:01 volumio-office volumio[1144]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 21 11:35:01 volumio-office go-librespot[8853]: time="2025-02-21T11:35:01-05:00" level=info msg="running go-librespot 0.1.3" Feb 21 11:35:01 volumio-office go-librespot[8853]: time="2025-02-21T11:35:01-05:00" level=debug msg="app state loaded" Feb 21 11:35:01 volumio-office go-librespot[8853]: time="2025-02-21T11:35:01-05:00" level=debug msg="stored credentials not found" Feb 21 11:35:01 volumio-office go-librespot[8853]: time="2025-02-21T11:35:01-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 11:35:02 volumio-office go-librespot[8853]: time="2025-02-21T11:35:02-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 21 11:35:02 volumio-office go-librespot[8853]: time="2025-02-21T11:35:02-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 21 11:35:02 volumio-office go-librespot[8853]: time="2025-02-21T11:35:02-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 21 11:35:02 volumio-office go-librespot[8853]: time="2025-02-21T11:35:02-05:00" level=info msg="zeroconf server listening on port 34779" Feb 21 11:35:02 volumio-office go-librespot[8853]: time="2025-02-21T11:35:02-05:00" level=debug msg="obtained new client token: AACuj0K/T6Vv2TYBNY0t9+xkFhGODX58s0rAadzLNgkm4tWjYPM+ns4JR/bNKRhJfPKJ/R+x+NDs4gyQTVu+RUSEezAc4937JFA/ZsIT1ilgxsXnOUbY3MuMdr5m45ZFdWO4cgnP+v34BzN3cR+XRkfFtq6B/oT9knP9ssGuFaAAoWva6rYfGWpcg/BWQRRZn/wU/EHPlP1236okoI/7CISbluPmD4DmyHT4ztX12G85zQv4JL1zRR4=" Feb 21 11:35:02 volumio-office go-librespot[8853]: time="2025-02-21T11:35:02-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 21 11:35:02 volumio-office go-librespot[8853]: time="2025-02-21T11:35:02-05:00" level=debug msg="completed keyexchange" Feb 21 11:35:02 volumio-office go-librespot[8853]: time="2025-02-21T11:35:02-05:00" level=debug msg="completed challenge" Feb 21 11:35:02 volumio-office go-librespot[8853]: time="2025-02-21T11:35:02-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Feb 21 11:35:02 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 21 11:35:02 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 21 11:35:03 volumio-office volumio[1144]: info: CoreCommandRouter::volumioGetState Feb 21 11:35:03 volumio-office volumio[1144]: info: CorePlayQueue::getTrack 0 Feb 21 11:35:04 volumio-office volumio[1144]: info: Initializing connection to go-librespot Websocket Feb 21 11:35:04 volumio-office volumio[1144]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 21 11:35:05 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 21 11:35:05 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1483. Feb 21 11:35:05 volumio-office systemd[1]: Stopped go-librespot Daemon. Feb 21 11:35:05 volumio-office systemd[1]: Started go-librespot Daemon. Feb 21 11:35:05 volumio-office go-librespot[8869]: go-librespot daemon starting... Feb 21 11:35:05 volumio-office go-librespot[8869]: time="2025-02-21T11:35:05-05:00" level=info msg="running go-librespot 0.1.3" Feb 21 11:35:05 volumio-office go-librespot[8869]: time="2025-02-21T11:35:05-05:00" level=debug msg="app state loaded" Feb 21 11:35:05 volumio-office go-librespot[8869]: time="2025-02-21T11:35:05-05:00" level=debug msg="stored credentials not found" Feb 21 11:35:05 volumio-office go-librespot[8869]: time="2025-02-21T11:35:05-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 11:35:06 volumio-office go-librespot[8869]: time="2025-02-21T11:35:06-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 21 11:35:06 volumio-office go-librespot[8869]: time="2025-02-21T11:35:06-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 21 11:35:06 volumio-office go-librespot[8869]: time="2025-02-21T11:35:06-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 21 11:35:06 volumio-office go-librespot[8869]: time="2025-02-21T11:35:06-05:00" level=info msg="zeroconf server listening on port 43519" Feb 21 11:35:06 volumio-office go-librespot[8869]: time="2025-02-21T11:35:06-05:00" level=debug msg="obtained new client token: AABe8wtuVoZIIv4/DXu8LxHlXeuh0Nw26ZNS2XUqM4SBYTzab0XJK0PL8chpYKw+T9Bfqas+xx06xaTXs8nNsIfR2gavLHZRLWzGJWD59tfCUfL/ej7nirc6XKoPFuhJR4AKtcUCyEiVRBFuuqzcmt82b/mz5E89mkYhP/YQ8jmGhYvo/9YMrR2gF1pkLN0vagRnDHxYv5VT9i4BiBwDg0AHuywYLttU3fGmLzRAY2TvclXnddvitBM=" Feb 21 11:35:06 volumio-office go-librespot[8869]: time="2025-02-21T11:35:06-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 21 11:35:06 volumio-office go-librespot[8869]: time="2025-02-21T11:35:06-05:00" level=debug msg="completed keyexchange" Feb 21 11:35:06 volumio-office go-librespot[8869]: time="2025-02-21T11:35:06-05:00" level=debug msg="completed challenge" Feb 21 11:35:06 volumio-office go-librespot[8869]: time="2025-02-21T11:35:06-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Feb 21 11:35:06 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 21 11:35:06 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 21 11:35:07 volumio-office volumio[1144]: info: Initializing connection to go-librespot Websocket Feb 21 11:35:07 volumio-office volumio[1144]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 21 11:35:09 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 21 11:35:09 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1484. Feb 21 11:35:09 volumio-office systemd[1]: Stopped go-librespot Daemon. Feb 21 11:35:09 volumio-office systemd[1]: Started go-librespot Daemon. Feb 21 11:35:09 volumio-office go-librespot[8885]: go-librespot daemon starting... Feb 21 11:35:09 volumio-office go-librespot[8885]: time="2025-02-21T11:35:09-05:00" level=info msg="running go-librespot 0.1.3" Feb 21 11:35:09 volumio-office go-librespot[8885]: time="2025-02-21T11:35:09-05:00" level=debug msg="app state loaded" Feb 21 11:35:09 volumio-office go-librespot[8885]: time="2025-02-21T11:35:09-05:00" level=debug msg="stored credentials not found" Feb 21 11:35:09 volumio-office go-librespot[8885]: time="2025-02-21T11:35:09-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 11:35:10 volumio-office go-librespot[8885]: time="2025-02-21T11:35:10-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 21 11:35:10 volumio-office go-librespot[8885]: time="2025-02-21T11:35:10-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 21 11:35:10 volumio-office go-librespot[8885]: time="2025-02-21T11:35:10-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 21 11:35:10 volumio-office go-librespot[8885]: time="2025-02-21T11:35:10-05:00" level=info msg="zeroconf server listening on port 32845" Feb 21 11:35:10 volumio-office go-librespot[8885]: time="2025-02-21T11:35:10-05:00" level=debug msg="obtained new client token: AACG24yU/uibHtkrJina/hzZCm4IebFyf4NoZg3eyuD3eWkiijKZZhVQEKBwTfLt8JBcWvrdt4mXgWLOKw4K1c/WS8lEl2qRbMSHtUFoEVY7Pfxz4VxCg+oxCxhIaaNKHTQIhPtCKxRXt7qA4P2kGTiOnfIBb+KqaPOlzgG5/bUovJyngTRC96Rg2D3kJ2/FxN2/Vy69L9zsMkTbmh/U0GotRBx50o+OzbopQLCoUWwmXBWezZbwqyM=" Feb 21 11:35:10 volumio-office go-librespot[8885]: time="2025-02-21T11:35:10-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 21 11:35:10 volumio-office go-librespot[8885]: time="2025-02-21T11:35:10-05:00" level=debug msg="completed keyexchange" Feb 21 11:35:10 volumio-office go-librespot[8885]: time="2025-02-21T11:35:10-05:00" level=debug msg="completed challenge" Feb 21 11:35:10 volumio-office go-librespot[8885]: time="2025-02-21T11:35:10-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Feb 21 11:35:10 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 21 11:35:10 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 21 11:35:10 volumio-office volumio[1144]: info: [1740155710773] [RadioParadise] getMetadata started with url https://api.radioparadise.com/api/now_playing?chan=0 Feb 21 11:35:10 volumio-office volumio[1144]: info: Initializing connection to go-librespot Websocket Feb 21 11:35:10 volumio-office volumio[1144]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 21 11:35:11 volumio-office volumio[1144]: info: [1740155711003] [RadioParadise] received new metadata: {"time":27,"artist":"","title":null,"album":null,"year":null,"cover":"https://img.radioparadise.com/covers/l/.jpg","cover_med":"https://img.radioparadise.com/covers/m/.jpg","cover_small":"https://img.radioparadise.com/covers/s/.jpg"} Feb 21 11:35:11 volumio-office volumio[1144]: info: CorePlayQueue::getTrack 0 Feb 21 11:35:11 volumio-office volumio[1144]: info: CoreCommandRouter::servicePushState Feb 21 11:35:11 volumio-office volumio[1144]: info: CorePlayQueue::getTrack 0 Feb 21 11:35:11 volumio-office volumio[1144]: verbose: STATE SERVICE {"status":"play","service":"radio_paradise","type":"webradio","trackType":"flac","radioType":"rparadise","albumart":"https://img.radioparadise.com/covers/l/.jpg","uri":"https://stream.radioparadise.com/flac","name":null,"title":null,"artist":"","album":null,"streaming":true,"disableUiControls":true,"duration":32,"seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Feb 21 11:35:11 volumio-office volumio[1144]: verbose: CURRENT POSITION 0 Feb 21 11:35:11 volumio-office volumio[1144]: info: CoreStateMachine::syncState stateService play Feb 21 11:35:11 volumio-office volumio[1144]: info: CoreStateMachine::syncState currentStatus play Feb 21 11:35:11 volumio-office volumio[1144]: info: Received an update from plugin. extracting info from payload Feb 21 11:35:11 volumio-office volumio[1144]: info: CoreStateMachine::pushState Feb 21 11:35:11 volumio-office volumio[1144]: info: CorePlayQueue::getTrack 0 Feb 21 11:35:11 volumio-office volumio[1144]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 21 11:35:11 volumio-office volumio[1144]: info: CoreCommandRouter::volumioPushState Feb 21 11:35:11 volumio-office volumio[1144]: info: CoreStateMachine::pushState Feb 21 11:35:11 volumio-office volumio[1144]: info: CorePlayQueue::getTrack 0 Feb 21 11:35:11 volumio-office volumio[1144]: info: CoreCommandRouter::volumioPushState Feb 21 11:35:11 volumio-office volumio[1144]: info: [1740155711011] [RadioParadise] setting new timer with duration of 32000 seconds. Feb 21 11:35:11 volumio-office volumio[1144]: info: [LastFM] Current track does not have sufficient metadata: Missing artist. Not a composite title! Feb 21 11:35:11 volumio-office volumio[1144]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 21 11:35:11 volumio-office volumio[1144]: TypeError: Cannot read property 'indexOf' of null Feb 21 11:35:11 volumio-office volumio[1144]: at ControllerLastFM.formatScrobbleData (/data/plugins/user_interface/lastfm/index.js:873:25) Feb 21 11:35:11 volumio-office volumio[1144]: at ControllerLastFM.checkStateUpdate (/data/plugins/user_interface/lastfm/index.js:825:26) Feb 21 11:35:11 volumio-office volumio[1144]: at Socket. (/data/plugins/user_interface/lastfm/index.js:110:52) Feb 21 11:35:11 volumio-office volumio[1144]: at Socket.Emitter.emit (/data/plugins/user_interface/lastfm/node_modules/component-emitter/index.js:133:20) Feb 21 11:35:11 volumio-office volumio[1144]: at Socket.onevent (/data/plugins/user_interface/lastfm/node_modules/socket.io-client/lib/socket.js:270:10) Feb 21 11:35:11 volumio-office volumio[1144]: at Socket.onpacket (/data/plugins/user_interface/lastfm/node_modules/socket.io-client/lib/socket.js:228:12) Feb 21 11:35:11 volumio-office volumio[1144]: at Manager. (/data/plugins/user_interface/lastfm/node_modules/component-bind/index.js:21:15) Feb 21 11:35:11 volumio-office volumio[1144]: at Manager.Emitter.emit (/data/plugins/user_interface/lastfm/node_modules/component-emitter/index.js:133:20) Feb 21 11:35:11 volumio-office volumio[1144]: at Manager.ondecoded (/data/plugins/user_interface/lastfm/node_modules/socket.io-client/lib/manager.js:332:8) Feb 21 11:35:11 volumio-office volumio[1144]: at Decoder. (/data/plugins/user_interface/lastfm/node_modules/component-bind/index.js:21:15) Feb 21 11:35:11 volumio-office volumio[1144]: at Decoder.Emitter.emit (/data/plugins/user_interface/lastfm/node_modules/socket.io-parser/node_modules/component-emitter/index.js:134:20) Feb 21 11:35:11 volumio-office volumio[1144]: at Decoder.add (/data/plugins/user_interface/lastfm/node_modules/socket.io-parser/index.js:246:12) Feb 21 11:35:11 volumio-office volumio[1144]: at Manager.ondata (/data/plugins/user_interface/lastfm/node_modules/socket.io-client/lib/manager.js:322:16) Feb 21 11:35:11 volumio-office volumio[1144]: at Socket. (/data/plugins/user_interface/lastfm/node_modules/component-bind/index.js:21:15) Feb 21 11:35:11 volumio-office volumio[1144]: at Socket.Emitter.emit (/data/plugins/user_interface/lastfm/node_modules/component-emitter/index.js:133:20) Feb 21 11:35:11 volumio-office volumio[1144]: at Socket.onPacket (/data/plugins/user_interface/lastfm/node_modules/engine.io-client/lib/socket.js:451:14) Feb 21 11:35:11 volumio-office volumio[1144]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 21 11:35:11 volumio-office sudo[8905]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-02-21 11:34 Feb 21 11:35:11 volumio-office sudo[8905]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="4b122b2365bb8c09786cd63b50d1ea6db780eb4e" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="49f98390f2d84c6549f33dc85b694fbd99e4c720" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 04 Jun 2024 08:41:12 PM CEST" VOLUMIO_VERSION="3.703" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="8e78a6e3f56f1bcbbd1760812129a8e9"