-- Logs begin at Tue 2025-02-25 20:41:37 CET, end at Tue 2025-02-25 21:42:44 CET. -- Feb 25 21:41:01 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 25 21:41:01 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 246. Feb 25 21:41:01 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Feb 25 21:41:01 minidsp-shd systemd[1]: Started go-librespot Daemon. Feb 25 21:41:01 minidsp-shd go-librespot[20378]: Librespot-go daemon starting... Feb 25 21:41:01 minidsp-shd go-librespot[20378]: time="2025-02-25T21:41:01+01:00" level=info msg="generated new device id: 26f9f744f7364042b701cefc10e0162d43e7cd01" Feb 25 21:41:01 minidsp-shd go-librespot[20378]: time="2025-02-25T21:41:01+01:00" level=debug msg="stored credentials found for saschabies80" Feb 25 21:41:01 minidsp-shd go-librespot[20378]: time="2025-02-25T21:41:01+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 25 21:41:01 minidsp-shd go-librespot[20378]: time="2025-02-25T21:41:01+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 25 21:41:01 minidsp-shd go-librespot[20378]: time="2025-02-25T21:41:01+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 25 21:41:01 minidsp-shd go-librespot[20378]: time="2025-02-25T21:41:01+01:00" level=debug msg="zeroconf server listening on port 43779" Feb 25 21:41:01 minidsp-shd go-librespot[20378]: time="2025-02-25T21:41:01+01:00" level=debug msg="obtained new client token: AAAJP1OO4Z38qOXWIjOOBpDWx414GcWsADHb6JtkSuz5IvlAld0t+vGu4wzquGKTErBjw0emyBh1yyau7uC3rqEO4+iJklu6Rl3cyrXfGhjuDwb/PdqFVAnKT/kBTYpNUHIA6F2qzcpOAFbTIF96LsBWmsuuq9gdZJucWn1e/IXKd9Cyx0aAEeTEIYwxnv2eRY1RLBwhdlOLB9zWMnDP5Hj/gFbVxl6FxEP1dC31UjjOLDm2AAcNRfPD/LrWTQ==" Feb 25 21:41:01 minidsp-shd go-librespot[20378]: time="2025-02-25T21:41:01+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 25 21:41:01 minidsp-shd go-librespot[20378]: time="2025-02-25T21:41:01+01:00" level=debug msg="completed keyexchange" Feb 25 21:41:02 minidsp-shd go-librespot[20378]: time="2025-02-25T21:41:02+01:00" level=debug msg="completed challenge" Feb 25 21:41:02 minidsp-shd go-librespot[20378]: time="2025-02-25T21:41:02+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 25 21:41:02 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 21:41:02 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 21:41:02 minidsp-shd volumio[19645]: info: Initializing connection to go-librespot Websocket Feb 25 21:41:02 minidsp-shd volumio[19645]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:41:03 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 25 21:41:04 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 25 21:41:04 minidsp-shd volumio[19645]: info: Discovery: Getting this device information Feb 25 21:41:04 minidsp-shd volumio[19645]: info: CoreCommandRouter::volumioGetState Feb 25 21:41:04 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 25 21:41:05 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 25 21:41:05 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 247. Feb 25 21:41:05 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Feb 25 21:41:05 minidsp-shd systemd[1]: Started go-librespot Daemon. Feb 25 21:41:05 minidsp-shd go-librespot[20386]: Librespot-go daemon starting... Feb 25 21:41:05 minidsp-shd go-librespot[20386]: time="2025-02-25T21:41:05+01:00" level=info msg="generated new device id: bcc7e77797f19819f82796af3227c53e7d036075" Feb 25 21:41:05 minidsp-shd go-librespot[20386]: time="2025-02-25T21:41:05+01:00" level=debug msg="stored credentials found for saschabies80" Feb 25 21:41:05 minidsp-shd go-librespot[20386]: time="2025-02-25T21:41: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 25 21:41:05 minidsp-shd go-librespot[20386]: time="2025-02-25T21:41:05+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 25 21:41:05 minidsp-shd go-librespot[20386]: time="2025-02-25T21:41:05+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 25 21:41:05 minidsp-shd go-librespot[20386]: time="2025-02-25T21:41:05+01:00" level=debug msg="zeroconf server listening on port 44755" Feb 25 21:41:05 minidsp-shd volumio[19645]: info: Initializing connection to go-librespot Websocket Feb 25 21:41:05 minidsp-shd go-librespot[20386]: time="2025-02-25T21:41:05+01:00" level=debug msg="new websocket client" Feb 25 21:41:05 minidsp-shd volumio[19645]: info: Connection to go-librespot Websocket established Feb 25 21:41:05 minidsp-shd go-librespot[20386]: time="2025-02-25T21:41:05+01:00" level=debug msg="obtained new client token: AADMq5eMpKohrmXhtZnkSzoJb//9M7Yqpw11RwHz8iIM7yGCfPsb9HU8xM9sled2PRfU0Bz1cJwQMz8r3Tb3BOwfaPH4OEmMrg5msp+WnZbXNfaiSmN9fvSWilbbFLnKQqaNnseSjvUVZLRg8MZzOQqXv9CY83HlHMtndnuU1RDbiY2RHcm+B4J+tXYXS2eplZCB3re0P8J2o5hHkefXaKExzV9GZAFx8qEYNuPdq8uhpK9pie4r83mq8RkJGg==" Feb 25 21:41:05 minidsp-shd go-librespot[20386]: time="2025-02-25T21:41:05+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 25 21:41:06 minidsp-shd go-librespot[20386]: time="2025-02-25T21:41:06+01:00" level=debug msg="completed keyexchange" Feb 25 21:41:07 minidsp-shd go-librespot[20386]: time="2025-02-25T21:41:07+01:00" level=debug msg="completed challenge" Feb 25 21:41:07 minidsp-shd go-librespot[20386]: time="2025-02-25T21:41:07+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 25 21:41:07 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 21:41:07 minidsp-shd volumio[19645]: info: Connection to go-librespot Websocket closed Feb 25 21:41:07 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 21:41:08 minidsp-shd volumio[19645]: info: Getting Spotify volume Feb 25 21:41:08 minidsp-shd volumio[19645]: (node:19645) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:41:08 minidsp-shd volumio[19645]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Feb 25 21:41:08 minidsp-shd volumio[19645]: (node:19645) 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: 10) Feb 25 21:41:08 minidsp-shd volumio[19645]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Feb 25 21:41:08 minidsp-shd volumio[19645]: info: CoreCommandRouter::volumioGetState Feb 25 21:41:08 minidsp-shd volumio[19645]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 25 21:41:08 minidsp-shd volumio[19645]: SPOTIFY: SPOTIFY VOLUME 99 Feb 25 21:41:08 minidsp-shd volumio[19645]: SPOTIFY: VOLUMIO VOLUME 100 Feb 25 21:41:08 minidsp-shd volumio[19645]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 25 21:41:10 minidsp-shd volumio[19645]: info: Initializing connection to go-librespot Websocket Feb 25 21:41:10 minidsp-shd volumio[19645]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:41:10 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 25 21:41:10 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 248. Feb 25 21:41:10 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Feb 25 21:41:10 minidsp-shd systemd[1]: Started go-librespot Daemon. Feb 25 21:41:10 minidsp-shd go-librespot[20433]: Librespot-go daemon starting... Feb 25 21:41:10 minidsp-shd go-librespot[20433]: time="2025-02-25T21:41:10+01:00" level=info msg="generated new device id: aedb35b389c8f05da89d3060f912516c15f63187" Feb 25 21:41:10 minidsp-shd go-librespot[20433]: time="2025-02-25T21:41:10+01:00" level=debug msg="stored credentials found for saschabies80" Feb 25 21:41:10 minidsp-shd go-librespot[20433]: time="2025-02-25T21:41: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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 25 21:41:10 minidsp-shd go-librespot[20433]: time="2025-02-25T21:41:10+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 25 21:41:10 minidsp-shd go-librespot[20433]: time="2025-02-25T21:41:10+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 25 21:41:10 minidsp-shd go-librespot[20433]: time="2025-02-25T21:41:10+01:00" level=debug msg="zeroconf server listening on port 41623" Feb 25 21:41:10 minidsp-shd go-librespot[20433]: time="2025-02-25T21:41:10+01:00" level=debug msg="obtained new client token: AACl+x/JiyEQLzeAmn6nvdch9HkBHFs7pZso8sGK9OqDPwB9ODKgSnYEXzBxVI15n0k3MFnnLiR8nLAS0GIp3JoFW+HFi6Cc0DkFHkSOejXGap0QJ0KvIXBndt9phwnUbckEcpg5x9WtKw2HJscInr71Vz2L14YxBOQo5KNzSSSGxFjeuK4GNBduiwAPj/smE6FY868BirS0+BzXpZznz8DjD6V/WjjgfdYKoKGLc/vnRFHujZmcVlM4PjtBDA==" Feb 25 21:41:10 minidsp-shd go-librespot[20433]: time="2025-02-25T21:41:10+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 25 21:41:10 minidsp-shd go-librespot[20433]: time="2025-02-25T21:41:10+01:00" level=debug msg="completed keyexchange" Feb 25 21:41:11 minidsp-shd go-librespot[20433]: time="2025-02-25T21:41:11+01:00" level=debug msg="completed challenge" Feb 25 21:41:11 minidsp-shd go-librespot[20433]: time="2025-02-25T21:41: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 25 21:41:11 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 21:41:11 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 21:41:13 minidsp-shd volumio[19645]: info: Initializing connection to go-librespot Websocket Feb 25 21:41:13 minidsp-shd volumio[19645]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:41:14 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 25 21:41:14 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 249. Feb 25 21:41:14 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Feb 25 21:41:14 minidsp-shd systemd[1]: Started go-librespot Daemon. Feb 25 21:41:14 minidsp-shd go-librespot[20442]: Librespot-go daemon starting... Feb 25 21:41:14 minidsp-shd go-librespot[20442]: time="2025-02-25T21:41:14+01:00" level=info msg="generated new device id: 32bb6ad05acab439dc4aeeeaa7c320ff50e67f72" Feb 25 21:41:14 minidsp-shd go-librespot[20442]: time="2025-02-25T21:41:14+01:00" level=debug msg="stored credentials found for saschabies80" Feb 25 21:41:14 minidsp-shd go-librespot[20442]: time="2025-02-25T21:41: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 25 21:41:14 minidsp-shd go-librespot[20442]: time="2025-02-25T21:41:14+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 25 21:41:14 minidsp-shd go-librespot[20442]: time="2025-02-25T21:41:14+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 25 21:41:14 minidsp-shd go-librespot[20442]: time="2025-02-25T21:41:14+01:00" level=debug msg="zeroconf server listening on port 35451" Feb 25 21:41:15 minidsp-shd go-librespot[20442]: time="2025-02-25T21:41:15+01:00" level=debug msg="obtained new client token: AAAUPohL1XZEsgrQ+mHO1LPdDzoKkdHhHxm9zoO6f0y9xZfJh5JbFDIqvPZVGGQF1+ZnOlv7ldPqsRKCH5VRRN4mzztDeL0ZY3WAprPPN/C07444c0UeYPiPgVB8NImx8iiw7EeJq2p12eYsyBDAUVG1UW2guCNFWxXqZpHOn7yfDUzMOYSx/WVdavMBX46lh/g9C5ySD8WRPw8Egr/NvaLCM5w4Vm8EjBifZnFfh8k8ook1JGX5ib/lzUI=" Feb 25 21:41:15 minidsp-shd go-librespot[20442]: time="2025-02-25T21:41:15+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 25 21:41:15 minidsp-shd go-librespot[20442]: time="2025-02-25T21:41:15+01:00" level=debug msg="completed keyexchange" Feb 25 21:41:15 minidsp-shd go-librespot[20442]: time="2025-02-25T21:41:15+01:00" level=debug msg="completed challenge" Feb 25 21:41:15 minidsp-shd go-librespot[20442]: time="2025-02-25T21:41:15+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 25 21:41:15 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 21:41:15 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 21:41:16 minidsp-shd volumio[19645]: info: Initializing connection to go-librespot Websocket Feb 25 21:41:16 minidsp-shd volumio[19645]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:41:18 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 25 21:41:18 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 250. Feb 25 21:41:18 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Feb 25 21:41:18 minidsp-shd systemd[1]: Started go-librespot Daemon. Feb 25 21:41:18 minidsp-shd go-librespot[20451]: Librespot-go daemon starting... Feb 25 21:41:18 minidsp-shd go-librespot[20451]: time="2025-02-25T21:41:18+01:00" level=info msg="generated new device id: 0864f0403ab9a0871a4852cd9936f9c202724810" Feb 25 21:41:18 minidsp-shd go-librespot[20451]: time="2025-02-25T21:41:18+01:00" level=debug msg="stored credentials found for saschabies80" Feb 25 21:41:19 minidsp-shd volumio[19645]: info: Initializing connection to go-librespot Websocket Feb 25 21:41:19 minidsp-shd go-librespot[20451]: time="2025-02-25T21:41:19+01:00" level=debug msg="new websocket client" Feb 25 21:41:19 minidsp-shd volumio[19645]: info: Connection to go-librespot Websocket established Feb 25 21:41:19 minidsp-shd go-librespot[20451]: time="2025-02-25T21:41:19+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 25 21:41:19 minidsp-shd go-librespot[20451]: time="2025-02-25T21:41:19+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 25 21:41:19 minidsp-shd go-librespot[20451]: time="2025-02-25T21:41:19+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 25 21:41:19 minidsp-shd go-librespot[20451]: time="2025-02-25T21:41:19+01:00" level=debug msg="zeroconf server listening on port 37313" Feb 25 21:41:19 minidsp-shd go-librespot[20451]: time="2025-02-25T21:41:19+01:00" level=debug msg="obtained new client token: AAAoeFmI/wjSOZ4wlIiHTfeOUE+tkxV4YpIZ4dsN9t9rqqDbZpmwqxceFMap/7BxPEkeIK/iMipOvi91UCPerLOfP/AfNa4K/hiGma6r1RVsRojPhUbooYAo3IALGqzqaXlA36TMLGoCo/480PXkFtIhQ8vlNFuWUsJppjdJq577OJo4i/MPHvI/VL+t0AMYeIuv0oIYLDncaAEJdXtO2Dk4kMRKDL2B+fgVrTo44dtvTqcvBj9j/dzQ94Vaxw==" Feb 25 21:41:19 minidsp-shd go-librespot[20451]: time="2025-02-25T21:41:19+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 25 21:41:19 minidsp-shd go-librespot[20451]: time="2025-02-25T21:41:19+01:00" level=debug msg="completed keyexchange" Feb 25 21:41:20 minidsp-shd go-librespot[20451]: time="2025-02-25T21:41:20+01:00" level=debug msg="completed challenge" Feb 25 21:41:20 minidsp-shd go-librespot[20451]: time="2025-02-25T21:41:20+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 25 21:41:20 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 21:41:20 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 21:41:20 minidsp-shd volumio[19645]: info: Connection to go-librespot Websocket closed Feb 25 21:41:22 minidsp-shd volumio[19645]: info: Getting Spotify volume Feb 25 21:41:22 minidsp-shd volumio[19645]: (node:19645) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:41:22 minidsp-shd volumio[19645]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Feb 25 21:41:22 minidsp-shd volumio[19645]: (node:19645) 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: 11) Feb 25 21:41:22 minidsp-shd volumio[19645]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Feb 25 21:41:22 minidsp-shd volumio[19645]: info: CoreCommandRouter::volumioGetState Feb 25 21:41:22 minidsp-shd volumio[19645]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 25 21:41:22 minidsp-shd volumio[19645]: SPOTIFY: SPOTIFY VOLUME 99 Feb 25 21:41:22 minidsp-shd volumio[19645]: SPOTIFY: VOLUMIO VOLUME 100 Feb 25 21:41:22 minidsp-shd volumio[19645]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 25 21:41:23 minidsp-shd volumio[19645]: info: Initializing connection to go-librespot Websocket Feb 25 21:41:23 minidsp-shd volumio[19645]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:41:23 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 25 21:41:23 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 251. Feb 25 21:41:23 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Feb 25 21:41:23 minidsp-shd systemd[1]: Started go-librespot Daemon. Feb 25 21:41:23 minidsp-shd go-librespot[20459]: Librespot-go daemon starting... Feb 25 21:41:23 minidsp-shd go-librespot[20459]: time="2025-02-25T21:41:23+01:00" level=info msg="generated new device id: b3c4751c4b05fb15e976f106fd82790d9031e2e9" Feb 25 21:41:23 minidsp-shd go-librespot[20459]: time="2025-02-25T21:41:23+01:00" level=debug msg="stored credentials found for saschabies80" Feb 25 21:41:23 minidsp-shd go-librespot[20459]: time="2025-02-25T21:41:23+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 25 21:41:23 minidsp-shd go-librespot[20459]: time="2025-02-25T21:41:23+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 25 21:41:23 minidsp-shd go-librespot[20459]: time="2025-02-25T21:41:23+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 25 21:41:23 minidsp-shd go-librespot[20459]: time="2025-02-25T21:41:23+01:00" level=debug msg="zeroconf server listening on port 34709" Feb 25 21:41:23 minidsp-shd go-librespot[20459]: time="2025-02-25T21:41:23+01:00" level=debug msg="obtained new client token: AAAbLvnFWPPXmwF3ISDuv1iQEqFVhjU3bnAhDgj3F59gwvA3bYEzKF3mVGt+vfvPwy9qU/FeqAbq+mcrZ4gHlBswk9LGe9zjiNKx1I6H2FUolWpeF3kvd7Gc2/XsmUz60DoO9WbsBvSzp8OWqVqXEsThbJneIQ0q453VYgFSEBeeDfPSupPXiY+Ok0EYYh4y+di0n2XGoAjzWbrMkdLATPhPq5EFkUmCabMQh1Dbda7Ft7QCOkSxQpSa9Aftew==" Feb 25 21:41:23 minidsp-shd go-librespot[20459]: time="2025-02-25T21:41:23+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 25 21:41:23 minidsp-shd go-librespot[20459]: time="2025-02-25T21:41:23+01:00" level=debug msg="completed keyexchange" Feb 25 21:41:24 minidsp-shd go-librespot[20459]: time="2025-02-25T21:41:24+01:00" level=debug msg="completed challenge" Feb 25 21:41:24 minidsp-shd go-librespot[20459]: time="2025-02-25T21:41:24+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 25 21:41:24 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 21:41:24 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 21:41:26 minidsp-shd volumio[19645]: info: Initializing connection to go-librespot Websocket Feb 25 21:41:26 minidsp-shd volumio[19645]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:41:27 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 25 21:41:27 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 252. Feb 25 21:41:27 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Feb 25 21:41:27 minidsp-shd systemd[1]: Started go-librespot Daemon. Feb 25 21:41:27 minidsp-shd go-librespot[20467]: Librespot-go daemon starting... Feb 25 21:41:27 minidsp-shd go-librespot[20467]: time="2025-02-25T21:41:27+01:00" level=info msg="generated new device id: 8a1100e6d7660a27dbc93e8c15255ecdce78a82b" Feb 25 21:41:27 minidsp-shd go-librespot[20467]: time="2025-02-25T21:41:27+01:00" level=debug msg="stored credentials found for saschabies80" Feb 25 21:41:27 minidsp-shd go-librespot[20467]: time="2025-02-25T21:41: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-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 25 21:41:27 minidsp-shd go-librespot[20467]: time="2025-02-25T21:41:27+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 25 21:41:27 minidsp-shd go-librespot[20467]: time="2025-02-25T21:41:27+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 25 21:41:27 minidsp-shd go-librespot[20467]: time="2025-02-25T21:41:27+01:00" level=debug msg="zeroconf server listening on port 34205" Feb 25 21:41:27 minidsp-shd go-librespot[20467]: time="2025-02-25T21:41:27+01:00" level=debug msg="obtained new client token: AACvXW5raNEq9OJSTP9XFrF6tnlMZhzOgjG6WWyDPcQjJKL7iKsAuhZN5QauL+iSEVhlmXJN+Tl5a9oLNkQQ5HlKxFSVVF3bJlxTiCU7elXSjqNw0BCSKgczOvsG6oNMBbWngKeJ/jXKLxkkT0EUZmAKJn83HHlKGQSJ1Vtc8PRAht/iyIZK7ESvQ0ifp+A7E78un0Z76bb9AzRe7bB10wzK2d8SwtTJZVYeS4ocfQz4QmECnwybtGywOZr/Ig==" Feb 25 21:41:28 minidsp-shd go-librespot[20467]: time="2025-02-25T21:41:28+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 25 21:41:28 minidsp-shd go-librespot[20467]: time="2025-02-25T21:41:28+01:00" level=debug msg="completed keyexchange" Feb 25 21:41:28 minidsp-shd go-librespot[20467]: time="2025-02-25T21:41:28+01:00" level=debug msg="completed challenge" Feb 25 21:41:28 minidsp-shd go-librespot[20467]: time="2025-02-25T21:41: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 25 21:41:28 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 21:41:28 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 21:41:29 minidsp-shd volumio[19645]: info: Initializing connection to go-librespot Websocket Feb 25 21:41:29 minidsp-shd volumio[19645]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:41:31 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 25 21:41:31 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 253. Feb 25 21:41:31 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Feb 25 21:41:31 minidsp-shd systemd[1]: Started go-librespot Daemon. Feb 25 21:41:31 minidsp-shd go-librespot[20477]: Librespot-go daemon starting... Feb 25 21:41:31 minidsp-shd go-librespot[20477]: time="2025-02-25T21:41:31+01:00" level=info msg="generated new device id: fa3d8d34178685fbcad00cfa3b7b5d9fe868988f" Feb 25 21:41:31 minidsp-shd go-librespot[20477]: time="2025-02-25T21:41:31+01:00" level=debug msg="stored credentials found for saschabies80" Feb 25 21:41:32 minidsp-shd volumio[19645]: info: Initializing connection to go-librespot Websocket Feb 25 21:41:32 minidsp-shd go-librespot[20477]: time="2025-02-25T21:41:32+01:00" level=debug msg="new websocket client" Feb 25 21:41:32 minidsp-shd go-librespot[20477]: time="2025-02-25T21:41: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 25 21:41:32 minidsp-shd go-librespot[20477]: time="2025-02-25T21:41:32+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 25 21:41:32 minidsp-shd go-librespot[20477]: time="2025-02-25T21:41:32+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 25 21:41:32 minidsp-shd volumio[19645]: info: Connection to go-librespot Websocket established Feb 25 21:41:32 minidsp-shd go-librespot[20477]: time="2025-02-25T21:41:32+01:00" level=debug msg="zeroconf server listening on port 37715" Feb 25 21:41:32 minidsp-shd go-librespot[20477]: time="2025-02-25T21:41:32+01:00" level=debug msg="obtained new client token: AACe40tDhbLNptNEmk3Gm/DaMWq9VmUM8lLBtGHinxymVHwdviEo6RB/l2QYMNbqHEH+DqVjZtBBXXaEQbNTQLEe5xcETvPnsx2TN9wOfD5+IIOB46tn5fZKKHvHC0stnNcAfzQ5eRCRgWukgaOuH88wMnFc7YhffsY+g8DRm0idKGVznUG1kVMIWSUvZfdmMjobERLixve4ZslMpd+RZm3JfqopQ87vx6l41yDhHEID4K3hgdc2i/SyRdU=" Feb 25 21:41:32 minidsp-shd go-librespot[20477]: time="2025-02-25T21:41:32+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 25 21:41:32 minidsp-shd go-librespot[20477]: time="2025-02-25T21:41:32+01:00" level=debug msg="completed keyexchange" Feb 25 21:41:32 minidsp-shd go-librespot[20477]: time="2025-02-25T21:41:32+01:00" level=debug msg="completed challenge" Feb 25 21:41:32 minidsp-shd go-librespot[20477]: time="2025-02-25T21:41:32+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 25 21:41:32 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 21:41:32 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 21:41:32 minidsp-shd volumio[19645]: info: Connection to go-librespot Websocket closed Feb 25 21:41:33 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 25 21:41:33 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 25 21:41:33 minidsp-shd volumio[19645]: info: Discovery: Getting this device information Feb 25 21:41:33 minidsp-shd volumio[19645]: info: CoreCommandRouter::volumioGetState Feb 25 21:41:33 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 25 21:41:35 minidsp-shd volumio[19645]: info: Getting Spotify volume Feb 25 21:41:35 minidsp-shd volumio[19645]: (node:19645) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:41:35 minidsp-shd volumio[19645]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Feb 25 21:41:35 minidsp-shd volumio[19645]: (node:19645) 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: 12) Feb 25 21:41:35 minidsp-shd volumio[19645]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Feb 25 21:41:35 minidsp-shd volumio[19645]: info: CoreCommandRouter::volumioGetState Feb 25 21:41:35 minidsp-shd volumio[19645]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 25 21:41:35 minidsp-shd volumio[19645]: SPOTIFY: SPOTIFY VOLUME 99 Feb 25 21:41:35 minidsp-shd volumio[19645]: SPOTIFY: VOLUMIO VOLUME 100 Feb 25 21:41:35 minidsp-shd volumio[19645]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 25 21:41:35 minidsp-shd volumio[19645]: info: Initializing connection to go-librespot Websocket Feb 25 21:41:35 minidsp-shd volumio[19645]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:41:36 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 25 21:41:36 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 254. Feb 25 21:41:36 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Feb 25 21:41:36 minidsp-shd systemd[1]: Started go-librespot Daemon. Feb 25 21:41:36 minidsp-shd go-librespot[20486]: Librespot-go daemon starting... Feb 25 21:41:36 minidsp-shd go-librespot[20486]: time="2025-02-25T21:41:36+01:00" level=info msg="generated new device id: 1eef06798cdb5c3d5e4328780729c074509e475d" Feb 25 21:41:36 minidsp-shd go-librespot[20486]: time="2025-02-25T21:41:36+01:00" level=debug msg="stored credentials found for saschabies80" Feb 25 21:41:36 minidsp-shd go-librespot[20486]: time="2025-02-25T21:41: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-gew1.spotify.com:80]" Feb 25 21:41:36 minidsp-shd go-librespot[20486]: time="2025-02-25T21:41:36+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 25 21:41:36 minidsp-shd go-librespot[20486]: time="2025-02-25T21:41:36+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 25 21:41:36 minidsp-shd go-librespot[20486]: time="2025-02-25T21:41:36+01:00" level=debug msg="zeroconf server listening on port 42331" Feb 25 21:41:36 minidsp-shd go-librespot[20486]: time="2025-02-25T21:41:36+01:00" level=debug msg="obtained new client token: AAAQtprCoCB04LqZ9xvScAsP5iqI7zw2PIWN4ZOiFmhUp92sTaY26RzAv7OLVnGBZVUMkF6VeDF8VutLjtKTQefyvv32jtl5c9ZisY0+DWZpGJUxkFAKEKuRc+9vhXelsOZ6SzxUOQsn/i4ma/gSfY9awgF3m3f8f35bTpQtL6gYIOtdBbC0Ll4wVzJhG0kmssW3OOGwHPB0gLyhqHRG6UuC8QvF8Z2MMWTnuCobH/z01DS13y+hgYmc/EVAKw==" Feb 25 21:41:36 minidsp-shd go-librespot[20486]: time="2025-02-25T21:41:36+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 25 21:41:36 minidsp-shd go-librespot[20486]: time="2025-02-25T21:41:36+01:00" level=debug msg="completed keyexchange" Feb 25 21:41:37 minidsp-shd go-librespot[20486]: time="2025-02-25T21:41:37+01:00" level=debug msg="completed challenge" Feb 25 21:41:37 minidsp-shd go-librespot[20486]: time="2025-02-25T21:41:37+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 25 21:41:37 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 21:41:37 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 21:41:38 minidsp-shd volumio[19645]: info: Initializing connection to go-librespot Websocket Feb 25 21:41:38 minidsp-shd volumio[19645]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:41:40 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 25 21:41:40 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 255. Feb 25 21:41:40 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Feb 25 21:41:40 minidsp-shd systemd[1]: Started go-librespot Daemon. Feb 25 21:41:40 minidsp-shd go-librespot[20496]: Librespot-go daemon starting... Feb 25 21:41:40 minidsp-shd go-librespot[20496]: time="2025-02-25T21:41:40+01:00" level=info msg="generated new device id: fea7a5180a41014c19d0e41e45411afa67a18a16" Feb 25 21:41:40 minidsp-shd go-librespot[20496]: time="2025-02-25T21:41:40+01:00" level=debug msg="stored credentials found for saschabies80" Feb 25 21:41:40 minidsp-shd go-librespot[20496]: time="2025-02-25T21:41:40+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 25 21:41:40 minidsp-shd go-librespot[20496]: time="2025-02-25T21:41:40+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 25 21:41:40 minidsp-shd go-librespot[20496]: time="2025-02-25T21:41:40+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 25 21:41:40 minidsp-shd go-librespot[20496]: time="2025-02-25T21:41:40+01:00" level=debug msg="zeroconf server listening on port 34177" Feb 25 21:41:40 minidsp-shd go-librespot[20496]: time="2025-02-25T21:41:40+01:00" level=debug msg="obtained new client token: AABTyITA9rEVlqqMCfUEZpl5JAW6RsIkXT4f1Z08PptLgoT/CGJozYy2h6Vp+Jz3oNgYuAAIwuXnVW31AKIPKzbuQPCyNj+tJrGFXmk3mF2UTEUJLwrEUONwRXVHfKWB3kOsknd8M6wv4hIgcW372c90ZZrlBQMtZ17FNpvo/IkXi5T3wfuawaZUjfuGNUUZaEQxRVS2vnPuz7yNaVltuHyjFYVqWOeWlkyoB72gxTYEjnABWluDHABEneI9uw==" Feb 25 21:41:40 minidsp-shd go-librespot[20496]: time="2025-02-25T21:41:40+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 25 21:41:40 minidsp-shd go-librespot[20496]: time="2025-02-25T21:41:40+01:00" level=debug msg="completed keyexchange" Feb 25 21:41:41 minidsp-shd go-librespot[20496]: time="2025-02-25T21:41:41+01:00" level=debug msg="completed challenge" Feb 25 21:41:41 minidsp-shd go-librespot[20496]: time="2025-02-25T21:41:41+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 25 21:41:41 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 21:41:41 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 21:41:41 minidsp-shd volumio[19645]: info: Initializing connection to go-librespot Websocket Feb 25 21:41:41 minidsp-shd volumio[19645]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:41:44 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 25 21:41:44 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 256. Feb 25 21:41:44 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Feb 25 21:41:44 minidsp-shd systemd[1]: Started go-librespot Daemon. Feb 25 21:41:44 minidsp-shd go-librespot[20504]: Librespot-go daemon starting... Feb 25 21:41:44 minidsp-shd go-librespot[20504]: time="2025-02-25T21:41:44+01:00" level=info msg="generated new device id: d819e43da0720fee8a3375c6f64f41470668c89b" Feb 25 21:41:44 minidsp-shd go-librespot[20504]: time="2025-02-25T21:41:44+01:00" level=debug msg="stored credentials found for saschabies80" Feb 25 21:41:44 minidsp-shd go-librespot[20504]: time="2025-02-25T21:41:44+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 25 21:41:44 minidsp-shd go-librespot[20504]: time="2025-02-25T21:41:44+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 25 21:41:44 minidsp-shd go-librespot[20504]: time="2025-02-25T21:41:44+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 25 21:41:44 minidsp-shd go-librespot[20504]: time="2025-02-25T21:41:44+01:00" level=debug msg="zeroconf server listening on port 42319" Feb 25 21:41:44 minidsp-shd volumio[19645]: info: Initializing connection to go-librespot Websocket Feb 25 21:41:44 minidsp-shd go-librespot[20504]: time="2025-02-25T21:41:44+01:00" level=debug msg="new websocket client" Feb 25 21:41:44 minidsp-shd volumio[19645]: info: Connection to go-librespot Websocket established Feb 25 21:41:45 minidsp-shd go-librespot[20504]: time="2025-02-25T21:41:45+01:00" level=debug msg="obtained new client token: AACBk/uBuro9dri5yRQysoHFYIHBsgusD8tr0Of4Ne1QrD4A9KhxYwsl8CXzROJLIBP2gBHGlYCidm/W/yZhRqPofFsXvD56t74pTccEIvAbHHdE8tz6HNMBGhbQ0fPfTskZm/VGaHfpb0P15mZSCXB+JhLD+WhvS8SNGIn3tr3BxcWVOXXqzkxhHShpdPQ/okJplM57W9K9UaogEY0506bUfIqRaNbbz+ZkFk/d3ySGD6c3iS1+zua2LOI=" Feb 25 21:41:45 minidsp-shd go-librespot[20504]: time="2025-02-25T21:41:45+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 25 21:41:45 minidsp-shd go-librespot[20504]: time="2025-02-25T21:41:45+01:00" level=debug msg="completed keyexchange" Feb 25 21:41:45 minidsp-shd go-librespot[20504]: time="2025-02-25T21:41:45+01:00" level=debug msg="completed challenge" Feb 25 21:41:45 minidsp-shd go-librespot[20504]: time="2025-02-25T21:41: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 25 21:41:45 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 21:41:45 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 21:41:45 minidsp-shd volumio[19645]: info: Connection to go-librespot Websocket closed Feb 25 21:41:47 minidsp-shd volumio[19645]: info: Getting Spotify volume Feb 25 21:41:47 minidsp-shd volumio[19645]: (node:19645) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:41:47 minidsp-shd volumio[19645]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Feb 25 21:41:47 minidsp-shd volumio[19645]: (node:19645) 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: 13) Feb 25 21:41:47 minidsp-shd volumio[19645]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Feb 25 21:41:48 minidsp-shd volumio[19645]: info: CoreCommandRouter::volumioGetState Feb 25 21:41:48 minidsp-shd volumio[19645]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 25 21:41:48 minidsp-shd volumio[19645]: SPOTIFY: SPOTIFY VOLUME 99 Feb 25 21:41:48 minidsp-shd volumio[19645]: SPOTIFY: VOLUMIO VOLUME 100 Feb 25 21:41:48 minidsp-shd volumio[19645]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 25 21:41:48 minidsp-shd volumio[19645]: info: Initializing connection to go-librespot Websocket Feb 25 21:41:48 minidsp-shd volumio[19645]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:41:48 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 25 21:41:48 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 257. Feb 25 21:41:48 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Feb 25 21:41:48 minidsp-shd systemd[1]: Started go-librespot Daemon. Feb 25 21:41:48 minidsp-shd go-librespot[20512]: Librespot-go daemon starting... Feb 25 21:41:48 minidsp-shd go-librespot[20512]: time="2025-02-25T21:41:48+01:00" level=info msg="generated new device id: bfee8f299729cfd54394f179455343503bc6f61c" Feb 25 21:41:48 minidsp-shd go-librespot[20512]: time="2025-02-25T21:41:48+01:00" level=debug msg="stored credentials found for saschabies80" Feb 25 21:41:49 minidsp-shd go-librespot[20512]: time="2025-02-25T21:41: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 25 21:41:49 minidsp-shd go-librespot[20512]: time="2025-02-25T21:41:49+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 25 21:41:49 minidsp-shd go-librespot[20512]: time="2025-02-25T21:41:49+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 25 21:41:49 minidsp-shd go-librespot[20512]: time="2025-02-25T21:41:49+01:00" level=debug msg="zeroconf server listening on port 36347" Feb 25 21:41:49 minidsp-shd go-librespot[20512]: time="2025-02-25T21:41:49+01:00" level=debug msg="obtained new client token: AAAN48otox9aN5Dm7wwHsNT4/MfRDyEXq4c0zKoWBiIfUbFQCwSd064aILLn07E77zjf3DCqY+yMwPM94aCEj5V59jPiyeMOWdWFewS7hD1QMAzNJ9rDPlxyfH4s/hgdeKIImM9mf3bBx5igjTAEB/gm0XxeoFWWm02b5DHq5+te7TI10t9DBQpItN+5LO6YxybRdC1K9HxBZ3FnF74U8SBtqBKzyapfB9IPAZZReVQEv2yPQENQjzUiORM=" Feb 25 21:41:49 minidsp-shd go-librespot[20512]: time="2025-02-25T21:41:49+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 25 21:41:49 minidsp-shd go-librespot[20512]: time="2025-02-25T21:41:49+01:00" level=debug msg="completed keyexchange" Feb 25 21:41:49 minidsp-shd go-librespot[20512]: time="2025-02-25T21:41:49+01:00" level=debug msg="completed challenge" Feb 25 21:41:49 minidsp-shd go-librespot[20512]: time="2025-02-25T21:41:49+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 25 21:41:49 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 21:41:49 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 21:41:51 minidsp-shd volumio[19645]: info: Initializing connection to go-librespot Websocket Feb 25 21:41:51 minidsp-shd volumio[19645]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:41:53 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 25 21:41:53 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 258. Feb 25 21:41:53 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Feb 25 21:41:53 minidsp-shd systemd[1]: Started go-librespot Daemon. Feb 25 21:41:53 minidsp-shd go-librespot[20520]: Librespot-go daemon starting... Feb 25 21:41:53 minidsp-shd go-librespot[20520]: time="2025-02-25T21:41:53+01:00" level=info msg="generated new device id: 456208e6fac30c6c334afe06313c61030c99fa32" Feb 25 21:41:53 minidsp-shd go-librespot[20520]: time="2025-02-25T21:41:53+01:00" level=debug msg="stored credentials found for saschabies80" Feb 25 21:41:53 minidsp-shd go-librespot[20520]: time="2025-02-25T21:41:53+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 25 21:41:53 minidsp-shd go-librespot[20520]: time="2025-02-25T21:41:53+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 25 21:41:53 minidsp-shd go-librespot[20520]: time="2025-02-25T21:41:53+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 25 21:41:53 minidsp-shd go-librespot[20520]: time="2025-02-25T21:41:53+01:00" level=debug msg="zeroconf server listening on port 38801" Feb 25 21:41:53 minidsp-shd go-librespot[20520]: time="2025-02-25T21:41:53+01:00" level=debug msg="obtained new client token: AADZxWhGVxVzyDChYhdroj4nwYez6hzDtn17xIfksZ2Jh5Ga9MCfhZVzPzsWJt1WJgvpo3FsutSWEz4qaHwJVlNbOfx305GoZ1qOqScRvg3Rp/Zfz5NQLElM60eOIQEXRfPsYfoQbWvTiQLIj7iDC7VlURYGPJcaMKy5oklSAREB1yEvU3yyWtZzYcS30ajf3iZLuFgXkcUqtbOsgI1FFo+8T4U6DCcWLeio7xCCyF/x2izS/o1M275I/qmZeA==" Feb 25 21:41:53 minidsp-shd go-librespot[20520]: time="2025-02-25T21:41:53+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 25 21:41:53 minidsp-shd go-librespot[20520]: time="2025-02-25T21:41:53+01:00" level=debug msg="completed keyexchange" Feb 25 21:41:54 minidsp-shd go-librespot[20520]: time="2025-02-25T21:41:54+01:00" level=debug msg="completed challenge" Feb 25 21:41:54 minidsp-shd go-librespot[20520]: time="2025-02-25T21:41:54+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 25 21:41:54 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 21:41:54 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 21:41:54 minidsp-shd volumio[19645]: info: Initializing connection to go-librespot Websocket Feb 25 21:41:54 minidsp-shd volumio[19645]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:41:57 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 25 21:41:57 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 259. Feb 25 21:41:57 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Feb 25 21:41:57 minidsp-shd systemd[1]: Started go-librespot Daemon. Feb 25 21:41:57 minidsp-shd go-librespot[20528]: Librespot-go daemon starting... Feb 25 21:41:57 minidsp-shd go-librespot[20528]: time="2025-02-25T21:41:57+01:00" level=info msg="generated new device id: e4146bbd9b9fa8ed393c6276de4c0cafae0a08cf" Feb 25 21:41:57 minidsp-shd go-librespot[20528]: time="2025-02-25T21:41:57+01:00" level=debug msg="stored credentials found for saschabies80" Feb 25 21:41:57 minidsp-shd go-librespot[20528]: time="2025-02-25T21:41:57+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 25 21:41:57 minidsp-shd go-librespot[20528]: time="2025-02-25T21:41:57+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 25 21:41:57 minidsp-shd go-librespot[20528]: time="2025-02-25T21:41:57+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 25 21:41:57 minidsp-shd go-librespot[20528]: time="2025-02-25T21:41:57+01:00" level=debug msg="zeroconf server listening on port 37885" Feb 25 21:41:57 minidsp-shd volumio[19645]: info: Initializing connection to go-librespot Websocket Feb 25 21:41:57 minidsp-shd go-librespot[20528]: time="2025-02-25T21:41:57+01:00" level=debug msg="new websocket client" Feb 25 21:41:57 minidsp-shd volumio[19645]: info: Connection to go-librespot Websocket established Feb 25 21:41:57 minidsp-shd go-librespot[20528]: time="2025-02-25T21:41:57+01:00" level=debug msg="obtained new client token: AAAa8+e1oqEumZ4P98wgHXqbu9gmZREnB9izHjCI0WOZV6jB4HKPxism9GoiQuYLcxSZ1v/KuVfYYf9XDpFRGaXkPiM79qv49EijQLl9SDncZtzZ5qy0j7U/cxo47+BnwhIIZaUUU+Rno1+kxU8w2MD6al1FLvYHGtIrP2kJnauoXz3yEpJtT/Up4s8wgyCE1PEag2rqNjD+i1XiK2IKWng50cupscHNHZEUL3Y0rfikSyHfcZOPqE0f7IQlXg==" Feb 25 21:41:57 minidsp-shd go-librespot[20528]: time="2025-02-25T21:41:57+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 25 21:41:57 minidsp-shd go-librespot[20528]: time="2025-02-25T21:41:57+01:00" level=debug msg="completed keyexchange" Feb 25 21:41:58 minidsp-shd go-librespot[20528]: time="2025-02-25T21:41:58+01:00" level=debug msg="completed challenge" Feb 25 21:41:58 minidsp-shd go-librespot[20528]: time="2025-02-25T21:41:58+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 25 21:41:58 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 21:41:58 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 21:41:58 minidsp-shd volumio[19645]: info: Connection to go-librespot Websocket closed Feb 25 21:42:00 minidsp-shd volumio[19645]: info: Getting Spotify volume Feb 25 21:42:00 minidsp-shd volumio[19645]: (node:19645) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:42:00 minidsp-shd volumio[19645]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Feb 25 21:42:00 minidsp-shd volumio[19645]: (node:19645) 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: 14) Feb 25 21:42:00 minidsp-shd volumio[19645]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Feb 25 21:42:00 minidsp-shd volumio[19645]: info: CoreCommandRouter::volumioGetState Feb 25 21:42:00 minidsp-shd volumio[19645]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 25 21:42:00 minidsp-shd volumio[19645]: SPOTIFY: SPOTIFY VOLUME 99 Feb 25 21:42:00 minidsp-shd volumio[19645]: SPOTIFY: VOLUMIO VOLUME 100 Feb 25 21:42:00 minidsp-shd volumio[19645]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 25 21:42:01 minidsp-shd volumio[19645]: info: Initializing connection to go-librespot Websocket Feb 25 21:42:01 minidsp-shd volumio[19645]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:42:01 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 25 21:42:01 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 260. Feb 25 21:42:01 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Feb 25 21:42:01 minidsp-shd systemd[1]: Started go-librespot Daemon. Feb 25 21:42:01 minidsp-shd go-librespot[20537]: Librespot-go daemon starting... Feb 25 21:42:01 minidsp-shd go-librespot[20537]: time="2025-02-25T21:42:01+01:00" level=info msg="generated new device id: d5ef01e78c3a49768bbe71640fd8ae2fbbcce4a2" Feb 25 21:42:01 minidsp-shd go-librespot[20537]: time="2025-02-25T21:42:01+01:00" level=debug msg="stored credentials found for saschabies80" Feb 25 21:42:01 minidsp-shd go-librespot[20537]: time="2025-02-25T21:42:01+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 25 21:42:01 minidsp-shd go-librespot[20537]: time="2025-02-25T21:42:01+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 25 21:42:01 minidsp-shd go-librespot[20537]: time="2025-02-25T21:42:01+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 25 21:42:01 minidsp-shd go-librespot[20537]: time="2025-02-25T21:42:01+01:00" level=debug msg="zeroconf server listening on port 45361" Feb 25 21:42:02 minidsp-shd go-librespot[20537]: time="2025-02-25T21:42:02+01:00" level=debug msg="obtained new client token: AABmA4zUm96YAgkLVYeWs77ldN1V9b3B0fFgxIFGm47T4AtuQGan5sJoQNcqtId4l8pbhnPqOPEoR2KYzoim2UWwXEIWbfvWUQMp8ZyIKq9yo7uRz0C+SeEX2wZ9Xk9ZgDWv3WyTXDgmGxGeTYQNeyt79q7CJ/EGmy0Xnd/xe0CXtPzUd1CfsURPUYiv7hjEy7CaVp4O/iUxE1xfeynlREASzrLHYc8DX3KKVLXEgkvaSkPMYlDHc8Xu" Feb 25 21:42:02 minidsp-shd go-librespot[20537]: time="2025-02-25T21:42:02+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 25 21:42:02 minidsp-shd go-librespot[20537]: time="2025-02-25T21:42:02+01:00" level=debug msg="completed keyexchange" Feb 25 21:42:02 minidsp-shd go-librespot[20537]: time="2025-02-25T21:42:02+01:00" level=debug msg="completed challenge" Feb 25 21:42:02 minidsp-shd go-librespot[20537]: time="2025-02-25T21:42:02+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 25 21:42:02 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 21:42:02 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 21:42:03 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 25 21:42:04 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 25 21:42:04 minidsp-shd volumio[19645]: info: Discovery: Getting this device information Feb 25 21:42:04 minidsp-shd volumio[19645]: info: CoreCommandRouter::volumioGetState Feb 25 21:42:04 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 25 21:42:04 minidsp-shd volumio[19645]: info: Initializing connection to go-librespot Websocket Feb 25 21:42:04 minidsp-shd volumio[19645]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:42:05 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 25 21:42:05 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 261. Feb 25 21:42:05 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Feb 25 21:42:05 minidsp-shd systemd[1]: Started go-librespot Daemon. Feb 25 21:42:05 minidsp-shd go-librespot[20546]: Librespot-go daemon starting... Feb 25 21:42:05 minidsp-shd go-librespot[20546]: time="2025-02-25T21:42:05+01:00" level=info msg="generated new device id: c6af4133bcb64920eba15c6dd839e6df89d8aad2" Feb 25 21:42:05 minidsp-shd go-librespot[20546]: time="2025-02-25T21:42:05+01:00" level=debug msg="stored credentials found for saschabies80" Feb 25 21:42:06 minidsp-shd volumio[19645]: info: CoreCommandRouter::volumioGetState Feb 25 21:42:06 minidsp-shd go-librespot[20546]: time="2025-02-25T21:42:06+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 25 21:42:06 minidsp-shd go-librespot[20546]: time="2025-02-25T21:42:06+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 25 21:42:06 minidsp-shd go-librespot[20546]: time="2025-02-25T21:42:06+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 25 21:42:06 minidsp-shd go-librespot[20546]: time="2025-02-25T21:42:06+01:00" level=debug msg="zeroconf server listening on port 36547" Feb 25 21:42:06 minidsp-shd go-librespot[20546]: time="2025-02-25T21:42:06+01:00" level=debug msg="obtained new client token: AAAAbtWkR1l5z6+Kmm39XckEpvPN2BssulJ2ORSMumbBuBWFaebV+GjAXOxVOvWsTRPJTWV8Vg8MxCi7hItMQOwxqKOaEbFBsUCAJxZl4wIbniXu+76iXq5VItdjS2KFUFXtDjjTtfAWwI9t7HvuLmBVkGR85utfSHqsf4CgbMnA+3yYqMyksqYvGYMiDKUOOMoB3ygObPyQryZXDnTkjRdVf5gbPArLRR8JF0Ce33aCZEDcaKqTcM9BCkY=" Feb 25 21:42:06 minidsp-shd go-librespot[20546]: time="2025-02-25T21:42:06+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 25 21:42:06 minidsp-shd go-librespot[20546]: time="2025-02-25T21:42:06+01:00" level=debug msg="completed keyexchange" Feb 25 21:42:06 minidsp-shd go-librespot[20546]: time="2025-02-25T21:42:06+01:00" level=debug msg="completed challenge" Feb 25 21:42:06 minidsp-shd go-librespot[20546]: time="2025-02-25T21:42: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 25 21:42:06 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 21:42:06 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 21:42:07 minidsp-shd volumio[19645]: info: Initializing connection to go-librespot Websocket Feb 25 21:42:07 minidsp-shd volumio[19645]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:42:08 minidsp-shd volumio[19645]: info: Executing endpoint metavolumio Feb 25 21:42:08 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 25 21:42:08 minidsp-shd volumio[19645]: info: Executing endpoint metavolumio Feb 25 21:42:08 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 25 21:42:08 minidsp-shd volumio[19645]: info: Executing endpoint metavolumio Feb 25 21:42:08 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 25 21:42:08 minidsp-shd volumio[19645]: info: CorePlayQueue::getTrack 1 Feb 25 21:42:08 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: qobuz , goto Feb 25 21:42:09 minidsp-shd volumio[19645]: info: explodeUri took 565 milliseconds Feb 25 21:42:09 minidsp-shd volumio[19645]: info: handleBrowseUri took 614 milliseconds Feb 25 21:42:10 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 25 21:42:10 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 262. Feb 25 21:42:10 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Feb 25 21:42:10 minidsp-shd systemd[1]: Started go-librespot Daemon. Feb 25 21:42:10 minidsp-shd go-librespot[20592]: Librespot-go daemon starting... Feb 25 21:42:10 minidsp-shd go-librespot[20592]: time="2025-02-25T21:42:10+01:00" level=info msg="generated new device id: 37dacdd2124b2201b952dfa7a6b6c6f490996a51" Feb 25 21:42:10 minidsp-shd go-librespot[20592]: time="2025-02-25T21:42:10+01:00" level=debug msg="stored credentials found for saschabies80" Feb 25 21:42:10 minidsp-shd volumio[19645]: info: Executing endpoint getSimilarAlbums Feb 25 21:42:10 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Feb 25 21:42:10 minidsp-shd go-librespot[20592]: time="2025-02-25T21:42: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 25 21:42:10 minidsp-shd go-librespot[20592]: time="2025-02-25T21:42:10+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 25 21:42:10 minidsp-shd go-librespot[20592]: time="2025-02-25T21:42:10+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 25 21:42:10 minidsp-shd volumio[19645]: info: Executing endpoint getSimilarAlbums Feb 25 21:42:10 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Feb 25 21:42:10 minidsp-shd go-librespot[20592]: time="2025-02-25T21:42:10+01:00" level=debug msg="zeroconf server listening on port 33291" Feb 25 21:42:10 minidsp-shd volumio[19645]: info: Executing endpoint getSimilarAlbums Feb 25 21:42:10 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Feb 25 21:42:10 minidsp-shd volumio[19645]: info: Initializing connection to go-librespot Websocket Feb 25 21:42:10 minidsp-shd volumio[19645]: info: Executing endpoint getSimilarAlbums Feb 25 21:42:10 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Feb 25 21:42:10 minidsp-shd volumio[19645]: info: Executing endpoint metavolumio Feb 25 21:42:10 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 25 21:42:10 minidsp-shd volumio[19645]: info: Executing endpoint metavolumio Feb 25 21:42:10 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 25 21:42:10 minidsp-shd volumio[19645]: info: Executing endpoint metavolumio Feb 25 21:42:10 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 25 21:42:10 minidsp-shd go-librespot[20592]: time="2025-02-25T21:42:10+01:00" level=debug msg="obtained new client token: AABoXBNlsUH13MvjcgjkKCTMWunPUEvOlRI7Qf7Y2TWRApemHxuXvbLUyFaugptc8oygRPM+Bo3AZ6A0BOAoHW8ryfbKuzeOKMGbXG5oDMs2YTyfwnDs94nUJvjcYrTgnEXJ9ISRCKHa6ek4k3QToKtvp+zLmharBg/kCfvBKNV0pHBIs2DQ1LWHy9YBNHuXeNwjtT6QHI/gQB0VLjZr3/2ANvFt/7BBLxSM1CayJu3uzNmbmLzvD5SS89asCQ==" Feb 25 21:42:10 minidsp-shd go-librespot[20592]: time="2025-02-25T21:42:10+01:00" level=debug msg="new websocket client" Feb 25 21:42:10 minidsp-shd volumio[19645]: info: Executing endpoint metavolumio Feb 25 21:42:10 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 25 21:42:10 minidsp-shd volumio[19645]: info: Connection to go-librespot Websocket established Feb 25 21:42:10 minidsp-shd go-librespot[20592]: time="2025-02-25T21:42:10+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 25 21:42:10 minidsp-shd volumio[19645]: info: Executing endpoint metavolumio Feb 25 21:42:10 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 25 21:42:10 minidsp-shd volumio[19645]: info: Executing endpoint metavolumio Feb 25 21:42:10 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 25 21:42:10 minidsp-shd go-librespot[20592]: time="2025-02-25T21:42:10+01:00" level=debug msg="completed keyexchange" Feb 25 21:42:10 minidsp-shd volumio[19645]: info: Executing endpoint metavolumio Feb 25 21:42:10 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 25 21:42:10 minidsp-shd volumio[19645]: info: Executing endpoint metavolumio Feb 25 21:42:10 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 25 21:42:11 minidsp-shd go-librespot[20592]: time="2025-02-25T21:42:11+01:00" level=debug msg="completed challenge" Feb 25 21:42:11 minidsp-shd go-librespot[20592]: time="2025-02-25T21:42: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 25 21:42:11 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 21:42:11 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 21:42:11 minidsp-shd volumio[19645]: info: Connection to go-librespot Websocket closed Feb 25 21:42:13 minidsp-shd volumio[19645]: info: Getting Spotify volume Feb 25 21:42:13 minidsp-shd volumio[19645]: (node:19645) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:42:13 minidsp-shd volumio[19645]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Feb 25 21:42:13 minidsp-shd volumio[19645]: (node:19645) 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: 15) Feb 25 21:42:13 minidsp-shd volumio[19645]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Feb 25 21:42:13 minidsp-shd volumio[19645]: info: CoreCommandRouter::volumioGetState Feb 25 21:42:13 minidsp-shd volumio[19645]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 25 21:42:13 minidsp-shd volumio[19645]: SPOTIFY: SPOTIFY VOLUME 99 Feb 25 21:42:13 minidsp-shd volumio[19645]: SPOTIFY: VOLUMIO VOLUME 100 Feb 25 21:42:13 minidsp-shd volumio[19645]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 25 21:42:14 minidsp-shd volumio[19645]: info: Initializing connection to go-librespot Websocket Feb 25 21:42:14 minidsp-shd volumio[19645]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:42:14 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 25 21:42:14 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 263. Feb 25 21:42:14 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Feb 25 21:42:14 minidsp-shd systemd[1]: Started go-librespot Daemon. Feb 25 21:42:14 minidsp-shd go-librespot[20600]: Librespot-go daemon starting... Feb 25 21:42:14 minidsp-shd go-librespot[20600]: time="2025-02-25T21:42:14+01:00" level=info msg="generated new device id: 09199534f6cbdaae11e477864fe7dcdbea758068" Feb 25 21:42:14 minidsp-shd go-librespot[20600]: time="2025-02-25T21:42:14+01:00" level=debug msg="stored credentials found for saschabies80" Feb 25 21:42:14 minidsp-shd go-librespot[20600]: time="2025-02-25T21:42: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 25 21:42:14 minidsp-shd go-librespot[20600]: time="2025-02-25T21:42: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 25 21:42:14 minidsp-shd go-librespot[20600]: time="2025-02-25T21:42: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 25 21:42:14 minidsp-shd go-librespot[20600]: time="2025-02-25T21:42:14+01:00" level=debug msg="zeroconf server listening on port 33645" Feb 25 21:42:14 minidsp-shd go-librespot[20600]: time="2025-02-25T21:42:14+01:00" level=debug msg="obtained new client token: AACb5Wg6Gf/M+v6GfJPb2a3Ax6MoLv9p4U0YX5zFLZQNDF1V9YlNVHrHVOcFTeHCl0dg9XPta/P9ohk5VCCQOPadyUq5btetarpOleL6VzgUFwHFp8CLuMfAsrAfLAOKCnjRG86jnAGcU8CQCMAurtrQw9sYTlGtg/uUrGt8WpvT1saBrr4YVvbiLXJmrWqgcZqbMOErGHGlI278Xs1n/9+lsKPGSopGXfVjp3umAJwVNr529b9hcmADaQksPg==" Feb 25 21:42:14 minidsp-shd go-librespot[20600]: time="2025-02-25T21:42:14+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 25 21:42:14 minidsp-shd go-librespot[20600]: time="2025-02-25T21:42:14+01:00" level=debug msg="completed keyexchange" Feb 25 21:42:15 minidsp-shd go-librespot[20600]: time="2025-02-25T21:42:15+01:00" level=debug msg="completed challenge" Feb 25 21:42:15 minidsp-shd go-librespot[20600]: time="2025-02-25T21:42:15+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 25 21:42:15 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 21:42:15 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 21:42:17 minidsp-shd volumio[19645]: info: Initializing connection to go-librespot Websocket Feb 25 21:42:17 minidsp-shd volumio[19645]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:42:18 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 25 21:42:18 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 264. Feb 25 21:42:18 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Feb 25 21:42:18 minidsp-shd systemd[1]: Started go-librespot Daemon. Feb 25 21:42:18 minidsp-shd go-librespot[20608]: Librespot-go daemon starting... Feb 25 21:42:18 minidsp-shd go-librespot[20608]: time="2025-02-25T21:42:18+01:00" level=info msg="generated new device id: 19c816e7383f958b196b684fb0d7eb4435d18d40" Feb 25 21:42:18 minidsp-shd go-librespot[20608]: time="2025-02-25T21:42:18+01:00" level=debug msg="stored credentials found for saschabies80" Feb 25 21:42:18 minidsp-shd go-librespot[20608]: time="2025-02-25T21:42: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-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 25 21:42:18 minidsp-shd go-librespot[20608]: time="2025-02-25T21:42:18+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 25 21:42:18 minidsp-shd go-librespot[20608]: time="2025-02-25T21:42:18+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 25 21:42:18 minidsp-shd go-librespot[20608]: time="2025-02-25T21:42:18+01:00" level=debug msg="zeroconf server listening on port 32893" Feb 25 21:42:19 minidsp-shd go-librespot[20608]: time="2025-02-25T21:42:19+01:00" level=debug msg="obtained new client token: AACrsU+J9/C8YZ/n7dbBMYnfZuDv55BBe6DtNEjgx8jJJqvPTEUWryKA9TzzMW0PqzkgeXtEtiBDi8B8ZfJWF9dNcIOQQ76XTqivQyDVJcE6CU/b1ld9N2I2JEWFoXfy5tgyg93qF5/mCCqX+Xcd1+Fi/MFVfmTfmJAnyTgi8cTaForYUY4p7AyaqrG9ZnBJjSlMXGcdPI0i9qscW71YKr5hobyVX4qbtUzTQmrXRw18fOTivZW2aZQvJnD8rA==" Feb 25 21:42:19 minidsp-shd go-librespot[20608]: time="2025-02-25T21:42:19+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 25 21:42:19 minidsp-shd go-librespot[20608]: time="2025-02-25T21:42:19+01:00" level=debug msg="completed keyexchange" Feb 25 21:42:19 minidsp-shd go-librespot[20608]: time="2025-02-25T21:42:19+01:00" level=debug msg="completed challenge" Feb 25 21:42:19 minidsp-shd go-librespot[20608]: time="2025-02-25T21:42: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 25 21:42:19 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 21:42:19 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 21:42:20 minidsp-shd volumio[19645]: info: Initializing connection to go-librespot Websocket Feb 25 21:42:20 minidsp-shd volumio[19645]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:42:22 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 25 21:42:22 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 265. Feb 25 21:42:22 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Feb 25 21:42:22 minidsp-shd systemd[1]: Started go-librespot Daemon. Feb 25 21:42:22 minidsp-shd go-librespot[20616]: Librespot-go daemon starting... Feb 25 21:42:22 minidsp-shd go-librespot[20616]: time="2025-02-25T21:42:22+01:00" level=info msg="generated new device id: 722ff08d634b15a29d40726434d46cceb4ecc590" Feb 25 21:42:22 minidsp-shd go-librespot[20616]: time="2025-02-25T21:42:22+01:00" level=debug msg="stored credentials found for saschabies80" Feb 25 21:42:23 minidsp-shd go-librespot[20616]: time="2025-02-25T21:42:23+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 25 21:42:23 minidsp-shd go-librespot[20616]: time="2025-02-25T21:42:23+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 25 21:42:23 minidsp-shd go-librespot[20616]: time="2025-02-25T21:42:23+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 25 21:42:23 minidsp-shd go-librespot[20616]: time="2025-02-25T21:42:23+01:00" level=debug msg="zeroconf server listening on port 37907" Feb 25 21:42:23 minidsp-shd go-librespot[20616]: time="2025-02-25T21:42:23+01:00" level=debug msg="obtained new client token: AACMPslMFPY/1ImsGlE35keivigHytB6KQGCixPOc7wIrBHmq4yD6UbiR/LuGOYbS4BwAgQ5DyDExBz+HP9QwvLY7UGVWd6dO+/mB8Y/oAWC/U+gGsBzp9z/LerclqV7dabuo6l4TdGjquwABcorMeU3qdiPi8RN9QzuBBYctuZQpnKYPl+NVHaPpxBZgF5Tk3Y6b4N3hFfRi50lQ6sxsmkcyYhIZz9n1LB2ugIiQx3ODDM124e/XjBziaM=" Feb 25 21:42:23 minidsp-shd volumio[19645]: info: Initializing connection to go-librespot Websocket Feb 25 21:42:23 minidsp-shd go-librespot[20616]: time="2025-02-25T21:42:23+01:00" level=debug msg="new websocket client" Feb 25 21:42:23 minidsp-shd volumio[19645]: info: Connection to go-librespot Websocket established Feb 25 21:42:23 minidsp-shd go-librespot[20616]: time="2025-02-25T21:42:23+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 25 21:42:23 minidsp-shd go-librespot[20616]: time="2025-02-25T21:42:23+01:00" level=debug msg="completed keyexchange" Feb 25 21:42:23 minidsp-shd go-librespot[20616]: time="2025-02-25T21:42:23+01:00" level=debug msg="completed challenge" Feb 25 21:42:23 minidsp-shd go-librespot[20616]: time="2025-02-25T21:42: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 25 21:42:23 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 21:42:23 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 21:42:23 minidsp-shd volumio[19645]: info: Connection to go-librespot Websocket closed Feb 25 21:42:25 minidsp-shd volumio[19645]: info: CoreCommandRouter::volumioGetState Feb 25 21:42:26 minidsp-shd volumio[19645]: info: Getting Spotify volume Feb 25 21:42:26 minidsp-shd volumio[19645]: (node:19645) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:42:26 minidsp-shd volumio[19645]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Feb 25 21:42:26 minidsp-shd volumio[19645]: (node:19645) 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: 16) Feb 25 21:42:26 minidsp-shd volumio[19645]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Feb 25 21:42:26 minidsp-shd volumio[19645]: info: CoreCommandRouter::volumioGetState Feb 25 21:42:26 minidsp-shd volumio[19645]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 25 21:42:26 minidsp-shd volumio[19645]: SPOTIFY: SPOTIFY VOLUME 99 Feb 25 21:42:26 minidsp-shd volumio[19645]: SPOTIFY: VOLUMIO VOLUME 100 Feb 25 21:42:26 minidsp-shd volumio[19645]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 25 21:42:26 minidsp-shd volumio[19645]: info: Initializing connection to go-librespot Websocket Feb 25 21:42:26 minidsp-shd volumio[19645]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:42:27 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 25 21:42:27 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 266. Feb 25 21:42:27 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Feb 25 21:42:27 minidsp-shd systemd[1]: Started go-librespot Daemon. Feb 25 21:42:27 minidsp-shd go-librespot[20625]: Librespot-go daemon starting... Feb 25 21:42:27 minidsp-shd go-librespot[20625]: time="2025-02-25T21:42:27+01:00" level=info msg="generated new device id: 6d4965e713e827d3bebd5e14390fc320ff706c0f" Feb 25 21:42:27 minidsp-shd go-librespot[20625]: time="2025-02-25T21:42:27+01:00" level=debug msg="stored credentials found for saschabies80" Feb 25 21:42:27 minidsp-shd volumio[19645]: info: Executing endpoint metavolumio Feb 25 21:42:27 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 25 21:42:27 minidsp-shd go-librespot[20625]: time="2025-02-25T21:42: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 25 21:42:27 minidsp-shd go-librespot[20625]: time="2025-02-25T21:42: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 25 21:42:27 minidsp-shd go-librespot[20625]: time="2025-02-25T21:42: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 25 21:42:27 minidsp-shd volumio[19645]: info: Executing endpoint metavolumio Feb 25 21:42:27 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 25 21:42:27 minidsp-shd go-librespot[20625]: time="2025-02-25T21:42:27+01:00" level=debug msg="zeroconf server listening on port 33619" Feb 25 21:42:27 minidsp-shd volumio[19645]: info: Executing endpoint metavolumio Feb 25 21:42:27 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 25 21:42:27 minidsp-shd go-librespot[20625]: time="2025-02-25T21:42:27+01:00" level=debug msg="obtained new client token: AADh4D395vJmcwfXkouo7ezaoZ2YuQ8wYnB3vqRQ0pO44/flWhpAOx/bNSM3qXDLRWBGn9mO+7b2D2Kgb8tEqGl5OD+T3MEHMLJuQVYuYF+WSiYK+aZVwvIP1+NtReSaX92ovtZd5fp7SGLBQSkeyvhWPOMLlZ8aGBECDX6YmqPvpJFosezyNnV687BQHsf97Wh4NU+B30x7rXyePB7xhpqzkhPjtJBb5JoUz0GcS4LnQakK0xnWbm9Dk7Wrrg==" Feb 25 21:42:27 minidsp-shd go-librespot[20625]: time="2025-02-25T21:42:27+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 25 21:42:27 minidsp-shd go-librespot[20625]: time="2025-02-25T21:42:27+01:00" level=debug msg="completed keyexchange" Feb 25 21:42:28 minidsp-shd go-librespot[20625]: time="2025-02-25T21:42:28+01:00" level=debug msg="completed challenge" Feb 25 21:42:28 minidsp-shd go-librespot[20625]: time="2025-02-25T21:42: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 25 21:42:28 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 21:42:28 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 21:42:29 minidsp-shd volumio[19645]: info: Initializing connection to go-librespot Websocket Feb 25 21:42:29 minidsp-shd volumio[19645]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:42:32 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 25 21:42:32 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 267. Feb 25 21:42:32 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Feb 25 21:42:32 minidsp-shd systemd[1]: Started go-librespot Daemon. Feb 25 21:42:32 minidsp-shd go-librespot[20634]: Librespot-go daemon starting... Feb 25 21:42:32 minidsp-shd go-librespot[20634]: time="2025-02-25T21:42:32+01:00" level=info msg="generated new device id: af3197c863d84488c8424fb3677dc5c3ed767281" Feb 25 21:42:32 minidsp-shd go-librespot[20634]: time="2025-02-25T21:42:32+01:00" level=debug msg="stored credentials found for saschabies80" Feb 25 21:42:32 minidsp-shd volumio[19645]: info: CoreCommandRouter::volumioGetState Feb 25 21:42:32 minidsp-shd go-librespot[20634]: time="2025-02-25T21:42: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 25 21:42:32 minidsp-shd go-librespot[20634]: time="2025-02-25T21:42: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 25 21:42:32 minidsp-shd go-librespot[20634]: time="2025-02-25T21:42: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 25 21:42:32 minidsp-shd go-librespot[20634]: time="2025-02-25T21:42:32+01:00" level=debug msg="zeroconf server listening on port 33305" Feb 25 21:42:32 minidsp-shd go-librespot[20634]: time="2025-02-25T21:42:32+01:00" level=debug msg="obtained new client token: AABWtDktMI04toOVy2qLCNkgaXna8QQpWKljpsjdCqobPn5FQ+jqJPFW7GNOXm8zqZUG8FXW2HetBWFLSf1HQdutrizz3Y9NM32hnun5HKgXekHfmlEeswB2DjrnmWSi+VZO2KWCbEtIK+58EtsdRksiSY7tnqVtK53LBA6yFeJoMp6KyNmuXEcMMezFYX2f3abjueVkh9+oy3qudqXYVcmBH7iT8f33aoTtFd22Y9KebxVq2UoLS4hosK9LsQ==" Feb 25 21:42:32 minidsp-shd go-librespot[20634]: time="2025-02-25T21:42:32+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 25 21:42:32 minidsp-shd go-librespot[20634]: time="2025-02-25T21:42:32+01:00" level=debug msg="completed keyexchange" Feb 25 21:42:32 minidsp-shd volumio[19645]: info: Initializing connection to go-librespot Websocket Feb 25 21:42:32 minidsp-shd go-librespot[20634]: time="2025-02-25T21:42:32+01:00" level=debug msg="new websocket client" Feb 25 21:42:32 minidsp-shd volumio[19645]: info: Connection to go-librespot Websocket established Feb 25 21:42:33 minidsp-shd go-librespot[20634]: time="2025-02-25T21:42:33+01:00" level=debug msg="completed challenge" Feb 25 21:42:33 minidsp-shd go-librespot[20634]: time="2025-02-25T21:42: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 25 21:42:33 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 21:42:33 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 21:42:33 minidsp-shd volumio[19645]: info: Connection to go-librespot Websocket closed Feb 25 21:42:33 minidsp-shd volumio[19645]: info: Executing endpoint metavolumio Feb 25 21:42:33 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 25 21:42:33 minidsp-shd volumio[19645]: info: Executing endpoint metavolumio Feb 25 21:42:33 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 25 21:42:33 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 25 21:42:33 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 25 21:42:33 minidsp-shd volumio[19645]: info: Discovery: Getting this device information Feb 25 21:42:33 minidsp-shd volumio[19645]: info: CoreCommandRouter::volumioGetState Feb 25 21:42:33 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 25 21:42:34 minidsp-shd volumio[19645]: info: Executing endpoint metavolumio Feb 25 21:42:34 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 25 21:42:34 minidsp-shd volumio[19645]: info: Executing endpoint metavolumio Feb 25 21:42:34 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 25 21:42:34 minidsp-shd volumio[19645]: info: Executing endpoint metavolumio Feb 25 21:42:34 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 25 21:42:35 minidsp-shd volumio[19645]: info: Getting Spotify volume Feb 25 21:42:35 minidsp-shd volumio[19645]: (node:19645) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:42:35 minidsp-shd volumio[19645]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Feb 25 21:42:35 minidsp-shd volumio[19645]: (node:19645) 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: 17) Feb 25 21:42:35 minidsp-shd volumio[19645]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Feb 25 21:42:36 minidsp-shd volumio[19645]: info: CoreCommandRouter::volumioGetState Feb 25 21:42:36 minidsp-shd volumio[19645]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 25 21:42:36 minidsp-shd volumio[19645]: SPOTIFY: SPOTIFY VOLUME 99 Feb 25 21:42:36 minidsp-shd volumio[19645]: SPOTIFY: VOLUMIO VOLUME 100 Feb 25 21:42:36 minidsp-shd volumio[19645]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 25 21:42:36 minidsp-shd volumio[19645]: info: Initializing connection to go-librespot Websocket Feb 25 21:42:36 minidsp-shd volumio[19645]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:42:36 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 25 21:42:36 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 268. Feb 25 21:42:36 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Feb 25 21:42:36 minidsp-shd systemd[1]: Started go-librespot Daemon. Feb 25 21:42:36 minidsp-shd go-librespot[20642]: Librespot-go daemon starting... Feb 25 21:42:36 minidsp-shd go-librespot[20642]: time="2025-02-25T21:42:36+01:00" level=info msg="generated new device id: c5fbc665f78b70c907d08730af7b2d1fb5de28f8" Feb 25 21:42:36 minidsp-shd go-librespot[20642]: time="2025-02-25T21:42:36+01:00" level=debug msg="stored credentials found for saschabies80" Feb 25 21:42:36 minidsp-shd go-librespot[20642]: time="2025-02-25T21:42: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 25 21:42:36 minidsp-shd go-librespot[20642]: time="2025-02-25T21:42:36+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 25 21:42:36 minidsp-shd go-librespot[20642]: time="2025-02-25T21:42:36+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 25 21:42:36 minidsp-shd go-librespot[20642]: time="2025-02-25T21:42:36+01:00" level=debug msg="zeroconf server listening on port 34535" Feb 25 21:42:36 minidsp-shd go-librespot[20642]: time="2025-02-25T21:42:36+01:00" level=debug msg="obtained new client token: AAC/uqvVP8UtY5CjqS17icgbDsW5yrIwgCf0jQoU2xpdaRsRIUE3O2Oc7uuZ61YSkSsgGajD64ARqnjCZMKaLuZu1CqNYTekQA8XMA6WbtPhOVOREUwGtcZFaf5cMLBfb4FwUNMK4oqKyikT/Rv3UzTWwqRIzrHVnALNsvTeA4Bm9UhmlbUcxj9Menq12FfUVL6HYPUw8zfGQKwsl8XJVT77Y5m+SyQdT8mtGzkhJCNp5vpMdEGJa86ITuauhQ==" Feb 25 21:42:36 minidsp-shd go-librespot[20642]: time="2025-02-25T21:42:36+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 25 21:42:36 minidsp-shd go-librespot[20642]: time="2025-02-25T21:42:36+01:00" level=debug msg="completed keyexchange" Feb 25 21:42:37 minidsp-shd go-librespot[20642]: time="2025-02-25T21:42:37+01:00" level=debug msg="completed challenge" Feb 25 21:42:37 minidsp-shd go-librespot[20642]: time="2025-02-25T21:42:37+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 25 21:42:37 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 21:42:37 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 21:42:39 minidsp-shd volumio[19645]: info: Initializing connection to go-librespot Websocket Feb 25 21:42:39 minidsp-shd volumio[19645]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:42:40 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 25 21:42:40 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 269. Feb 25 21:42:40 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Feb 25 21:42:40 minidsp-shd systemd[1]: Started go-librespot Daemon. Feb 25 21:42:40 minidsp-shd go-librespot[20650]: Librespot-go daemon starting... Feb 25 21:42:40 minidsp-shd go-librespot[20650]: time="2025-02-25T21:42:40+01:00" level=info msg="generated new device id: 14ea6529fef3d67f1a4f652e02c93d7e71ca2645" Feb 25 21:42:40 minidsp-shd go-librespot[20650]: time="2025-02-25T21:42:40+01:00" level=debug msg="stored credentials found for saschabies80" Feb 25 21:42:40 minidsp-shd go-librespot[20650]: time="2025-02-25T21:42:40+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 25 21:42:40 minidsp-shd go-librespot[20650]: time="2025-02-25T21:42:40+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 25 21:42:40 minidsp-shd go-librespot[20650]: time="2025-02-25T21:42:40+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 25 21:42:40 minidsp-shd go-librespot[20650]: time="2025-02-25T21:42:40+01:00" level=debug msg="zeroconf server listening on port 35587" Feb 25 21:42:41 minidsp-shd go-librespot[20650]: time="2025-02-25T21:42:41+01:00" level=debug msg="obtained new client token: AACGegoRGT6n+vlsdTVo7rnb52CPYnw/SDXqDPzJkH7u4t9+G4mn1yMLSiyDvrznFcua30ZHURX6Wun9LGkbartUb0IpQZXpNmm4vqz1NTcn+NtLnEAI6xeLTgc3auH9tc9tFRh1d+hz8mMcM13OYACDoVgd7DOv+Q4flArKl63981tdz5/d6ew0k6dMCFGYduisoflIgq1PUmZ/ZQgXf6DQWsVrtxTQvdwYwTjRtu1/PCOhXBe7PXz4B2P9LQ==" Feb 25 21:42:41 minidsp-shd go-librespot[20650]: time="2025-02-25T21:42:41+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 25 21:42:41 minidsp-shd go-librespot[20650]: time="2025-02-25T21:42:41+01:00" level=debug msg="completed keyexchange" Feb 25 21:42:41 minidsp-shd go-librespot[20650]: time="2025-02-25T21:42:41+01:00" level=debug msg="completed challenge" Feb 25 21:42:41 minidsp-shd go-librespot[20650]: time="2025-02-25T21:42:41+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 25 21:42:41 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 21:42:41 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 21:42:42 minidsp-shd volumio[19645]: info: Initializing connection to go-librespot Websocket Feb 25 21:42:42 minidsp-shd volumio[19645]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:42:43 minidsp-shd volumio[19645]: Searching all installed plugins Feb 25 21:42:43 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 21:42:43 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: , search Feb 25 21:42:43 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: mpd , search Feb 25 21:42:43 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Feb 25 21:42:43 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Feb 25 21:42:43 minidsp-shd volumio[19645]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Feb 25 21:42:43 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: webradio , search Feb 25 21:42:43 minidsp-shd volumio[19645]: info: CoreCommandRouter::executeOnPlugin: calmradio , search Feb 25 21:42:43 minidsp-shd volumio[19645]: info: [1740516163052] ControllerCalmRadio::searchCategories Feb 25 21:42:43 minidsp-shd volumio[19645]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 25 21:42:43 minidsp-shd volumio[19645]: TypeError: Cannot read property 'cats' of undefined Feb 25 21:42:43 minidsp-shd volumio[19645]: at ControllerCalmRadio.searchCategories (/data/plugins/music_service/calmradio/index.js:615:42) Feb 25 21:42:43 minidsp-shd volumio[19645]: at ControllerCalmRadio.search (/data/plugins/music_service/calmradio/index.js:665:28) Feb 25 21:42:43 minidsp-shd volumio[19645]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1077:32) Feb 25 21:42:43 minidsp-shd volumio[19645]: at CoreMusicLibrary.searchOnPlugin (/volumio/app/musiclibrary.js:668:44) Feb 25 21:42:43 minidsp-shd volumio[19645]: at CoreMusicLibrary.search (/volumio/app/musiclibrary.js:455:27) Feb 25 21:42:43 minidsp-shd volumio[19645]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:457:44) Feb 25 21:42:43 minidsp-shd volumio[19645]: at Socket.emit (events.js:400:28) Feb 25 21:42:43 minidsp-shd volumio[19645]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Feb 25 21:42:43 minidsp-shd volumio[19645]: at processTicksAndRejections (internal/process/task_queues.js:77:11) Feb 25 21:42:43 minidsp-shd volumio[19645]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 25 21:42:44 minidsp-shd sudo[20667]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-02-25 21:41 Feb 25 21:42:44 minidsp-shd sudo[20667]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="17fcb754ddd6bd152b01008c46cc4ba1ca48bf35" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="281cefcd7a302aa7cfba569185cf7aae19b8c376" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="minidspshd" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 22 Mar 2024 03:13:25 PM CET" VOLUMIO_VERSION="3.608" VOLUMIO_HARDWARE="nanopineo3" VOLUMIO_DEVICENAME="Nanopi Neo3" VOLUMIO_VENDOR="miniDSP" VOLUMIO_MODEL="SHD" VOLUMIO_VENDOR_MODEL="miniDSP SHD" VOLUMIO_HASH="18533ba33f8f92d7e7e459bb30f70beb"