-- Logs begin at Thu 2019-02-14 18:11:59 +08, end at Sun 2025-12-28 12:53:53 +08. -- Dec 28 12:52:01 volumiopi volumio[968]: info: Getting Spotify volume Dec 28 12:52:01 volumiopi volumio[968]: (node:968) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 12:52:01 volumiopi volumio[968]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 28 12:52:01 volumiopi volumio[968]: (node:968) 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: 73) Dec 28 12:52:01 volumiopi volumio[968]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Dec 28 12:52:01 volumiopi volumio[968]: info: CoreCommandRouter::volumioGetState Dec 28 12:52:01 volumiopi volumio[968]: info: CorePlayQueue::getTrack 0 Dec 28 12:52:01 volumiopi volumio[968]: info: Initializing connection to go-librespot Websocket Dec 28 12:52:01 volumiopi volumio[968]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 12:52:01 volumiopi systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 12:52:01 volumiopi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 392. Dec 28 12:52:01 volumiopi systemd[1]: Stopped go-librespot Daemon. Dec 28 12:52:01 volumiopi systemd[1]: Started go-librespot Daemon. Dec 28 12:52:01 volumiopi go-librespot[8226]: go-librespot daemon starting... Dec 28 12:52:01 volumiopi go-librespot[8226]: time="2025-12-28T12:52:01+08:00" level=info msg="running go-librespot 0.4.0" Dec 28 12:52:01 volumiopi go-librespot[8226]: time="2025-12-28T12:52:01+08:00" level=debug msg="app state loaded" Dec 28 12:52:01 volumiopi go-librespot[8226]: time="2025-12-28T12:52:01+08:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 28 12:52:02 volumiopi go-librespot[8226]: time="2025-12-28T12:52:01+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 28 12:52:02 volumiopi go-librespot[8226]: time="2025-12-28T12:52:01+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 28 12:52:02 volumiopi go-librespot[8226]: time="2025-12-28T12:52:01+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 28 12:52:02 volumiopi go-librespot[8226]: time="2025-12-28T12:52:02+08:00" level=info msg="zeroconf server listening on port 41477" Dec 28 12:52:02 volumiopi go-librespot[8226]: time="2025-12-28T12:52:02+08:00" level=debug msg="obtained new client token: AADdi9/neOy3U5gMS4k2P53svvbTfds08Iw47Pkb22KQebDk3+riZlrtP7zaxc8GEqxg+AtHLBD2I7d2iJzlaW7zEb0aiW70OpjSN10EITojv7dBUOminiS9LrRD3xHzRtdNCnYFq5YEm3na7sW3CQdrwIz+4ZOhlQgGisbJoVJcBM+jvLxPCEmegnX0bNt7ah6efsAc/PpUi7HyBsrUjpEVf8ATPRW3QChSzydAhM9csto2bklhgSA=" Dec 28 12:52:02 volumiopi go-librespot[8226]: time="2025-12-28T12:52:02+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 28 12:52:02 volumiopi go-librespot[8226]: time="2025-12-28T12:52:02+08:00" level=debug msg="completed keyexchange" Dec 28 12:52:02 volumiopi go-librespot[8226]: time="2025-12-28T12:52:02+08:00" level=debug msg="completed challenge" Dec 28 12:52:02 volumiopi go-librespot[8226]: time="2025-12-28T12:52:02+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 28 12:52:02 volumiopi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 12:52:02 volumiopi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 12:52:04 volumiopi volumio[968]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 28 12:52:04 volumiopi volumio[968]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 28 12:52:04 volumiopi volumio[968]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 28 12:52:04 volumiopi volumio[968]: info: FusionDsp - Fluance SX6 Full Range Dec 28 12:52:04 volumiopi volumio[968]: info: FusionDsp - .json,Fluance SX6 Full Range.json Dec 28 12:52:04 volumiopi volumio[968]: info: Initializing connection to go-librespot Websocket Dec 28 12:52:04 volumiopi volumio[968]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 12:52:05 volumiopi systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 12:52:05 volumiopi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 393. Dec 28 12:52:05 volumiopi systemd[1]: Stopped go-librespot Daemon. Dec 28 12:52:05 volumiopi systemd[1]: Started go-librespot Daemon. Dec 28 12:52:05 volumiopi go-librespot[8237]: go-librespot daemon starting... Dec 28 12:52:05 volumiopi go-librespot[8237]: time="2025-12-28T12:52:05+08:00" level=info msg="running go-librespot 0.4.0" Dec 28 12:52:05 volumiopi go-librespot[8237]: time="2025-12-28T12:52:05+08:00" level=debug msg="app state loaded" Dec 28 12:52:05 volumiopi go-librespot[8237]: time="2025-12-28T12:52:05+08:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 28 12:52:05 volumiopi go-librespot[8237]: time="2025-12-28T12:52:05+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 28 12:52:05 volumiopi go-librespot[8237]: time="2025-12-28T12:52:05+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 28 12:52:05 volumiopi go-librespot[8237]: time="2025-12-28T12:52:05+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 28 12:52:05 volumiopi go-librespot[8237]: time="2025-12-28T12:52:05+08:00" level=info msg="zeroconf server listening on port 36111" Dec 28 12:52:05 volumiopi go-librespot[8237]: time="2025-12-28T12:52:05+08:00" level=debug msg="obtained new client token: AACtWLTi+BL6CGjBA3RVIfIy8hp6gvjOPNmTo19oqi03LEo30eoeMvJ/nZab7x9auLk3Ux8Mf5r7ZtzqMcL86uI+Fg9R/Ahmhdrccrt/60A2tohC+MTCyhtakxQpqIjGK+zM0DW2LvNTmFNae01OEnak/VxxoZhGzt/JKBig4aV2IaMyHEoDqL7An5t5sKubpidiOmhy5mdM/ih2LinaxmT5RmLevHAkmSsjv3JD3W+rcdCH8bW/QGWYqg==" Dec 28 12:52:06 volumiopi go-librespot[8237]: time="2025-12-28T12:52:06+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 28 12:52:07 volumiopi go-librespot[8237]: time="2025-12-28T12:52:07+08:00" level=debug msg="completed keyexchange" Dec 28 12:52:07 volumiopi go-librespot[8237]: time="2025-12-28T12:52:07+08:00" level=debug msg="completed challenge" Dec 28 12:52:07 volumiopi go-librespot[8237]: time="2025-12-28T12:52:07+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 28 12:52:07 volumiopi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 12:52:07 volumiopi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 12:52:07 volumiopi volumio[968]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 28 12:52:07 volumiopi volumio[968]: info: FusionDsp - Fluance SX6 Full Range Dec 28 12:52:07 volumiopi volumio[968]: info: FusionDsp - .json,Fluance SX6 Full Range.json Dec 28 12:52:07 volumiopi volumio[968]: info: Initializing connection to go-librespot Websocket Dec 28 12:52:07 volumiopi volumio[968]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 12:52:08 volumiopi volumio[968]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 28 12:52:08 volumiopi volumio[968]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Dec 28 12:52:08 volumiopi volumio[968]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Dec 28 12:52:08 volumiopi volumio[968]: info: Received Get System Version Dec 28 12:52:08 volumiopi volumio[968]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 28 12:52:08 volumiopi volumio[968]: info: Received Get System Info Dec 28 12:52:08 volumiopi volumio[968]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 28 12:52:08 volumiopi volumio[968]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 28 12:52:08 volumiopi volumio[968]: info: Discovery: Getting this device information Dec 28 12:52:08 volumiopi volumio[968]: info: CoreCommandRouter::volumioGetState Dec 28 12:52:08 volumiopi volumio[968]: info: CorePlayQueue::getTrack 0 Dec 28 12:52:08 volumiopi volumio[968]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 28 12:52:10 volumiopi systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 12:52:10 volumiopi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 394. Dec 28 12:52:10 volumiopi systemd[1]: Stopped go-librespot Daemon. Dec 28 12:52:10 volumiopi systemd[1]: Started go-librespot Daemon. Dec 28 12:52:10 volumiopi go-librespot[8246]: go-librespot daemon starting... Dec 28 12:52:10 volumiopi go-librespot[8246]: time="2025-12-28T12:52:10+08:00" level=info msg="running go-librespot 0.4.0" Dec 28 12:52:10 volumiopi go-librespot[8246]: time="2025-12-28T12:52:10+08:00" level=debug msg="app state loaded" Dec 28 12:52:10 volumiopi go-librespot[8246]: time="2025-12-28T12:52:10+08:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 28 12:52:10 volumiopi go-librespot[8246]: time="2025-12-28T12:52:10+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 28 12:52:10 volumiopi go-librespot[8246]: time="2025-12-28T12:52:10+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 28 12:52:10 volumiopi go-librespot[8246]: time="2025-12-28T12:52:10+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 28 12:52:10 volumiopi go-librespot[8246]: time="2025-12-28T12:52:10+08:00" level=info msg="zeroconf server listening on port 38993" Dec 28 12:52:10 volumiopi volumio[968]: info: Initializing connection to go-librespot Websocket Dec 28 12:52:10 volumiopi go-librespot[8246]: time="2025-12-28T12:52:10+08:00" level=debug msg="new websocket client" Dec 28 12:52:10 volumiopi volumio[968]: info: Connection to go-librespot Websocket established Dec 28 12:52:10 volumiopi go-librespot[8246]: time="2025-12-28T12:52:10+08:00" level=debug msg="obtained new client token: AAAGLbkyYSyVFteM//WnBEDVb/n5hEljiK6maPF0Ay2w+84ASjZLNs4rYGAQ8w73ofr1b8H3a9406i/6knHjl7KgtKX07INbvAprfMYM4YwyHDxMzfqboINjoe5GIB/zxMo9Ft3QGE81j4u5Vd9i1nMK8jVgBjSjrpZqdVmDsEuMGGUADZLX75s8bLyJPMlPEveiN2N4UhjFh4HYNFmJTX3oDUT5xmUaZQ7XqNnp085nuRmWr+8E1n1TnQ==" Dec 28 12:52:10 volumiopi go-librespot[8246]: time="2025-12-28T12:52:10+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 28 12:52:10 volumiopi go-librespot[8246]: time="2025-12-28T12:52:10+08:00" level=debug msg="completed keyexchange" Dec 28 12:52:10 volumiopi go-librespot[8246]: time="2025-12-28T12:52:10+08:00" level=debug msg="completed challenge" Dec 28 12:52:10 volumiopi go-librespot[8246]: time="2025-12-28T12:52:10+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 28 12:52:10 volumiopi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 12:52:10 volumiopi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 12:52:10 volumiopi volumio[968]: info: Connection to go-librespot Websocket closed Dec 28 12:52:13 volumiopi volumio[968]: info: Getting Spotify volume Dec 28 12:52:13 volumiopi volumio[968]: (node:968) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 12:52:13 volumiopi volumio[968]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 28 12:52:13 volumiopi volumio[968]: (node:968) 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: 74) Dec 28 12:52:13 volumiopi volumio[968]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Dec 28 12:52:13 volumiopi volumio[968]: info: CoreCommandRouter::volumioGetState Dec 28 12:52:13 volumiopi volumio[968]: info: CorePlayQueue::getTrack 0 Dec 28 12:52:13 volumiopi volumio[968]: info: Initializing connection to go-librespot Websocket Dec 28 12:52:13 volumiopi volumio[968]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 12:52:13 volumiopi systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 12:52:13 volumiopi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 395. Dec 28 12:52:13 volumiopi systemd[1]: Stopped go-librespot Daemon. Dec 28 12:52:13 volumiopi systemd[1]: Started go-librespot Daemon. Dec 28 12:52:13 volumiopi go-librespot[8269]: go-librespot daemon starting... Dec 28 12:52:14 volumiopi go-librespot[8269]: time="2025-12-28T12:52:14+08:00" level=info msg="running go-librespot 0.4.0" Dec 28 12:52:14 volumiopi go-librespot[8269]: time="2025-12-28T12:52:14+08:00" level=debug msg="app state loaded" Dec 28 12:52:14 volumiopi go-librespot[8269]: time="2025-12-28T12:52:14+08:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 28 12:52:14 volumiopi go-librespot[8269]: time="2025-12-28T12:52:14+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 28 12:52:14 volumiopi go-librespot[8269]: time="2025-12-28T12:52:14+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 28 12:52:14 volumiopi go-librespot[8269]: time="2025-12-28T12:52:14+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 28 12:52:14 volumiopi go-librespot[8269]: time="2025-12-28T12:52:14+08:00" level=info msg="zeroconf server listening on port 46733" Dec 28 12:52:14 volumiopi go-librespot[8269]: time="2025-12-28T12:52:14+08:00" level=debug msg="obtained new client token: AABHxITvXU+8JfBxg45Ir1/2SRP0BmkQ0JKtpSpY6i/l7/luBS+SJtldVUN1a1zHIH4hviuvVVSOHGMlU++RgJPQcMplURBp6QdwUUjM2sJJab1W0uHthAZu06KS8b+J8cCO0eXeba7EQg0hWLUD0rBZXlOCgVWcSwTdpu+hDj9YllPr8322brnPhdq3R/ZSMGsxpn7y2xZnqnIPdiu7T9I9wq+N/qstLjm76yrrFMBuI6vK5WdLbdeqqw==" Dec 28 12:52:14 volumiopi go-librespot[8269]: time="2025-12-28T12:52:14+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 28 12:52:14 volumiopi go-librespot[8269]: time="2025-12-28T12:52:14+08:00" level=debug msg="completed keyexchange" Dec 28 12:52:14 volumiopi go-librespot[8269]: time="2025-12-28T12:52:14+08:00" level=debug msg="completed challenge" Dec 28 12:52:14 volumiopi go-librespot[8269]: time="2025-12-28T12:52:14+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 28 12:52:14 volumiopi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 12:52:14 volumiopi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 12:52:16 volumiopi volumio[968]: info: Initializing connection to go-librespot Websocket Dec 28 12:52:16 volumiopi volumio[968]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 12:52:17 volumiopi systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 12:52:17 volumiopi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 396. Dec 28 12:52:17 volumiopi systemd[1]: Stopped go-librespot Daemon. Dec 28 12:52:17 volumiopi systemd[1]: Started go-librespot Daemon. Dec 28 12:52:17 volumiopi go-librespot[8277]: go-librespot daemon starting... Dec 28 12:52:18 volumiopi go-librespot[8277]: time="2025-12-28T12:52:18+08:00" level=info msg="running go-librespot 0.4.0" Dec 28 12:52:18 volumiopi go-librespot[8277]: time="2025-12-28T12:52:18+08:00" level=debug msg="app state loaded" Dec 28 12:52:18 volumiopi go-librespot[8277]: time="2025-12-28T12:52:18+08:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 28 12:52:18 volumiopi go-librespot[8277]: time="2025-12-28T12:52:18+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 28 12:52:18 volumiopi go-librespot[8277]: time="2025-12-28T12:52:18+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 28 12:52:18 volumiopi go-librespot[8277]: time="2025-12-28T12:52:18+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 28 12:52:18 volumiopi go-librespot[8277]: time="2025-12-28T12:52:18+08:00" level=info msg="zeroconf server listening on port 38503" Dec 28 12:52:18 volumiopi volumio[968]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 28 12:52:18 volumiopi volumio[968]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 28 12:52:18 volumiopi go-librespot[8277]: time="2025-12-28T12:52:18+08:00" level=debug msg="obtained new client token: AACvrVLUJRayfyi6BvKHPyZ6Si2XqIneUM9CX30hdRxJKg+EZut1A11Mu/4jrObSUkozFanaDXjUPdpmz6zIaY7KcNwJa7e/c03WBmAev6DaenYkCBpU7cztxF8ZCnxsYTnyvoMQdzs3L6nUWZeW1vBo1qhMT1RAODcqeoc+ZLKNpC1UMP3/hmgVY6K3reebk6bCLg+AqP73T555CsZysj0Ct3mOab0KOxwzc3n7p0jCPKQJSUBZ/wYk0g==" Dec 28 12:52:18 volumiopi go-librespot[8277]: time="2025-12-28T12:52:18+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 28 12:52:18 volumiopi go-librespot[8277]: time="2025-12-28T12:52:18+08:00" level=debug msg="completed keyexchange" Dec 28 12:52:18 volumiopi go-librespot[8277]: time="2025-12-28T12:52:18+08:00" level=debug msg="completed challenge" Dec 28 12:52:18 volumiopi go-librespot[8277]: time="2025-12-28T12:52:18+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 28 12:52:18 volumiopi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 12:52:18 volumiopi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 12:52:19 volumiopi volumio[968]: info: Initializing connection to go-librespot Websocket Dec 28 12:52:19 volumiopi volumio[968]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 12:52:21 volumiopi systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 12:52:21 volumiopi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 397. Dec 28 12:52:21 volumiopi systemd[1]: Stopped go-librespot Daemon. Dec 28 12:52:21 volumiopi systemd[1]: Started go-librespot Daemon. Dec 28 12:52:21 volumiopi go-librespot[8299]: go-librespot daemon starting... Dec 28 12:52:21 volumiopi go-librespot[8299]: time="2025-12-28T12:52:21+08:00" level=info msg="running go-librespot 0.4.0" Dec 28 12:52:21 volumiopi go-librespot[8299]: time="2025-12-28T12:52:21+08:00" level=debug msg="app state loaded" Dec 28 12:52:21 volumiopi go-librespot[8299]: time="2025-12-28T12:52:21+08:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 28 12:52:22 volumiopi go-librespot[8299]: time="2025-12-28T12:52:22+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 28 12:52:22 volumiopi go-librespot[8299]: time="2025-12-28T12:52:22+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 28 12:52:22 volumiopi go-librespot[8299]: time="2025-12-28T12:52:22+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 28 12:52:22 volumiopi go-librespot[8299]: time="2025-12-28T12:52:22+08:00" level=info msg="zeroconf server listening on port 40553" Dec 28 12:52:22 volumiopi volumio[968]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/fusiondsp/volumio/buster/armhf Dec 28 12:52:22 volumiopi go-librespot[8299]: time="2025-12-28T12:52:22+08:00" level=debug msg="obtained new client token: AAAYwkFCXch96ZXWii26NoDLWWByRfULDcGU76jRA/RCDV9oxc19aWgG04HxCpd/fghJUKgIcX2km10rpi6wUliNPvs7bxeaEEeXOevExTpbgogl2d3ZyhVYGV7CsouZnd7w8IxanUDNfjuORw7S9Hj1cSbIE/Zpcx8avr+DVEMjeOff71dqweQ+Zy9U+2GCzffeiDxbLj1vOnTTj0MbIx5A2SMoQ3VTr0Hoqi++3ZfPeRjwBsy4ZlY=" Dec 28 12:52:22 volumiopi go-librespot[8299]: time="2025-12-28T12:52:22+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 28 12:52:22 volumiopi go-librespot[8299]: time="2025-12-28T12:52:22+08:00" level=debug msg="completed keyexchange" Dec 28 12:52:22 volumiopi go-librespot[8299]: time="2025-12-28T12:52:22+08:00" level=debug msg="completed challenge" Dec 28 12:52:22 volumiopi go-librespot[8299]: time="2025-12-28T12:52:22+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 28 12:52:22 volumiopi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 12:52:22 volumiopi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 12:52:22 volumiopi volumio[968]: info: Initializing connection to go-librespot Websocket Dec 28 12:52:22 volumiopi volumio[968]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 12:52:25 volumiopi systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 12:52:25 volumiopi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 398. Dec 28 12:52:25 volumiopi systemd[1]: Stopped go-librespot Daemon. Dec 28 12:52:25 volumiopi systemd[1]: Started go-librespot Daemon. Dec 28 12:52:25 volumiopi go-librespot[8312]: go-librespot daemon starting... Dec 28 12:52:25 volumiopi go-librespot[8312]: time="2025-12-28T12:52:25+08:00" level=info msg="running go-librespot 0.4.0" Dec 28 12:52:25 volumiopi go-librespot[8312]: time="2025-12-28T12:52:25+08:00" level=debug msg="app state loaded" Dec 28 12:52:25 volumiopi go-librespot[8312]: time="2025-12-28T12:52:25+08:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 28 12:52:25 volumiopi volumio[968]: info: Initializing connection to go-librespot Websocket Dec 28 12:52:25 volumiopi go-librespot[8312]: time="2025-12-28T12:52:25+08:00" level=debug msg="new websocket client" Dec 28 12:52:25 volumiopi volumio[968]: info: Connection to go-librespot Websocket established Dec 28 12:52:25 volumiopi go-librespot[8312]: time="2025-12-28T12:52:25+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 28 12:52:25 volumiopi go-librespot[8312]: time="2025-12-28T12:52:25+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 28 12:52:25 volumiopi go-librespot[8312]: time="2025-12-28T12:52:25+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 28 12:52:25 volumiopi go-librespot[8312]: time="2025-12-28T12:52:25+08:00" level=info msg="zeroconf server listening on port 43163" Dec 28 12:52:26 volumiopi volumio[968]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/fusiondsp/volumio/buster/armhf Dec 28 12:52:26 volumiopi volumio[968]: info: FusionDsp - Stopping FusionDsp service Dec 28 12:52:26 volumiopi volumio[968]: info: camilladsp stopping service pid 1661... Dec 28 12:52:26 volumiopi volumio[968]: info: camilladsp service terminated, instance 1 Dec 28 12:52:26 volumiopi sudo[8324]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop fusiondsp.service Dec 28 12:52:26 volumiopi sudo[8324]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 12:52:26 volumiopi go-librespot[8312]: time="2025-12-28T12:52:26+08:00" level=debug msg="obtained new client token: AAB0tUTtkefJY0N3gll0bWtgXADxplecBh3gWvvaPO9oe9FVYcCfntDz3iMPGxkOBdQIc4TCt/chC4jP3WMXESMURJlMpTtI2QgqjOILcRoC8LTaXD0ihDpNOM5M6ueO3x9NIJ3mMLutaGCrp4d0hCeBAOSAR4iQtyGYe09JZdspkBhAQ5F6ozXHy7Pjo1v1f6IvRO6ZlVj7H5SC3F1BzuScRiNRRflLJQ/Ow1TLYJKXl+FLCNY1x1I=" Dec 28 12:52:26 volumiopi systemd[1]: Stopping FusionDsp Daemon... Dec 28 12:52:26 volumiopi volumio[1316]: Backend configuration: Dec 28 12:52:26 volumiopi volumio[1316]: active_config: /data/configuration/audio_interface/fusiondsp/camilladsp.yml Dec 28 12:52:26 volumiopi volumio[1316]: active_config_txt: null Dec 28 12:52:26 volumiopi volumio[1316]: camilla_host: 127.0.0.1 Dec 28 12:52:26 volumiopi volumio[1316]: camilla_port: 9876 Dec 28 12:52:26 volumiopi volumio[1316]: coeff_dir: /data/INTERNAL/FusionDsp/filters Dec 28 12:52:26 volumiopi volumio[1316]: config_dir: /data/configuration/audio_interface/fusiondsp Dec 28 12:52:26 volumiopi volumio[1316]: default_config: /data/configuration/audio_interface/fusiondsp/camilladsp.yml Dec 28 12:52:26 volumiopi volumio[1316]: log_file: /tmp/camilladsp.log Dec 28 12:52:26 volumiopi volumio[1316]: on_get_active_config: null Dec 28 12:52:26 volumiopi volumio[1316]: on_set_active_config: null Dec 28 12:52:26 volumiopi volumio[1316]: port: 5011 Dec 28 12:52:26 volumiopi volumio[1316]: supported_capture_types: null Dec 28 12:52:26 volumiopi volumio[1316]: supported_playback_types: null Dec 28 12:52:26 volumiopi volumio[1316]: update_config_symlink: false Dec 28 12:52:26 volumiopi volumio[1316]: update_config_txt: false Dec 28 12:52:26 volumiopi volumio[1316]: ======== Running on http://0.0.0.0:5011 ======== Dec 28 12:52:26 volumiopi volumio[1316]: (Press CTRL+C to quit) Dec 28 12:52:26 volumiopi go-librespot[8312]: time="2025-12-28T12:52:26+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 28 12:52:26 volumiopi go-librespot[8312]: time="2025-12-28T12:52:26+08:00" level=debug msg="completed keyexchange" Dec 28 12:52:26 volumiopi go-librespot[8312]: time="2025-12-28T12:52:26+08:00" level=debug msg="completed challenge" Dec 28 12:52:26 volumiopi systemd[1]: fusiondsp.service: Succeeded. Dec 28 12:52:26 volumiopi systemd[1]: Stopped FusionDsp Daemon. Dec 28 12:52:26 volumiopi sudo[8324]: pam_unix(sudo:session): session closed for user root Dec 28 12:52:26 volumiopi volumio[968]: info: FusionDsp - Reporting Fusion DSP Disabled Dec 28 12:52:26 volumiopi volumio[968]: info: Removing fusiondspeq DSP Signal Path Element Dec 28 12:52:26 volumiopi go-librespot[8312]: time="2025-12-28T12:52:26+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 28 12:52:26 volumiopi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 12:52:26 volumiopi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 12:52:26 volumiopi volumio[968]: info: Connection to go-librespot Websocket closed Dec 28 12:52:26 volumiopi volumio[968]: info: Check plugin dependencies Dec 28 12:52:26 volumiopi volumio[968]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 28 12:52:26 volumiopi volumio[968]: info: Rename folder Dec 28 12:52:26 volumiopi volumio[968]: info: Folder /tmp/downloaded_plugin.zip removed Dec 28 12:52:26 volumiopi volumio[968]: info: Move to category Dec 28 12:52:29 volumiopi volumio[968]: info: Checking if install.sh is present Dec 28 12:52:29 volumiopi volumio[968]: info: Getting Spotify volume Dec 28 12:52:29 volumiopi volumio[968]: info: Executing install.sh Dec 28 12:52:29 volumiopi volumio[968]: (node:968) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 12:52:29 volumiopi volumio[968]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 28 12:52:29 volumiopi volumio[968]: (node:968) 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: 75) Dec 28 12:52:29 volumiopi volumio[968]: info: Initializing connection to go-librespot Websocket Dec 28 12:52:29 volumiopi systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 12:52:29 volumiopi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 399. Dec 28 12:52:29 volumiopi systemd[1]: Stopped go-librespot Daemon. Dec 28 12:52:29 volumiopi volumio[968]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Dec 28 12:52:29 volumiopi volumio[968]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 12:52:29 volumiopi volumio[968]: info: CoreCommandRouter::volumioGetState Dec 28 12:52:29 volumiopi volumio[968]: info: CorePlayQueue::getTrack 0 Dec 28 12:52:29 volumiopi systemd[1]: Started go-librespot Daemon. Dec 28 12:52:29 volumiopi go-librespot[8339]: go-librespot daemon starting... Dec 28 12:52:29 volumiopi go-librespot[8339]: time="2025-12-28T12:52:29+08:00" level=info msg="running go-librespot 0.4.0" Dec 28 12:52:29 volumiopi go-librespot[8339]: time="2025-12-28T12:52:29+08:00" level=debug msg="app state loaded" Dec 28 12:52:29 volumiopi go-librespot[8339]: time="2025-12-28T12:52:29+08:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 28 12:52:29 volumiopi sudo[8338]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/audio_interface/fusiondsp/install.sh Dec 28 12:52:29 volumiopi sudo[8338]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 12:52:29 volumiopi volumio[968]: info: creating filters folder and copying demo filters Dec 28 12:52:29 volumiopi volumio[968]: info: copying demo flters Dec 28 12:52:29 volumiopi volumio[968]: info: ./presets/ Dec 28 12:52:29 volumiopi volumio[968]: info: ./presets/2XEQ15/ Dec 28 12:52:29 volumiopi volumio[968]: info: ./presets/2XEQ15/.Bass-FusionDsp.json Dec 28 12:52:29 volumiopi volumio[968]: info: ./presets/2XEQ15/.Soundtrack-FusionDsp.json Dec 28 12:52:29 volumiopi volumio[968]: info: ./presets/2XEQ15/.Classic-FusionDsp.json Dec 28 12:52:29 volumiopi sudo[8371]: root : TTY=unknown ; PWD=/data/plugins/audio_interface/fusiondsp ; USER=root ; COMMAND=/usr/bin/apt update Dec 28 12:52:29 volumiopi sudo[8371]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 12:52:29 volumiopi volumio[968]: info: ./presets/2XEQ15/.Voice-FusionDsp.json Dec 28 12:52:29 volumiopi go-librespot[8339]: time="2025-12-28T12:52:29+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 28 12:52:29 volumiopi go-librespot[8339]: time="2025-12-28T12:52:29+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 28 12:52:29 volumiopi go-librespot[8339]: time="2025-12-28T12:52:29+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 28 12:52:29 volumiopi volumio[968]: info: ./presets/2XEQ15/.Rock-FusionDsp.json Dec 28 12:52:29 volumiopi go-librespot[8339]: time="2025-12-28T12:52:29+08:00" level=info msg="zeroconf server listening on port 32781" Dec 28 12:52:29 volumiopi volumio[968]: info: ./presets/PEQ/ Dec 28 12:52:29 volumiopi volumio[968]: info: ./presets/convfir/ Dec 28 12:52:29 volumiopi volumio[968]: info: ./presets/convfir/kef.json Dec 28 12:52:29 volumiopi volumio[968]: info: ./presets/convfir/test.json Dec 28 12:52:29 volumiopi volumio[968]: info: ./presets/EQ15/ Dec 28 12:52:29 volumiopi volumio[968]: info: ./presets/EQ15/.Bass-FusionDsp.json Dec 28 12:52:29 volumiopi volumio[968]: info: ./presets/EQ15/.Soundtrack-FusionDsp.json Dec 28 12:52:29 volumiopi volumio[968]: info: ./presets/EQ15/.Classic-FusionDsp.json Dec 28 12:52:29 volumiopi volumio[968]: info: ./presets/EQ15/.Voice-FusionDsp.json Dec 28 12:52:29 volumiopi volumio[968]: info: ./presets/EQ15/.Rock-FusionDsp.json Dec 28 12:52:29 volumiopi volumio[968]: info: Installing/fusiondsp dependencies Dec 28 12:52:29 volumiopi go-librespot[8339]: time="2025-12-28T12:52:29+08:00" level=debug msg="obtained new client token: AABYiDeCe+isksW1v8qih6nNNYde9tlAKHE1HqWTctAcqPPA/Qwdfzy1ByG5J++NUrHB4lFMPk5kmmtLKafnypPdk2I8bOsexavc/a3oEO89mYSkiE78C7z3lw/8gJkUKA5IssBZk/ubhl9GEpybptCJo/cVhzrgPlrw4KXur6eIaHncu4OkGJvo+lkNExwi23RubJ9BdAhHgW5o92d+tVnPpzPJDYv09p5+k6F6OPG5e9yUO7qHWq0Otw==" Dec 28 12:52:30 volumiopi go-librespot[8339]: time="2025-12-28T12:52:30+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 28 12:52:30 volumiopi go-librespot[8339]: time="2025-12-28T12:52:30+08:00" level=debug msg="completed keyexchange" Dec 28 12:52:30 volumiopi go-librespot[8339]: time="2025-12-28T12:52:30+08:00" level=debug msg="completed challenge" Dec 28 12:52:30 volumiopi go-librespot[8339]: time="2025-12-28T12:52:30+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 28 12:52:30 volumiopi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 12:52:30 volumiopi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 12:52:30 volumiopi volumio[968]: info: Hit:1 https://deb.nodesource.com/node_14.x buster InRelease Dec 28 12:52:32 volumiopi volumio[968]: info: Get:2 https://apt2.volumio.org/raspbian buster InRelease [15.0 kB] Dec 28 12:52:32 volumiopi volumio[968]: info: Get:3 https://archive2.volumio.org/debian buster InRelease [54.2 kB] Dec 28 12:52:32 volumiopi volumio[968]: info: Initializing connection to go-librespot Websocket Dec 28 12:52:32 volumiopi volumio[968]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 12:52:32 volumiopi volumio[968]: info: Get:4 https://apt2.volumio.org/raspbian buster/main armhf Packages [13.0 MB] Dec 28 12:52:33 volumiopi volumio[968]: info: Get:5 https://archive2.volumio.org/debian buster/main armhf Packages [400 kB] Dec 28 12:52:33 volumiopi systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 12:52:33 volumiopi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 400. Dec 28 12:52:33 volumiopi systemd[1]: Stopped go-librespot Daemon. Dec 28 12:52:33 volumiopi systemd[1]: Started go-librespot Daemon. Dec 28 12:52:33 volumiopi go-librespot[8625]: go-librespot daemon starting... Dec 28 12:52:33 volumiopi go-librespot[8625]: time="2025-12-28T12:52:33+08:00" level=info msg="running go-librespot 0.4.0" Dec 28 12:52:33 volumiopi go-librespot[8625]: time="2025-12-28T12:52:33+08:00" level=debug msg="app state loaded" Dec 28 12:52:33 volumiopi go-librespot[8625]: time="2025-12-28T12:52:33+08:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 28 12:52:33 volumiopi go-librespot[8625]: time="2025-12-28T12:52:33+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 28 12:52:33 volumiopi go-librespot[8625]: time="2025-12-28T12:52:33+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 28 12:52:33 volumiopi go-librespot[8625]: time="2025-12-28T12:52:33+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 28 12:52:33 volumiopi go-librespot[8625]: time="2025-12-28T12:52:33+08:00" level=info msg="zeroconf server listening on port 46599" Dec 28 12:52:33 volumiopi go-librespot[8625]: time="2025-12-28T12:52:33+08:00" level=debug msg="obtained new client token: AAB+ugmsjQzx8blUsLDdi6Jjwrrg9GzVqgAUgF7sfgOnMjLixWdQIS3zwRX3zcL7JeOB+j+nhJGMqGdrasYvTVWcaVrmQEjuwVVMiuVwhidOvkonu5NFv60r439INyxvOeKcTpwndibcIz1BhJbfJGaTIXHLmWLdFDI4T+lCtSh2k0lsFQjypHL6G99xHKB3MVfeupkczbGAYzlbEcxLD8zFNUdDlFvfKt5XFAmrBptdiRHsfI9xcSVAqA==" Dec 28 12:52:33 volumiopi go-librespot[8625]: time="2025-12-28T12:52:33+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 28 12:52:34 volumiopi go-librespot[8625]: time="2025-12-28T12:52:34+08:00" level=debug msg="completed keyexchange" Dec 28 12:52:34 volumiopi go-librespot[8625]: time="2025-12-28T12:52:34+08:00" level=debug msg="completed challenge" Dec 28 12:52:34 volumiopi go-librespot[8625]: time="2025-12-28T12:52:34+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 28 12:52:34 volumiopi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 12:52:34 volumiopi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 12:52:35 volumiopi volumio[968]: info: Initializing connection to go-librespot Websocket Dec 28 12:52:35 volumiopi volumio[968]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 12:52:37 volumiopi systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 12:52:37 volumiopi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 401. Dec 28 12:52:37 volumiopi systemd[1]: Stopped go-librespot Daemon. Dec 28 12:52:37 volumiopi systemd[1]: Started go-librespot Daemon. Dec 28 12:52:37 volumiopi go-librespot[8635]: go-librespot daemon starting... Dec 28 12:52:37 volumiopi go-librespot[8635]: time="2025-12-28T12:52:37+08:00" level=info msg="running go-librespot 0.4.0" Dec 28 12:52:37 volumiopi go-librespot[8635]: time="2025-12-28T12:52:37+08:00" level=debug msg="app state loaded" Dec 28 12:52:37 volumiopi go-librespot[8635]: time="2025-12-28T12:52:37+08:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 28 12:52:37 volumiopi go-librespot[8635]: time="2025-12-28T12:52:37+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 28 12:52:37 volumiopi go-librespot[8635]: time="2025-12-28T12:52:37+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 28 12:52:37 volumiopi go-librespot[8635]: time="2025-12-28T12:52:37+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 28 12:52:37 volumiopi go-librespot[8635]: time="2025-12-28T12:52:37+08:00" level=info msg="zeroconf server listening on port 39703" Dec 28 12:52:38 volumiopi go-librespot[8635]: time="2025-12-28T12:52:38+08:00" level=debug msg="obtained new client token: AACme61JoQlkra/nxpzCXMp4AwajRUrnsXg9EZtuCKxUe7/xuxihJy4kEHGWehgVUVoL75dACzaGZK4fzx63azQwMTK//+IBv/kjXXEBQa2yQev6LLsHOburnWZjZAAtx1VHugEEfsMrxlFQh99OzFBrsMZ9yW9LSpvRUWTDLHwwlPXIU6Jk/qChLIIfvv3fEyAivUWrP0kLQNXzLNxM1lIv8anb9xrBEHBO7Rd3s8gcZjVA3ZRzjpL6mQ==" Dec 28 12:52:38 volumiopi go-librespot[8635]: time="2025-12-28T12:52:38+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 28 12:52:38 volumiopi go-librespot[8635]: time="2025-12-28T12:52:38+08:00" level=debug msg="completed keyexchange" Dec 28 12:52:38 volumiopi go-librespot[8635]: time="2025-12-28T12:52:38+08:00" level=debug msg="completed challenge" Dec 28 12:52:38 volumiopi volumio[968]: info: Initializing connection to go-librespot Websocket Dec 28 12:52:38 volumiopi go-librespot[8635]: time="2025-12-28T12:52:38+08:00" level=debug msg="new websocket client" Dec 28 12:52:38 volumiopi volumio[968]: info: Connection to go-librespot Websocket established Dec 28 12:52:38 volumiopi go-librespot[8635]: time="2025-12-28T12:52:38+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 28 12:52:38 volumiopi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 12:52:38 volumiopi volumio[968]: info: Connection to go-librespot Websocket closed Dec 28 12:52:38 volumiopi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 12:52:38 volumiopi volumio[968]: info: Get:6 https://apt2.volumio.org/raspbian buster/contrib armhf Packages [58.8 kB] Dec 28 12:52:38 volumiopi volumio[968]: info: Get:7 https://apt2.volumio.org/raspbian buster/non-free armhf Packages [110 kB] Dec 28 12:52:38 volumiopi volumio[968]: info: Get:8 https://apt2.volumio.org/raspbian buster/rpi armhf Packages [1360 B] Dec 28 12:52:41 volumiopi volumio[968]: info: Getting Spotify volume Dec 28 12:52:41 volumiopi volumio[968]: (node:968) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 12:52:41 volumiopi volumio[968]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 28 12:52:41 volumiopi volumio[968]: (node:968) 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: 76) Dec 28 12:52:41 volumiopi volumio[968]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Dec 28 12:52:41 volumiopi volumio[968]: info: CoreCommandRouter::volumioGetState Dec 28 12:52:41 volumiopi volumio[968]: info: CorePlayQueue::getTrack 0 Dec 28 12:52:41 volumiopi volumio[968]: info: Initializing connection to go-librespot Websocket Dec 28 12:52:41 volumiopi volumio[968]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 12:52:41 volumiopi systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 12:52:41 volumiopi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 402. Dec 28 12:52:41 volumiopi systemd[1]: Stopped go-librespot Daemon. Dec 28 12:52:41 volumiopi systemd[1]: Started go-librespot Daemon. Dec 28 12:52:41 volumiopi go-librespot[8658]: go-librespot daemon starting... Dec 28 12:52:41 volumiopi go-librespot[8658]: time="2025-12-28T12:52:41+08:00" level=info msg="running go-librespot 0.4.0" Dec 28 12:52:41 volumiopi go-librespot[8658]: time="2025-12-28T12:52:41+08:00" level=debug msg="app state loaded" Dec 28 12:52:41 volumiopi go-librespot[8658]: time="2025-12-28T12:52:41+08:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 28 12:52:42 volumiopi go-librespot[8658]: time="2025-12-28T12:52:42+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 28 12:52:42 volumiopi go-librespot[8658]: time="2025-12-28T12:52:42+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 28 12:52:42 volumiopi go-librespot[8658]: time="2025-12-28T12:52:42+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 28 12:52:42 volumiopi go-librespot[8658]: time="2025-12-28T12:52:42+08:00" level=info msg="zeroconf server listening on port 40203" Dec 28 12:52:42 volumiopi go-librespot[8658]: time="2025-12-28T12:52:42+08:00" level=debug msg="obtained new client token: AAA4rKcA454TRKcQp6UrqogTg780IaPvQI8eL/GM5SC6qKUZSI15++NgUk1QTmsVHa67duuHnZHRYN6bILELgu9in8q+6RCN0K/hY0QqEMN0QMkdaoht5iVbDmKFw3D3WmH11PEiG5rutyb2kKQGU00fcQK94+IJnxOj0HizIlJQ6lKGw45nYPlIAVTqEWNw3eXkMZ/1ZUojeQ28ldFzWcENAcAM5VMoBgp1kWHAAVkfEpfFucmz+Gk=" Dec 28 12:52:42 volumiopi go-librespot[8658]: time="2025-12-28T12:52:42+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 28 12:52:42 volumiopi go-librespot[8658]: time="2025-12-28T12:52:42+08:00" level=debug msg="completed keyexchange" Dec 28 12:52:42 volumiopi go-librespot[8658]: time="2025-12-28T12:52:42+08:00" level=debug msg="completed challenge" Dec 28 12:52:42 volumiopi go-librespot[8658]: time="2025-12-28T12:52:42+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 28 12:52:42 volumiopi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 12:52:42 volumiopi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 12:52:44 volumiopi volumio[968]: info: Initializing connection to go-librespot Websocket Dec 28 12:52:44 volumiopi volumio[968]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 12:52:45 volumiopi systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 12:52:45 volumiopi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 403. Dec 28 12:52:45 volumiopi systemd[1]: Stopped go-librespot Daemon. Dec 28 12:52:45 volumiopi systemd[1]: Started go-librespot Daemon. Dec 28 12:52:45 volumiopi go-librespot[8669]: go-librespot daemon starting... Dec 28 12:52:45 volumiopi go-librespot[8669]: time="2025-12-28T12:52:45+08:00" level=info msg="running go-librespot 0.4.0" Dec 28 12:52:45 volumiopi go-librespot[8669]: time="2025-12-28T12:52:45+08:00" level=debug msg="app state loaded" Dec 28 12:52:45 volumiopi go-librespot[8669]: time="2025-12-28T12:52:45+08:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 28 12:52:45 volumiopi go-librespot[8669]: time="2025-12-28T12:52:45+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 28 12:52:45 volumiopi go-librespot[8669]: time="2025-12-28T12:52:45+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 28 12:52:45 volumiopi go-librespot[8669]: time="2025-12-28T12:52:45+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 28 12:52:45 volumiopi go-librespot[8669]: time="2025-12-28T12:52:45+08:00" level=info msg="zeroconf server listening on port 40323" Dec 28 12:52:45 volumiopi go-librespot[8669]: time="2025-12-28T12:52:45+08:00" level=debug msg="obtained new client token: AAD0vzCDzdEEypgEbVHEmBunp4qIvVI9a95FpyFUERplERX0nO9isOzmLao404P90UfXed6kUQe+4sJbVshWI/14UJPjJSnohLDLzSClZ3hLyzge6uhnvQBme1oraAnVpSgW8El7QC+NaiJAPTmkeNDmSUMPltMPjzfHrOEBZK8xWKggvVeSJygbGg1INpLjS0sBF91aOCXx7pYR0rRlG4xqAYuNsb6LF7h8Qm37xNfYxMMPhLJtBt7okQ==" Dec 28 12:52:46 volumiopi go-librespot[8669]: time="2025-12-28T12:52:46+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 28 12:52:46 volumiopi go-librespot[8669]: time="2025-12-28T12:52:46+08:00" level=debug msg="completed keyexchange" Dec 28 12:52:46 volumiopi go-librespot[8669]: time="2025-12-28T12:52:46+08:00" level=debug msg="completed challenge" Dec 28 12:52:46 volumiopi go-librespot[8669]: time="2025-12-28T12:52:46+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 28 12:52:46 volumiopi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 12:52:46 volumiopi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 12:52:47 volumiopi volumio[968]: info: Initializing connection to go-librespot Websocket Dec 28 12:52:47 volumiopi volumio[968]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 12:52:49 volumiopi systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 12:52:49 volumiopi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 404. Dec 28 12:52:49 volumiopi systemd[1]: Stopped go-librespot Daemon. Dec 28 12:52:49 volumiopi systemd[1]: Started go-librespot Daemon. Dec 28 12:52:49 volumiopi go-librespot[8677]: go-librespot daemon starting... Dec 28 12:52:49 volumiopi go-librespot[8677]: time="2025-12-28T12:52:49+08:00" level=info msg="running go-librespot 0.4.0" Dec 28 12:52:49 volumiopi go-librespot[8677]: time="2025-12-28T12:52:49+08:00" level=debug msg="app state loaded" Dec 28 12:52:49 volumiopi go-librespot[8677]: time="2025-12-28T12:52:49+08:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 28 12:52:49 volumiopi go-librespot[8677]: time="2025-12-28T12:52:49+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 28 12:52:49 volumiopi go-librespot[8677]: time="2025-12-28T12:52:49+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 28 12:52:49 volumiopi go-librespot[8677]: time="2025-12-28T12:52:49+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 28 12:52:49 volumiopi go-librespot[8677]: time="2025-12-28T12:52:49+08:00" level=info msg="zeroconf server listening on port 42415" Dec 28 12:52:49 volumiopi go-librespot[8677]: time="2025-12-28T12:52:49+08:00" level=debug msg="obtained new client token: AABaxDwhEkUvLsPAbExXsS1c0xLKcqTrHGAKyivRGdrVnMobVlIIqGDFEJTJ2UwNDoa+0ZO5Rmgp1iRknxuM2kZtFo2fc0VuBxxlvqQaO6BPuA6uAs/u1mbs5cfvIioxovEVjUPBuboZh0BCSQPgC8AfE1gcomI25Z8CXOxUGTwDc1lbHtiFK4gbsD8mPjuy8nU0UxEIn2ITMHvAUL9QuGwwpg4Vu8ClJ1u5yHOfQyokRs/jTEZey7X6/w==" Dec 28 12:52:49 volumiopi go-librespot[8677]: time="2025-12-28T12:52:49+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 28 12:52:50 volumiopi go-librespot[8677]: time="2025-12-28T12:52:50+08:00" level=debug msg="completed keyexchange" Dec 28 12:52:50 volumiopi go-librespot[8677]: time="2025-12-28T12:52:50+08:00" level=debug msg="completed challenge" Dec 28 12:52:50 volumiopi go-librespot[8677]: time="2025-12-28T12:52:50+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 28 12:52:50 volumiopi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 12:52:50 volumiopi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 12:52:50 volumiopi volumio[968]: info: Initializing connection to go-librespot Websocket Dec 28 12:52:50 volumiopi volumio[968]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 12:52:52 volumiopi volumio[968]: info: Fetched 13.7 MB in 19s (721 kB/s) Dec 28 12:52:53 volumiopi systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 12:52:53 volumiopi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 405. Dec 28 12:52:53 volumiopi systemd[1]: Stopped go-librespot Daemon. Dec 28 12:52:53 volumiopi systemd[1]: Started go-librespot Daemon. Dec 28 12:52:53 volumiopi go-librespot[8701]: go-librespot daemon starting... Dec 28 12:52:53 volumiopi go-librespot[8701]: time="2025-12-28T12:52:53+08:00" level=info msg="running go-librespot 0.4.0" Dec 28 12:52:53 volumiopi go-librespot[8701]: time="2025-12-28T12:52:53+08:00" level=debug msg="app state loaded" Dec 28 12:52:53 volumiopi go-librespot[8701]: time="2025-12-28T12:52:53+08:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 28 12:52:53 volumiopi volumio[968]: info: Initializing connection to go-librespot Websocket Dec 28 12:52:53 volumiopi go-librespot[8701]: time="2025-12-28T12:52:53+08:00" level=debug msg="new websocket client" Dec 28 12:52:53 volumiopi volumio[968]: info: Connection to go-librespot Websocket established Dec 28 12:52:53 volumiopi go-librespot[8701]: time="2025-12-28T12:52:53+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 28 12:52:53 volumiopi go-librespot[8701]: time="2025-12-28T12:52:53+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 28 12:52:53 volumiopi go-librespot[8701]: time="2025-12-28T12:52:53+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 28 12:52:53 volumiopi go-librespot[8701]: time="2025-12-28T12:52:53+08:00" level=info msg="zeroconf server listening on port 40883" Dec 28 12:52:53 volumiopi go-librespot[8701]: time="2025-12-28T12:52:53+08:00" level=debug msg="obtained new client token: AACz+lpmlCnr8OP6B2PVXXUtFuXi28UoZTzyAHUyXmCLgHLW1lRobfRwBAT6xYDjg6KViwGIb24YQMAbsVTvg3pGTr6fxWvV85Xv+9BTU0QU5zPccZvsZJnBp0r9XmjpvO1Nc9J8IwV0qU4I0OKVNMVelXMpGu54RV5kjn0wYMyiTiJFmVAmxEnjcoeKCey6+UlPWMKzLoV4E4/v9by3oiFHWp63JG213zZduVC1Kyxd1Pr5i5t4IKotHw==" Dec 28 12:52:53 volumiopi go-librespot[8701]: time="2025-12-28T12:52:53+08:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Dec 28 12:52:53 volumiopi go-librespot[8701]: time="2025-12-28T12:52:53+08:00" level=debug msg="connected to ap-gae2.spotify.com:443" Dec 28 12:52:53 volumiopi go-librespot[8701]: time="2025-12-28T12:52:53+08:00" level=debug msg="completed keyexchange" Dec 28 12:52:53 volumiopi go-librespot[8701]: time="2025-12-28T12:52:53+08:00" level=debug msg="completed challenge" Dec 28 12:52:54 volumiopi go-librespot[8701]: time="2025-12-28T12:52:54+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 28 12:52:54 volumiopi volumio[968]: info: Connection to go-librespot Websocket closed Dec 28 12:52:54 volumiopi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 12:52:54 volumiopi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 12:52:56 volumiopi volumio[968]: info: Getting Spotify volume Dec 28 12:52:56 volumiopi volumio[968]: (node:968) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 12:52:56 volumiopi volumio[968]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 28 12:52:56 volumiopi volumio[968]: (node:968) 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: 77) Dec 28 12:52:56 volumiopi volumio[968]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Dec 28 12:52:56 volumiopi volumio[968]: info: CoreCommandRouter::volumioGetState Dec 28 12:52:56 volumiopi volumio[968]: info: CorePlayQueue::getTrack 0 Dec 28 12:52:57 volumiopi volumio[968]: info: Initializing connection to go-librespot Websocket Dec 28 12:52:57 volumiopi volumio[968]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 12:52:57 volumiopi systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 12:52:57 volumiopi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 406. Dec 28 12:52:57 volumiopi systemd[1]: Stopped go-librespot Daemon. Dec 28 12:52:57 volumiopi systemd[1]: Started go-librespot Daemon. Dec 28 12:52:57 volumiopi go-librespot[8710]: go-librespot daemon starting... Dec 28 12:52:57 volumiopi go-librespot[8710]: time="2025-12-28T12:52:57+08:00" level=info msg="running go-librespot 0.4.0" Dec 28 12:52:57 volumiopi go-librespot[8710]: time="2025-12-28T12:52:57+08:00" level=debug msg="app state loaded" Dec 28 12:52:57 volumiopi go-librespot[8710]: time="2025-12-28T12:52:57+08:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 28 12:52:57 volumiopi volumio[968]: info: Reading package lists... Dec 28 12:52:57 volumiopi go-librespot[8710]: time="2025-12-28T12:52:57+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 28 12:52:57 volumiopi go-librespot[8710]: time="2025-12-28T12:52:57+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 28 12:52:57 volumiopi go-librespot[8710]: time="2025-12-28T12:52:57+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 28 12:52:57 volumiopi go-librespot[8710]: time="2025-12-28T12:52:57+08:00" level=info msg="zeroconf server listening on port 41091" Dec 28 12:52:57 volumiopi go-librespot[8710]: time="2025-12-28T12:52:57+08:00" level=debug msg="obtained new client token: AAAWNHJGK/9YVy0d/7UZfoQ4g6xYKJVeDrBUGFH/fH0U/+GzAI5J04KtEQcyZZzlwV9JcC6MEfZpnRuEcR34Lf15Caxok850QLOESV4zAwxW/Hv/70mj5XqQZ8tWEn8TFtZnirGwXlAICxKfmAbe5uyJrdC4uZzJQdFEcX2Ca/EZCpJhqVpJfhThXU84TH74Z0p+kv3NCyFnwFA7ZcK0hxBkcz2rXM5UgSsrSWi+ubt3EBG8dlxsh6Pcyw==" Dec 28 12:52:57 volumiopi go-librespot[8710]: time="2025-12-28T12:52:57+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 28 12:52:57 volumiopi go-librespot[8710]: time="2025-12-28T12:52:57+08:00" level=debug msg="completed keyexchange" Dec 28 12:52:57 volumiopi go-librespot[8710]: time="2025-12-28T12:52:57+08:00" level=debug msg="completed challenge" Dec 28 12:52:58 volumiopi go-librespot[8710]: time="2025-12-28T12:52:58+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 28 12:52:58 volumiopi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 12:52:58 volumiopi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 12:52:58 volumiopi volumio[968]: info: Building dependency tree... Dec 28 12:52:58 volumiopi volumio[968]: info: Reading state information... Dec 28 12:52:58 volumiopi volumio[968]: info: All packages are up to date. Dec 28 12:52:58 volumiopi sudo[8371]: pam_unix(sudo:session): session closed for user root Dec 28 12:52:58 volumiopi sudo[8721]: root : TTY=unknown ; PWD=/data/plugins/audio_interface/fusiondsp ; USER=root ; COMMAND=/usr/bin/apt -y install python3-aiohttp python3-pip Dec 28 12:52:58 volumiopi sudo[8721]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 12:52:58 volumiopi volumio[968]: info: Reading package lists... Dec 28 12:52:59 volumiopi volumio[968]: info: Building dependency tree... Dec 28 12:52:59 volumiopi volumio[968]: info: Reading state information... Dec 28 12:53:00 volumiopi volumio[968]: info: Initializing connection to go-librespot Websocket Dec 28 12:53:00 volumiopi volumio[968]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 12:53:01 volumiopi systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 12:53:01 volumiopi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 407. Dec 28 12:53:01 volumiopi systemd[1]: Stopped go-librespot Daemon. Dec 28 12:53:01 volumiopi systemd[1]: Started go-librespot Daemon. Dec 28 12:53:01 volumiopi go-librespot[8725]: go-librespot daemon starting... Dec 28 12:53:01 volumiopi go-librespot[8725]: time="2025-12-28T12:53:01+08:00" level=info msg="running go-librespot 0.4.0" Dec 28 12:53:01 volumiopi go-librespot[8725]: time="2025-12-28T12:53:01+08:00" level=debug msg="app state loaded" Dec 28 12:53:01 volumiopi go-librespot[8725]: time="2025-12-28T12:53:01+08:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 28 12:53:01 volumiopi go-librespot[8725]: time="2025-12-28T12:53:01+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 28 12:53:01 volumiopi go-librespot[8725]: time="2025-12-28T12:53:01+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 28 12:53:01 volumiopi go-librespot[8725]: time="2025-12-28T12:53:01+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 28 12:53:01 volumiopi go-librespot[8725]: time="2025-12-28T12:53:01+08:00" level=info msg="zeroconf server listening on port 33183" Dec 28 12:53:02 volumiopi go-librespot[8725]: time="2025-12-28T12:53:02+08:00" level=debug msg="obtained new client token: AADT8qp8NswukpkAxGQgL+4uLqr+ElCx3J7oE+YYNqcCd/VS5YcjnyOeTmzrtgT8DgnJ0TO4IFs6E4LZwbVZij9LtzwOLAW0qyDgy8V7x+lu4flVGmRf66X5FNCuQIcoxkHjyOKaCGSeS57emtH0j/3nbLYDcV4EzM1BmS+cQ/RZLR6DNTxh4zf7PJLSBRL3Vt1DWplQDbmY3XLa45vTEj2se0Ouzu4KaQMtSR75jdZLQyZygBq8es4=" Dec 28 12:53:02 volumiopi go-librespot[8725]: time="2025-12-28T12:53:02+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 28 12:53:02 volumiopi go-librespot[8725]: time="2025-12-28T12:53:02+08:00" level=debug msg="completed keyexchange" Dec 28 12:53:02 volumiopi go-librespot[8725]: time="2025-12-28T12:53:02+08:00" level=debug msg="completed challenge" Dec 28 12:53:02 volumiopi go-librespot[8725]: time="2025-12-28T12:53:02+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 28 12:53:02 volumiopi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 12:53:02 volumiopi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 12:53:03 volumiopi volumio[968]: info: Initializing connection to go-librespot Websocket Dec 28 12:53:03 volumiopi volumio[968]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 12:53:04 volumiopi volumio[968]: info: python3-aiohttp is already the newest version (3.5.1-1+deb10u1). Dec 28 12:53:04 volumiopi sudo[8721]: pam_unix(sudo:session): session closed for user root Dec 28 12:53:04 volumiopi volumio[968]: info: python3-pip is already the newest version (18.1-5+rpt1). Dec 28 12:53:04 volumiopi volumio[968]: info: 0 upgraded, 0 newly installed, 0 to remove and 2 not upgraded. Dec 28 12:53:04 volumiopi sudo[8750]: root : TTY=unknown ; PWD=/data/plugins/audio_interface/fusiondsp ; USER=root ; COMMAND=/bin/tar -xvf fusiondsp.service.tar -C / Dec 28 12:53:04 volumiopi sudo[8750]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 12:53:05 volumiopi systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 12:53:05 volumiopi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 408. Dec 28 12:53:05 volumiopi systemd[1]: Stopped go-librespot Daemon. Dec 28 12:53:05 volumiopi systemd[1]: Started go-librespot Daemon. Dec 28 12:53:05 volumiopi go-librespot[8752]: go-librespot daemon starting... Dec 28 12:53:05 volumiopi go-librespot[8752]: time="2025-12-28T12:53:05+08:00" level=info msg="running go-librespot 0.4.0" Dec 28 12:53:05 volumiopi go-librespot[8752]: time="2025-12-28T12:53:05+08:00" level=debug msg="app state loaded" Dec 28 12:53:05 volumiopi go-librespot[8752]: time="2025-12-28T12:53:05+08:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 28 12:53:05 volumiopi go-librespot[8752]: time="2025-12-28T12:53:05+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 28 12:53:05 volumiopi go-librespot[8752]: time="2025-12-28T12:53:05+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 28 12:53:05 volumiopi go-librespot[8752]: time="2025-12-28T12:53:05+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 28 12:53:05 volumiopi go-librespot[8752]: time="2025-12-28T12:53:05+08:00" level=info msg="zeroconf server listening on port 34267" Dec 28 12:53:05 volumiopi go-librespot[8752]: time="2025-12-28T12:53:05+08:00" level=debug msg="obtained new client token: AABGOP6V312YFQDgpVPkcNGMsuIscH3nlAsK2RJRcQuRQe5ZfrY9Vv2JEfaPi0bzFyNV7Dnz2xGhf4GwwU03itPQJpMqV7HPjWQqDvULSQiACXVgSe3pnuoVAODD5/8Iy39JskNfj4hX7LeDcJNPLev++x+e+1m/wiBUIp75fD0W92WmXEeQO2zkMtWJd5eCVIsSIQh+P7DGcI4mzSF2MAG1oDjyl6tW4coRdTxUPelQ2CAf1GJutaM/6w==" Dec 28 12:53:05 volumiopi go-librespot[8752]: time="2025-12-28T12:53:05+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 28 12:53:06 volumiopi volumio[968]: info: Initializing connection to go-librespot Websocket Dec 28 12:53:06 volumiopi go-librespot[8752]: time="2025-12-28T12:53:06+08:00" level=debug msg="completed keyexchange" Dec 28 12:53:06 volumiopi go-librespot[8752]: time="2025-12-28T12:53:06+08:00" level=debug msg="completed challenge" Dec 28 12:53:06 volumiopi go-librespot[8752]: time="2025-12-28T12:53:06+08:00" level=debug msg="new websocket client" Dec 28 12:53:06 volumiopi volumio[968]: info: Connection to go-librespot Websocket established Dec 28 12:53:06 volumiopi go-librespot[8752]: time="2025-12-28T12:53:06+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 28 12:53:06 volumiopi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 12:53:06 volumiopi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 12:53:06 volumiopi volumio[968]: info: Connection to go-librespot Websocket closed Dec 28 12:53:08 volumiopi volumio[968]: info: lib/systemd/system/fusiondsp.service Dec 28 12:53:08 volumiopi sudo[8750]: pam_unix(sudo:session): session closed for user root Dec 28 12:53:09 volumiopi volumio[968]: info: Getting Spotify volume Dec 28 12:53:09 volumiopi volumio[968]: (node:968) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 12:53:09 volumiopi volumio[968]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 28 12:53:09 volumiopi volumio[968]: (node:968) 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: 78) Dec 28 12:53:09 volumiopi volumio[968]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Dec 28 12:53:09 volumiopi volumio[968]: info: CoreCommandRouter::volumioGetState Dec 28 12:53:09 volumiopi volumio[968]: info: CorePlayQueue::getTrack 0 Dec 28 12:53:09 volumiopi volumio[968]: info: Initializing connection to go-librespot Websocket Dec 28 12:53:09 volumiopi volumio[968]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 12:53:09 volumiopi systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 12:53:09 volumiopi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 409. Dec 28 12:53:09 volumiopi systemd[1]: Stopped go-librespot Daemon. Dec 28 12:53:09 volumiopi systemd[1]: Started go-librespot Daemon. Dec 28 12:53:09 volumiopi go-librespot[8762]: go-librespot daemon starting... Dec 28 12:53:09 volumiopi go-librespot[8762]: time="2025-12-28T12:53:09+08:00" level=info msg="running go-librespot 0.4.0" Dec 28 12:53:09 volumiopi go-librespot[8762]: time="2025-12-28T12:53:09+08:00" level=debug msg="app state loaded" Dec 28 12:53:09 volumiopi go-librespot[8762]: time="2025-12-28T12:53:09+08:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 28 12:53:09 volumiopi go-librespot[8762]: time="2025-12-28T12:53:09+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 28 12:53:09 volumiopi go-librespot[8762]: time="2025-12-28T12:53:09+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 28 12:53:09 volumiopi go-librespot[8762]: time="2025-12-28T12:53:09+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 28 12:53:09 volumiopi go-librespot[8762]: time="2025-12-28T12:53:09+08:00" level=info msg="zeroconf server listening on port 38863" Dec 28 12:53:09 volumiopi go-librespot[8762]: time="2025-12-28T12:53:09+08:00" level=debug msg="obtained new client token: AAC+V8z5MAumJGaEd7erdMORJBTJjmzvrX7wZwZhTQr2HPIW6VV1QM6XLdY/VOfYUERqFhuXA76JMMFyUO0JlwspPZPne6ry9lVPihRk48pCg6kCWzUrTROoiVo5X1f5TRRevw9JKObtJcJ8iLAIWc8yf0/5hCf0+F8tnXSIHs1p+UhSHolz3GEkXqWV75PfL1DpQN2nsRdudCByH/oe5zp9mfnE9gQPEcARRE2jMpuekxG6nVGl7hpAJQ==" Dec 28 12:53:09 volumiopi go-librespot[8762]: time="2025-12-28T12:53:09+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 28 12:53:09 volumiopi go-librespot[8762]: time="2025-12-28T12:53:09+08:00" level=debug msg="completed keyexchange" Dec 28 12:53:09 volumiopi go-librespot[8762]: time="2025-12-28T12:53:09+08:00" level=debug msg="completed challenge" Dec 28 12:53:09 volumiopi go-librespot[8762]: time="2025-12-28T12:53:09+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 28 12:53:10 volumiopi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 12:53:10 volumiopi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 12:53:12 volumiopi volumio[968]: info: Initializing connection to go-librespot Websocket Dec 28 12:53:12 volumiopi volumio[968]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 12:53:13 volumiopi systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 12:53:13 volumiopi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 410. Dec 28 12:53:13 volumiopi systemd[1]: Stopped go-librespot Daemon. Dec 28 12:53:13 volumiopi systemd[1]: Started go-librespot Daemon. Dec 28 12:53:13 volumiopi go-librespot[8785]: go-librespot daemon starting... Dec 28 12:53:13 volumiopi go-librespot[8785]: time="2025-12-28T12:53:13+08:00" level=info msg="running go-librespot 0.4.0" Dec 28 12:53:13 volumiopi go-librespot[8785]: time="2025-12-28T12:53:13+08:00" level=debug msg="app state loaded" Dec 28 12:53:13 volumiopi go-librespot[8785]: time="2025-12-28T12:53:13+08:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 28 12:53:13 volumiopi go-librespot[8785]: time="2025-12-28T12:53:13+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 28 12:53:13 volumiopi go-librespot[8785]: time="2025-12-28T12:53:13+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 28 12:53:13 volumiopi go-librespot[8785]: time="2025-12-28T12:53:13+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 28 12:53:13 volumiopi go-librespot[8785]: time="2025-12-28T12:53:13+08:00" level=info msg="zeroconf server listening on port 38463" Dec 28 12:53:14 volumiopi go-librespot[8785]: time="2025-12-28T12:53:14+08:00" level=debug msg="obtained new client token: AACwBOCjy5bc0/FqnVoNl7FvIIfrviLTXR8sUZI/v5mfExBLnA/WIa++QWw66MP5Q2zJVyThM720m+iZ08RnDrxuQkFV4hVJmCaldsHHXyi3S3yUfpDdNkpj+pMo3gCUYauIhdU0RHy60XWLR39v7+PsqLfFyeJ6Zdpb38yaaE673O3uFkSX/ENgqell2SBLlDFYcKNX4Kg8xdrbH8z9PiektuHc8V2RQ0nDsuSeTKiT+GiXiXp9/TU=" Dec 28 12:53:14 volumiopi go-librespot[8785]: time="2025-12-28T12:53:14+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 28 12:53:14 volumiopi go-librespot[8785]: time="2025-12-28T12:53:14+08:00" level=debug msg="completed keyexchange" Dec 28 12:53:14 volumiopi go-librespot[8785]: time="2025-12-28T12:53:14+08:00" level=debug msg="completed challenge" Dec 28 12:53:14 volumiopi go-librespot[8785]: time="2025-12-28T12:53:14+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 28 12:53:14 volumiopi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 12:53:14 volumiopi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 12:53:14 volumiopi volumio[968]: info: MiniUnz 1.01b, demo of zLib + Unz package written by Gilles Vollant Dec 28 12:53:14 volumiopi volumio[968]: info: more info at http://www.winimage.com/zLibDll/unzip.html Dec 28 12:53:14 volumiopi volumio[968]: info: Dec 28 12:53:14 volumiopi volumio[968]: info: cgui-1.0.0.zip opened Dec 28 12:53:14 volumiopi volumio[968]: info: creating directory: cgui/ Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/LICENSE.txt Dec 28 12:53:14 volumiopi sudo[8794]: root : TTY=unknown ; PWD=/data/plugins/audio_interface/fusiondsp ; USER=root ; COMMAND=/bin/chown -R volumio cgui Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/README.md Dec 28 12:53:14 volumiopi sudo[8794]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 12:53:14 volumiopi volumio[968]: info: creating directory: cgui/build/ Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/robots.txt Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/logo512.png Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/asset-manifest.json Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/index.html Dec 28 12:53:14 volumiopi sudo[8794]: pam_unix(sudo:session): session closed for user root Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/.put_statics_here Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/favicon.ico Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/logo192.png Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/.xdp-css-variables-1.css-PvrWoX Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/manifest.json Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/css-variables.css Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/precache-manifest.76db5aad1647230454f47b1e22783b54.js Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/service-worker.js Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/precache-manifest.5e6c675b70ef6a3fe73d0209febfe347.js Dec 28 12:53:14 volumiopi volumio[968]: info: creating directory: cgui/build/static/ Dec 28 12:53:14 volumiopi volumio[968]: info: creating directory: cgui/build/static/css/ Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/static/css/main.d51d005e.chunk.css Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/static/css/main.d51d005e.chunk.css.map Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/static/css/2.975d6916.chunk.css.map Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/static/css/main.56bdf14e.chunk.css Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/static/css/main.56bdf14e.chunk.css.map Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/static/css/main.1503f6cd.css.map Dec 28 12:53:14 volumiopi sudo[8796]: root : TTY=unknown ; PWD=/data/plugins/audio_interface/fusiondsp ; USER=root ; COMMAND=/bin/chgrp -R volumio cgui Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/static/css/2.a4c7e7cf.chunk.css.map Dec 28 12:53:14 volumiopi sudo[8796]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/static/css/main.1503f6cd.css Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/static/css/2.975d6916.chunk.css Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/static/css/2.a4c7e7cf.chunk.css Dec 28 12:53:14 volumiopi volumio[968]: info: creating directory: cgui/build/static/media/ Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/static/media/camilladsp.95719842.svg Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/static/media/camilladsp.4767ea4ad3510467418b818dc677a87e.svg Dec 28 12:53:14 volumiopi volumio[968]: info: creating directory: cgui/build/static/js/ Dec 28 12:53:14 volumiopi sudo[8796]: pam_unix(sudo:session): session closed for user root Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/static/js/2.fd49ece5.chunk.js.map Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/static/js/main.71e11955.js Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/static/js/runtime-main.422581ec.js Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/static/js/2.fd49ece5.chunk.js Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/static/js/2.c1b9df8b.chunk.js.LICENSE.txt Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/static/js/main.61bb6809.chunk.js Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/static/js/main.61bb6809.chunk.js.map Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/static/js/2.c1b9df8b.chunk.js Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/static/js/main.1b3ac690.chunk.js.map Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/static/js/main.71e11955.js.LICENSE.txt Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/static/js/main.71e11955.js.map Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/static/js/runtime-main.422581ec.js.map Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/static/js/main.1b3ac690.chunk.js Dec 28 12:53:14 volumiopi sudo[8798]: root : TTY=unknown ; PWD=/data/plugins/audio_interface/fusiondsp ; USER=root ; COMMAND=/bin/rm cgui-1.0.0.zip Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/static/js/2.c1b9df8b.chunk.js.map Dec 28 12:53:14 volumiopi sudo[8798]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/build/static/js/2.fd49ece5.chunk.js.LICENSE.txt Dec 28 12:53:14 volumiopi volumio[968]: info: creating directory: cgui/config/ Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/config/camillagui.yml Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/config/.xdp-css-variables-1.css-ppBDuX Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/config/gui-config.yml Dec 28 12:53:14 volumiopi volumio[968]: info: creating directory: cgui/backend/ Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/backend/filters_test.py Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/backend/version.py Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/backend/filters.py Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/backend/settings.py Dec 28 12:53:14 volumiopi sudo[8798]: pam_unix(sudo:session): session closed for user root Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/backend/views.py Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/backend/filterdefaults.py Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/backend/__init__.py Dec 28 12:53:14 volumiopi volumio[968]: info: creating directory: cgui/backend/__pycache__/ Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/backend/__pycache__/filterdefaults.cpython-37.pyc Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/backend/__pycache__/views.cpython-37.pyc Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/backend/__pycache__/settings.cpython-37.pyc Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/backend/__pycache__/__init__.cpython-37.pyc Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/backend/__pycache__/routes.cpython-37.pyc Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/backend/__pycache__/filemanagement.cpython-37.pyc Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/backend/__pycache__/filters.cpython-37.pyc Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/backend/__pycache__/version.cpython-37.pyc Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/backend/routes.py Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/backend/filemanagement.py Dec 28 12:53:14 volumiopi volumio[968]: info: extracting: cgui/main.py Dec 28 12:53:15 volumiopi volumio[968]: info: Initializing connection to go-librespot Websocket Dec 28 12:53:15 volumiopi volumio[968]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 12:53:17 volumiopi systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 12:53:17 volumiopi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 411. Dec 28 12:53:17 volumiopi systemd[1]: Stopped go-librespot Daemon. Dec 28 12:53:17 volumiopi systemd[1]: Started go-librespot Daemon. Dec 28 12:53:17 volumiopi go-librespot[8801]: go-librespot daemon starting... Dec 28 12:53:17 volumiopi go-librespot[8801]: time="2025-12-28T12:53:17+08:00" level=info msg="running go-librespot 0.4.0" Dec 28 12:53:17 volumiopi go-librespot[8801]: time="2025-12-28T12:53:17+08:00" level=debug msg="app state loaded" Dec 28 12:53:17 volumiopi go-librespot[8801]: time="2025-12-28T12:53:17+08:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 28 12:53:17 volumiopi go-librespot[8801]: time="2025-12-28T12:53:17+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 28 12:53:17 volumiopi go-librespot[8801]: time="2025-12-28T12:53:17+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 28 12:53:17 volumiopi go-librespot[8801]: time="2025-12-28T12:53:17+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 28 12:53:17 volumiopi go-librespot[8801]: time="2025-12-28T12:53:17+08:00" level=info msg="zeroconf server listening on port 46647" Dec 28 12:53:17 volumiopi go-librespot[8801]: time="2025-12-28T12:53:17+08:00" level=debug msg="obtained new client token: AAB00MpkXTyCVUJIp018jO57KhdjxNLznXgXNmZH/fQfjy5pL2J7gfpVHNsoiEYxUDQDtD1iJS7qbWLWZAmXZQexaPtDn+KIwkMElXTImq8DgdAqNKKuwSH8jIkVqUpOHJJTDdW07AzvOKIijCzvJadp8rX7H2XRaf1ojfGbm022qFeiH2rD96n63CPN42lg8c3fviT5yu9RnJcK3WiBDhdvwrskirhsCvaepmFxlO8HVB8rpRauVx8YNQ==" Dec 28 12:53:18 volumiopi go-librespot[8801]: time="2025-12-28T12:53:18+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 28 12:53:18 volumiopi go-librespot[8801]: time="2025-12-28T12:53:18+08:00" level=debug msg="completed keyexchange" Dec 28 12:53:18 volumiopi go-librespot[8801]: time="2025-12-28T12:53:18+08:00" level=debug msg="completed challenge" Dec 28 12:53:18 volumiopi volumio[968]: info: Initializing connection to go-librespot Websocket Dec 28 12:53:18 volumiopi go-librespot[8801]: time="2025-12-28T12:53:18+08:00" level=debug msg="new websocket client" Dec 28 12:53:18 volumiopi volumio[968]: info: Connection to go-librespot Websocket established Dec 28 12:53:18 volumiopi go-librespot[8801]: time="2025-12-28T12:53:18+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 28 12:53:18 volumiopi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 12:53:18 volumiopi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 12:53:18 volumiopi volumio[968]: info: Connection to go-librespot Websocket closed Dec 28 12:53:21 volumiopi volumio[968]: info: Getting Spotify volume Dec 28 12:53:21 volumiopi volumio[968]: (node:968) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 12:53:21 volumiopi volumio[968]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 28 12:53:21 volumiopi volumio[968]: (node:968) 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: 79) Dec 28 12:53:21 volumiopi volumio[968]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Dec 28 12:53:21 volumiopi volumio[968]: info: Initializing connection to go-librespot Websocket Dec 28 12:53:21 volumiopi volumio[968]: info: CoreCommandRouter::volumioGetState Dec 28 12:53:21 volumiopi volumio[968]: info: CorePlayQueue::getTrack 0 Dec 28 12:53:21 volumiopi volumio[968]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 12:53:21 volumiopi systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 12:53:21 volumiopi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 412. Dec 28 12:53:21 volumiopi systemd[1]: Stopped go-librespot Daemon. Dec 28 12:53:21 volumiopi systemd[1]: Started go-librespot Daemon. Dec 28 12:53:21 volumiopi go-librespot[8810]: go-librespot daemon starting... Dec 28 12:53:21 volumiopi go-librespot[8810]: time="2025-12-28T12:53:21+08:00" level=info msg="running go-librespot 0.4.0" Dec 28 12:53:21 volumiopi go-librespot[8810]: time="2025-12-28T12:53:21+08:00" level=debug msg="app state loaded" Dec 28 12:53:21 volumiopi go-librespot[8810]: time="2025-12-28T12:53:21+08:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 28 12:53:21 volumiopi go-librespot[8810]: time="2025-12-28T12:53:21+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 28 12:53:21 volumiopi go-librespot[8810]: time="2025-12-28T12:53:21+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 28 12:53:21 volumiopi go-librespot[8810]: time="2025-12-28T12:53:21+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 28 12:53:21 volumiopi go-librespot[8810]: time="2025-12-28T12:53:21+08:00" level=info msg="zeroconf server listening on port 39789" Dec 28 12:53:21 volumiopi go-librespot[8810]: time="2025-12-28T12:53:21+08:00" level=debug msg="obtained new client token: AABhYOuE6MO1JL+ZFP+HDrTx2q+Km4Tb95oaZ51kltqlM9+eNFmyn8S83hnWDwdyMcxv74XoWPLd7TIpp2NaEu+6vI82EbeyQIj8qwAQyRUGMHq/Mdd77K6M1swCHiBSFuTOc8KnuMMgP4pxLPQeN3Cs2QkdzG+oN/S32HzzotSXHTrv7X0xwCFcQXE+EhhbXrR/RJCyKbdozV8NV/uYOhgLDkrioGoghA+ZMwjdzIuAkfS3ZcP3gzMU8w==" Dec 28 12:53:21 volumiopi go-librespot[8810]: time="2025-12-28T12:53:21+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 28 12:53:22 volumiopi go-librespot[8810]: time="2025-12-28T12:53:22+08:00" level=debug msg="completed keyexchange" Dec 28 12:53:22 volumiopi go-librespot[8810]: time="2025-12-28T12:53:22+08:00" level=debug msg="completed challenge" Dec 28 12:53:22 volumiopi go-librespot[8810]: time="2025-12-28T12:53:22+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 28 12:53:22 volumiopi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 12:53:22 volumiopi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 12:53:24 volumiopi volumio[968]: info: Initializing connection to go-librespot Websocket Dec 28 12:53:24 volumiopi volumio[968]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 12:53:25 volumiopi systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 12:53:25 volumiopi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 413. Dec 28 12:53:25 volumiopi systemd[1]: Stopped go-librespot Daemon. Dec 28 12:53:25 volumiopi systemd[1]: Started go-librespot Daemon. Dec 28 12:53:25 volumiopi go-librespot[8835]: go-librespot daemon starting... Dec 28 12:53:25 volumiopi go-librespot[8835]: time="2025-12-28T12:53:25+08:00" level=info msg="running go-librespot 0.4.0" Dec 28 12:53:25 volumiopi go-librespot[8835]: time="2025-12-28T12:53:25+08:00" level=debug msg="app state loaded" Dec 28 12:53:25 volumiopi go-librespot[8835]: time="2025-12-28T12:53:25+08:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 28 12:53:25 volumiopi go-librespot[8835]: time="2025-12-28T12:53:25+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 28 12:53:25 volumiopi go-librespot[8835]: time="2025-12-28T12:53:25+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 28 12:53:25 volumiopi go-librespot[8835]: time="2025-12-28T12:53:25+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 28 12:53:25 volumiopi go-librespot[8835]: time="2025-12-28T12:53:25+08:00" level=info msg="zeroconf server listening on port 42913" Dec 28 12:53:25 volumiopi go-librespot[8835]: time="2025-12-28T12:53:25+08:00" level=debug msg="obtained new client token: AAAqttxA0+7Ru5wbaMQJ91l8GZRvxQxsGKnRLJeisy9TAnpoW1cC/YQH+JuSOHiphMY1r6T1NZn+Y2Jl2TkTAYh67UOYZlN+45K9zPXLuWh3WzAUpnAg9Q4GszUBECrEYSPXnq6ZOefgc1U23QyJc6kUJjAvYjdvHKRKr1t7nrkC92K2ilSHDARAtiJbey2KcESrW/oVOukhrXLeNF2M4S4U0adKzcjUtaVB5gO77OvuODOXeJjX2igSfg==" Dec 28 12:53:25 volumiopi go-librespot[8835]: time="2025-12-28T12:53:25+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 28 12:53:25 volumiopi go-librespot[8835]: time="2025-12-28T12:53:25+08:00" level=debug msg="completed keyexchange" Dec 28 12:53:25 volumiopi go-librespot[8835]: time="2025-12-28T12:53:25+08:00" level=debug msg="completed challenge" Dec 28 12:53:25 volumiopi go-librespot[8835]: time="2025-12-28T12:53:25+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 28 12:53:25 volumiopi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 12:53:25 volumiopi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 12:53:27 volumiopi volumio[968]: info: Looking in indexes: https://pypi.org/simple, https://www.piwheels.org/simple Dec 28 12:53:27 volumiopi volumio[968]: info: Collecting git+https://github.com/HEnquist/pycamilladsp.git@v1.0.0 Dec 28 12:53:27 volumiopi volumio[968]: info: Cloning https://github.com/HEnquist/pycamilladsp.git (to revision v1.0.0) to /tmp/pip-req-build-th488js0 Dec 28 12:53:27 volumiopi volumio[968]: info: Initializing connection to go-librespot Websocket Dec 28 12:53:27 volumiopi volumio[968]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 12:53:29 volumiopi systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 12:53:29 volumiopi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 414. Dec 28 12:53:29 volumiopi systemd[1]: Stopped go-librespot Daemon. Dec 28 12:53:29 volumiopi systemd[1]: Started go-librespot Daemon. Dec 28 12:53:29 volumiopi go-librespot[8861]: go-librespot daemon starting... Dec 28 12:53:29 volumiopi go-librespot[8861]: time="2025-12-28T12:53:29+08:00" level=info msg="running go-librespot 0.4.0" Dec 28 12:53:29 volumiopi go-librespot[8861]: time="2025-12-28T12:53:29+08:00" level=debug msg="app state loaded" Dec 28 12:53:29 volumiopi go-librespot[8861]: time="2025-12-28T12:53:29+08:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 28 12:53:29 volumiopi go-librespot[8861]: time="2025-12-28T12:53:29+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 28 12:53:29 volumiopi go-librespot[8861]: time="2025-12-28T12:53:29+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 28 12:53:29 volumiopi go-librespot[8861]: time="2025-12-28T12:53:29+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 28 12:53:29 volumiopi go-librespot[8861]: time="2025-12-28T12:53:29+08:00" level=info msg="zeroconf server listening on port 43703" Dec 28 12:53:29 volumiopi go-librespot[8861]: time="2025-12-28T12:53:29+08:00" level=debug msg="obtained new client token: AAAyO3XQvBEAkj9U907IVOZCzLjBop5QKraqTX3YqsJ++TISoi46yhOMMmybJNEsQu2PdQ7jCiEyp7cWLJRKlYTYioHMjOMpZjTGJHp5/WyfUWL6LUjI0k0a0aPt5Sh2AOTtBLLILBqYLKk0DdJQzPoC4+L23HkIgfEOYtKTqmmfSHts3w5F8OMwXh5rq1/Dr0YP+5IIUZ8xuSBJfm6WMTthBnmBrI92oi5RYrQMUtgKyX4OT+BsAI1O0g==" Dec 28 12:53:29 volumiopi go-librespot[8861]: time="2025-12-28T12:53:29+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 28 12:53:29 volumiopi go-librespot[8861]: time="2025-12-28T12:53:29+08:00" level=debug msg="completed keyexchange" Dec 28 12:53:29 volumiopi go-librespot[8861]: time="2025-12-28T12:53:29+08:00" level=debug msg="completed challenge" Dec 28 12:53:29 volumiopi go-librespot[8861]: time="2025-12-28T12:53:29+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 28 12:53:29 volumiopi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 12:53:29 volumiopi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 12:53:30 volumiopi volumio[968]: info: Initializing connection to go-librespot Websocket Dec 28 12:53:30 volumiopi volumio[968]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 12:53:30 volumiopi volumio[968]: info: Requirement already satisfied (use --upgrade to upgrade): camilladsp==1.0.0 from git+https://github.com/HEnquist/pycamilladsp.git@v1.0.0 in /usr/local/lib/python3.7/dist-packages Dec 28 12:53:30 volumiopi volumio[968]: info: Requirement already satisfied: PyYAML in /usr/local/lib/python3.7/dist-packages (from camilladsp==1.0.0) (6.0.1) Dec 28 12:53:30 volumiopi volumio[968]: info: Requirement already satisfied: websocket_client in /usr/local/lib/python3.7/dist-packages (from camilladsp==1.0.0) (1.6.1) Dec 28 12:53:30 volumiopi volumio[968]: info: Building wheels for collected packages: camilladsp Dec 28 12:53:30 volumiopi volumio[968]: info: Running setup.py bdist_wheel for camilladsp: started Dec 28 12:53:32 volumiopi volumio[968]: info: Running setup.py bdist_wheel for camilladsp: finished with status 'done' Dec 28 12:53:32 volumiopi volumio[968]: info: Stored in directory: /tmp/pip-ephem-wheel-cache-l3owh29k/wheels/ca/47/7d/ee36beb671f74869a8e2ecb2c3fd4a28c1b7488a9c78e442b6 Dec 28 12:53:32 volumiopi volumio[968]: info: Successfully built camilladsp Dec 28 12:53:33 volumiopi systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 12:53:33 volumiopi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 415. Dec 28 12:53:33 volumiopi systemd[1]: Stopped go-librespot Daemon. Dec 28 12:53:33 volumiopi volumio[968]: info: Initializing connection to go-librespot Websocket Dec 28 12:53:33 volumiopi volumio[968]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 12:53:33 volumiopi systemd[1]: Started go-librespot Daemon. Dec 28 12:53:33 volumiopi go-librespot[8927]: go-librespot daemon starting... Dec 28 12:53:33 volumiopi go-librespot[8927]: time="2025-12-28T12:53:33+08:00" level=info msg="running go-librespot 0.4.0" Dec 28 12:53:33 volumiopi go-librespot[8927]: time="2025-12-28T12:53:33+08:00" level=debug msg="app state loaded" Dec 28 12:53:33 volumiopi go-librespot[8927]: time="2025-12-28T12:53:33+08:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 28 12:53:33 volumiopi go-librespot[8927]: time="2025-12-28T12:53:33+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 28 12:53:33 volumiopi go-librespot[8927]: time="2025-12-28T12:53:33+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 28 12:53:33 volumiopi go-librespot[8927]: time="2025-12-28T12:53:33+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 28 12:53:33 volumiopi go-librespot[8927]: time="2025-12-28T12:53:33+08:00" level=info msg="zeroconf server listening on port 44009" Dec 28 12:53:33 volumiopi go-librespot[8927]: time="2025-12-28T12:53:33+08:00" level=debug msg="obtained new client token: AAAnyS2w8ZRW1/nEAX17E6dJftgRKc6/qQxDEe6HCC2/2CRM0kvcjjkDTaS7V+x6KwoPih1zrl7rKq8pTq3LPWE77tvNFAcw5Uo6ybLiWlD9ifo0V7tE0c5snHuP5z+5kDJyk3KlM0NFcg5OJuOpH6/Ewb28VP9Q7A0bNO4m5dtHfA1h7d0SO2v9OdMayMx0/BmfnpvuNYW7HhcAcRjjO0nD0x0XKTj98G386kw54Yx5mMWD/l6oxpkt0Q==" Dec 28 12:53:33 volumiopi go-librespot[8927]: time="2025-12-28T12:53:33+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 28 12:53:33 volumiopi go-librespot[8927]: time="2025-12-28T12:53:33+08:00" level=debug msg="completed keyexchange" Dec 28 12:53:33 volumiopi go-librespot[8927]: time="2025-12-28T12:53:33+08:00" level=debug msg="completed challenge" Dec 28 12:53:33 volumiopi go-librespot[8927]: time="2025-12-28T12:53:33+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 28 12:53:33 volumiopi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 12:53:33 volumiopi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 12:53:35 volumiopi volumio[968]: verbose: New Socket.io Connection to 192.168.18.32:3000 from 192.168.18.65 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Dec 28 12:53:35 volumiopi volumio[968]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 28 12:53:35 volumiopi volumio[968]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 28 12:53:35 volumiopi volumio[968]: info: Discovery: Getting this device information Dec 28 12:53:35 volumiopi volumio[968]: info: CoreCommandRouter::volumioGetState Dec 28 12:53:35 volumiopi volumio[968]: info: CorePlayQueue::getTrack 0 Dec 28 12:53:35 volumiopi volumio[968]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 28 12:53:36 volumiopi volumio[968]: info: Initializing connection to go-librespot Websocket Dec 28 12:53:36 volumiopi volumio[968]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 12:53:36 volumiopi systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 12:53:36 volumiopi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 416. Dec 28 12:53:36 volumiopi systemd[1]: Stopped go-librespot Daemon. Dec 28 12:53:37 volumiopi systemd[1]: Started go-librespot Daemon. Dec 28 12:53:37 volumiopi go-librespot[8936]: go-librespot daemon starting... Dec 28 12:53:37 volumiopi go-librespot[8936]: time="2025-12-28T12:53:37+08:00" level=info msg="running go-librespot 0.4.0" Dec 28 12:53:37 volumiopi go-librespot[8936]: time="2025-12-28T12:53:37+08:00" level=debug msg="app state loaded" Dec 28 12:53:37 volumiopi go-librespot[8936]: time="2025-12-28T12:53:37+08:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 28 12:53:37 volumiopi volumio[968]: verbose: New Socket.io Connection to 192.168.18.32 from 192.168.18.65 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 7 Dec 28 12:53:37 volumiopi go-librespot[8936]: time="2025-12-28T12:53:37+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 28 12:53:37 volumiopi go-librespot[8936]: time="2025-12-28T12:53:37+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 28 12:53:37 volumiopi go-librespot[8936]: time="2025-12-28T12:53:37+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 28 12:53:37 volumiopi go-librespot[8936]: time="2025-12-28T12:53:37+08:00" level=info msg="zeroconf server listening on port 40577" Dec 28 12:53:37 volumiopi go-librespot[8936]: time="2025-12-28T12:53:37+08:00" level=debug msg="obtained new client token: AACjcgYRbGZy0OYtjw+7Eu1WS6SufC2B+oxrVPE/VELmnrZbYWo0DJkOEPcYjWcRvBL9ShtRAZc/S8v5CJw5sBDX/WuQY+n1qnDB8elfz9GG/Qyu8gM/EmLTXjQ7MvE4nvZBtadQsNNHInp+DE926EIZvDTdCmf7hLqkkRlFRuHolRrn1RWVd3f3DV1lgcgXYssuuu/cxCgdeD1SO7TwiZs+tISUcMkxux6DBfce0B4C4vUZAQUQ1H43Kg==" Dec 28 12:53:37 volumiopi go-librespot[8936]: time="2025-12-28T12:53:37+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 28 12:53:37 volumiopi go-librespot[8936]: time="2025-12-28T12:53:37+08:00" level=debug msg="completed keyexchange" Dec 28 12:53:37 volumiopi go-librespot[8936]: time="2025-12-28T12:53:37+08:00" level=debug msg="completed challenge" Dec 28 12:53:37 volumiopi go-librespot[8936]: time="2025-12-28T12:53:37+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 28 12:53:37 volumiopi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 12:53:37 volumiopi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 12:53:39 volumiopi volumio[968]: verbose: New Socket.io Connection to 192.168.18.32 from 192.168.18.65 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 8 Dec 28 12:53:39 volumiopi volumio[968]: info: Initializing connection to go-librespot Websocket Dec 28 12:53:39 volumiopi volumio[968]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 12:53:39 volumiopi volumio[968]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 28 12:53:39 volumiopi volumio[968]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Dec 28 12:53:39 volumiopi volumio[968]: info: CoreCommandRouter::volumioGetVisibleSources Dec 28 12:53:39 volumiopi volumio[968]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 28 12:53:39 volumiopi volumio[968]: info: CoreCommandRouter::volumioGetState Dec 28 12:53:39 volumiopi volumio[968]: info: CorePlayQueue::getTrack 0 Dec 28 12:53:39 volumiopi volumio[968]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 28 12:53:39 volumiopi volumio[968]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 28 12:53:39 volumiopi volumio[968]: info: Received Get System Info Dec 28 12:53:39 volumiopi volumio[968]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 28 12:53:39 volumiopi volumio[968]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 28 12:53:39 volumiopi volumio[968]: info: Discovery: Getting this device information Dec 28 12:53:39 volumiopi volumio[968]: info: CoreCommandRouter::volumioGetState Dec 28 12:53:39 volumiopi volumio[968]: info: CorePlayQueue::getTrack 0 Dec 28 12:53:39 volumiopi volumio[968]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 28 12:53:39 volumiopi volumio[968]: info: CoreCommandRouter::volumioGetState Dec 28 12:53:39 volumiopi volumio[968]: info: CorePlayQueue::getTrack 0 Dec 28 12:53:39 volumiopi volumio[968]: info: Listing playlists Dec 28 12:53:39 volumiopi volumio[968]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 28 12:53:39 volumiopi volumio[968]: info: FusionDsp - Fluance SX6 Full Range Dec 28 12:53:40 volumiopi volumio[968]: info: FusionDsp - .json,Fluance SX6 Full Range.json Dec 28 12:53:40 volumiopi volumio[968]: info: Looking in indexes: https://pypi.org/simple, https://www.piwheels.org/simple Dec 28 12:53:40 volumiopi volumio[968]: info: Collecting git+https://github.com/HEnquist/pycamilladsp-plot.git@v1.0.2 Dec 28 12:53:40 volumiopi volumio[968]: info: Cloning https://github.com/HEnquist/pycamilladsp-plot.git (to revision v1.0.2) to /tmp/pip-req-build-55658fak Dec 28 12:53:40 volumiopi systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 12:53:40 volumiopi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 417. Dec 28 12:53:40 volumiopi systemd[1]: Stopped go-librespot Daemon. Dec 28 12:53:40 volumiopi systemd[1]: Started go-librespot Daemon. Dec 28 12:53:40 volumiopi go-librespot[8951]: go-librespot daemon starting... Dec 28 12:53:41 volumiopi go-librespot[8951]: time="2025-12-28T12:53:41+08:00" level=info msg="running go-librespot 0.4.0" Dec 28 12:53:41 volumiopi go-librespot[8951]: time="2025-12-28T12:53:41+08:00" level=debug msg="app state loaded" Dec 28 12:53:41 volumiopi go-librespot[8951]: time="2025-12-28T12:53:41+08:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 28 12:53:41 volumiopi go-librespot[8951]: time="2025-12-28T12:53:41+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 28 12:53:41 volumiopi go-librespot[8951]: time="2025-12-28T12:53:41+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 28 12:53:41 volumiopi go-librespot[8951]: time="2025-12-28T12:53:41+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 28 12:53:41 volumiopi go-librespot[8951]: time="2025-12-28T12:53:41+08:00" level=info msg="zeroconf server listening on port 33299" Dec 28 12:53:41 volumiopi go-librespot[8951]: time="2025-12-28T12:53:41+08:00" level=debug msg="obtained new client token: AABUkuiK5fXxhu7q8rsXTIu8vMUWwrfuZ/cocLUu5nYFTuGGg/SM0k/m2Yv6RhzoMFg/75NUbyq+tYZVZd8Mqcgz2GNM1RSmrGIkxt9nTWSIO/PgNqaF1Tsl2olmZuDFjhhfv+N66S8ysSP3G48E1dxI4SqET+IJuj44I/oeGSCHJi545kW6qvU3TuWeoqVnU+LNXuyVrzgC4yUAtOYQ2/V+JZ4s2p5U/FOEpgQl93LuNtcckuP2WBkyIw==" Dec 28 12:53:41 volumiopi go-librespot[8951]: time="2025-12-28T12:53:41+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 28 12:53:41 volumiopi go-librespot[8951]: time="2025-12-28T12:53:41+08:00" level=debug msg="completed keyexchange" Dec 28 12:53:41 volumiopi go-librespot[8951]: time="2025-12-28T12:53:41+08:00" level=debug msg="completed challenge" Dec 28 12:53:41 volumiopi go-librespot[8951]: time="2025-12-28T12:53:41+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 28 12:53:41 volumiopi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 12:53:41 volumiopi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 12:53:42 volumiopi volumio[968]: info: Initializing connection to go-librespot Websocket Dec 28 12:53:42 volumiopi volumio[968]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 12:53:43 volumiopi volumio[968]: info: Requirement already satisfied (use --upgrade to upgrade): camilladsp-plot==1.0.2 from git+https://github.com/HEnquist/pycamilladsp-plot.git@v1.0.2 in /usr/local/lib/python3.7/dist-packages Dec 28 12:53:43 volumiopi volumio[968]: info: Requirement already satisfied: PyYAML in /usr/local/lib/python3.7/dist-packages (from camilladsp-plot==1.0.2) (6.0.1) Dec 28 12:53:43 volumiopi volumio[968]: info: Requirement already satisfied: jsonschema in /usr/local/lib/python3.7/dist-packages (from camilladsp-plot==1.0.2) (4.17.3) Dec 28 12:53:43 volumiopi volumio[968]: info: Requirement already satisfied: attrs>=17.4.0 in /usr/lib/python3/dist-packages (from jsonschema->camilladsp-plot==1.0.2) (18.2.0) Dec 28 12:53:43 volumiopi volumio[968]: info: Requirement already satisfied: typing-extensions; python_version < "3.8" in /usr/local/lib/python3.7/dist-packages (from jsonschema->camilladsp-plot==1.0.2) (4.7.1) Dec 28 12:53:43 volumiopi volumio[968]: info: Requirement already satisfied: importlib-resources>=1.4.0; python_version < "3.9" in /usr/local/lib/python3.7/dist-packages (from jsonschema->camilladsp-plot==1.0.2) (5.12.0) Dec 28 12:53:43 volumiopi volumio[968]: info: Requirement already satisfied: pyrsistent!=0.17.0,!=0.17.1,!=0.17.2,>=0.14.0 in /usr/local/lib/python3.7/dist-packages (from jsonschema->camilladsp-plot==1.0.2) (0.19.3) Dec 28 12:53:43 volumiopi volumio[968]: info: Requirement already satisfied: pkgutil-resolve-name>=1.3.10; python_version < "3.9" in /usr/local/lib/python3.7/dist-packages (from jsonschema->camilladsp-plot==1.0.2) (1.3.10) Dec 28 12:53:43 volumiopi volumio[968]: info: Requirement already satisfied: importlib-metadata; python_version < "3.8" in /usr/local/lib/python3.7/dist-packages (from jsonschema->camilladsp-plot==1.0.2) (6.7.0) Dec 28 12:53:44 volumiopi volumio[968]: info: Requirement already satisfied: zipp>=3.1.0; python_version < "3.10" in /usr/local/lib/python3.7/dist-packages (from importlib-resources>=1.4.0; python_version < "3.9"->jsonschema->camilladsp-plot==1.0.2) (3.15.0) Dec 28 12:53:44 volumiopi volumio[968]: info: Building wheels for collected packages: camilladsp-plot Dec 28 12:53:44 volumiopi volumio[968]: info: Running setup.py bdist_wheel for camilladsp-plot: started Dec 28 12:53:44 volumiopi systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 12:53:44 volumiopi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 418. Dec 28 12:53:44 volumiopi systemd[1]: Stopped go-librespot Daemon. Dec 28 12:53:45 volumiopi systemd[1]: Started go-librespot Daemon. Dec 28 12:53:45 volumiopi go-librespot[8990]: go-librespot daemon starting... Dec 28 12:53:45 volumiopi go-librespot[8990]: time="2025-12-28T12:53:45+08:00" level=info msg="running go-librespot 0.4.0" Dec 28 12:53:45 volumiopi go-librespot[8990]: time="2025-12-28T12:53:45+08:00" level=debug msg="app state loaded" Dec 28 12:53:45 volumiopi go-librespot[8990]: time="2025-12-28T12:53:45+08:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 28 12:53:45 volumiopi volumio[968]: info: Initializing connection to go-librespot Websocket Dec 28 12:53:45 volumiopi go-librespot[8990]: time="2025-12-28T12:53:45+08:00" level=debug msg="new websocket client" Dec 28 12:53:45 volumiopi volumio[968]: info: Connection to go-librespot Websocket established Dec 28 12:53:45 volumiopi go-librespot[8990]: time="2025-12-28T12:53:45+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 28 12:53:45 volumiopi go-librespot[8990]: time="2025-12-28T12:53:45+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 28 12:53:45 volumiopi go-librespot[8990]: time="2025-12-28T12:53:45+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 28 12:53:45 volumiopi go-librespot[8990]: time="2025-12-28T12:53:45+08:00" level=info msg="zeroconf server listening on port 37069" Dec 28 12:53:45 volumiopi go-librespot[8990]: time="2025-12-28T12:53:45+08:00" level=debug msg="obtained new client token: AAAXJfVnbTDgSwAygosupU5Hm5AXI/iHjAHLogEd/N5r0n97cARnXaAaofxICFvn8YFKuFr3GbdA7sAv/K1S4z299TIhQqruMEK64zLPUTTNml42qLEuc13mNP/X8Ij0wJIXNJgGdwSltMi8AWqcAYjlBDdEc8PbczS3Zm68r9JYi8ottR1hp+XdE0IINalVMyuJQ0g5ij/Fd9Ruua99h0fGQcPBIPuCrKOk4AXl0U3GcL4skJV4vP0gLw==" Dec 28 12:53:45 volumiopi go-librespot[8990]: time="2025-12-28T12:53:45+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 28 12:53:45 volumiopi go-librespot[8990]: time="2025-12-28T12:53:45+08:00" level=debug msg="completed keyexchange" Dec 28 12:53:45 volumiopi go-librespot[8990]: time="2025-12-28T12:53:45+08:00" level=debug msg="completed challenge" Dec 28 12:53:45 volumiopi go-librespot[8990]: time="2025-12-28T12:53:45+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 28 12:53:45 volumiopi volumio[968]: info: Connection to go-librespot Websocket closed Dec 28 12:53:45 volumiopi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 12:53:45 volumiopi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 12:53:45 volumiopi volumio[968]: info: Running setup.py bdist_wheel for camilladsp-plot: finished with status 'done' Dec 28 12:53:46 volumiopi volumio[968]: info: Stored in directory: /tmp/pip-ephem-wheel-cache-uip4fdlj/wheels/11/e1/43/8275af2f537d569c7097d202b4955f9aec629859be39dab2e9 Dec 28 12:53:46 volumiopi volumio[968]: info: Successfully built camilladsp-plot Dec 28 12:53:46 volumiopi volumio[968]: info: copying hw detection script Dec 28 12:53:46 volumiopi volumio[968]: info: Detected cpu architecture as armv7l Dec 28 12:53:46 volumiopi volumio[968]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/fusiondsp/volumio/buster/armhf Dec 28 12:53:48 volumiopi volumio[968]: info: Getting Spotify volume Dec 28 12:53:48 volumiopi volumio[968]: (node:968) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 12:53:48 volumiopi volumio[968]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 28 12:53:48 volumiopi volumio[968]: (node:968) 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: 80) Dec 28 12:53:48 volumiopi volumio[968]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Dec 28 12:53:48 volumiopi volumio[968]: info: CoreCommandRouter::volumioGetState Dec 28 12:53:48 volumiopi volumio[968]: info: CorePlayQueue::getTrack 0 Dec 28 12:53:48 volumiopi volumio[968]: info: Initializing connection to go-librespot Websocket Dec 28 12:53:48 volumiopi volumio[968]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 28 12:53:48 volumiopi systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 28 12:53:48 volumiopi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 419. Dec 28 12:53:48 volumiopi systemd[1]: Stopped go-librespot Daemon. Dec 28 12:53:49 volumiopi systemd[1]: Started go-librespot Daemon. Dec 28 12:53:49 volumiopi go-librespot[9008]: go-librespot daemon starting... Dec 28 12:53:49 volumiopi go-librespot[9008]: time="2025-12-28T12:53:49+08:00" level=info msg="running go-librespot 0.4.0" Dec 28 12:53:49 volumiopi go-librespot[9008]: time="2025-12-28T12:53:49+08:00" level=debug msg="app state loaded" Dec 28 12:53:49 volumiopi go-librespot[9008]: time="2025-12-28T12:53:49+08:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 28 12:53:49 volumiopi sudo[9020]: root : TTY=unknown ; PWD=/tmp ; USER=root ; COMMAND=/bin/cp /data/plugins/audio_interface/fusiondsp/c/hw_params_arm /data/plugins/audio_interface/fusiondsp/hw_params Dec 28 12:53:49 volumiopi sudo[9020]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 12:53:49 volumiopi sudo[9020]: pam_unix(sudo:session): session closed for user root Dec 28 12:53:49 volumiopi sudo[9022]: root : TTY=unknown ; PWD=/tmp ; USER=root ; COMMAND=/bin/chmod +x /data/plugins/audio_interface/fusiondsp/hw_params Dec 28 12:53:49 volumiopi sudo[9022]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 12:53:49 volumiopi sudo[9022]: pam_unix(sudo:session): session closed for user root Dec 28 12:53:49 volumiopi sudo[9024]: root : TTY=unknown ; PWD=/tmp ; USER=root ; COMMAND=/usr/bin/apt-get -y install drc Dec 28 12:53:49 volumiopi sudo[9024]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 12:53:49 volumiopi volumio[968]: info: Reading package lists... Dec 28 12:53:50 volumiopi go-librespot[9008]: time="2025-12-28T12:53:50+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 28 12:53:50 volumiopi go-librespot[9008]: time="2025-12-28T12:53:50+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 28 12:53:50 volumiopi go-librespot[9008]: time="2025-12-28T12:53:50+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 28 12:53:50 volumiopi go-librespot[9008]: time="2025-12-28T12:53:50+08:00" level=info msg="zeroconf server listening on port 44965" Dec 28 12:53:50 volumiopi volumio[968]: info: Building dependency tree... Dec 28 12:53:50 volumiopi volumio[968]: info: Reading state information... Dec 28 12:53:51 volumiopi go-librespot[9008]: time="2025-12-28T12:53:51+08:00" level=debug msg="obtained new client token: AABb2hr/ENVt9Y6rSmuZnbvwvW+7ozggGCdgzKTAIT5XF+cZnmHrmRiVTYLlZlPAihsfVtrEOPAZ/eWEkkNAaucUm4zKHFcjjzKSkkSl+bEn/0Dww9kkEBrd+4apnaovS36FypvBp5S5hIFKwq1flpl52w0zURyGLBxy7FpGq6dVdIqT5e2d4fPBXVB81sehPESi8tN5A9okPO3O3mYbmAm6CCTAUegh4eNOiCVn8JUU84n/hrG+u07dwA==" Dec 28 12:53:51 volumiopi volumio[968]: info: Initializing connection to go-librespot Websocket Dec 28 12:53:51 volumiopi go-librespot[9008]: time="2025-12-28T12:53:51+08:00" level=debug msg="new websocket client" Dec 28 12:53:51 volumiopi volumio[968]: info: Connection to go-librespot Websocket established Dec 28 12:53:51 volumiopi go-librespot[9008]: time="2025-12-28T12:53:51+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 28 12:53:52 volumiopi go-librespot[9008]: time="2025-12-28T12:53:52+08:00" level=debug msg="completed keyexchange" Dec 28 12:53:52 volumiopi go-librespot[9008]: time="2025-12-28T12:53:52+08:00" level=debug msg="completed challenge" Dec 28 12:53:52 volumiopi sudo[9024]: pam_unix(sudo:session): session closed for user root Dec 28 12:53:52 volumiopi volumio[968]: info: drc is already the newest version (3.2.2~dfsg0-2). Dec 28 12:53:52 volumiopi sudo[8338]: pam_unix(sudo:session): session closed for user root Dec 28 12:53:52 volumiopi volumio[968]: info: 0 upgraded, 0 newly installed, 0 to remove and 2 not upgraded. Dec 28 12:53:52 volumiopi volumio[968]: info: Install script completed Dec 28 12:53:52 volumiopi volumio[968]: info: Done installing plugin. Dec 28 12:53:52 volumiopi volumio[968]: info: Enabling plugin fusiondsp Dec 28 12:53:52 volumiopi volumio[968]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 28 12:53:52 volumiopi volumio[968]: info: [{"prettyName":"FusionDsp","name":"fusiondsp","category":"audio_interface","version":"1.0.62","icon":"fa-sliders fa-rotate-90","isManuallyInstalled":false,"enabled":true,"active":false},{"prettyName":"Spotify","name":"spop","category":"music_service","version":"4.3.0","icon":"fa-spotify","isManuallyInstalled":false,"enabled":true,"active":true}] Dec 28 12:53:52 volumiopi volumio[968]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 28 12:53:52 volumiopi go-librespot[9008]: time="2025-12-28T12:53:52+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 28 12:53:52 volumiopi volumio[968]: info: Folder /tmp/plugins removed Dec 28 12:53:52 volumiopi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 28 12:53:52 volumiopi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 28 12:53:52 volumiopi volumio[968]: Plugin install end detected on script Dec 28 12:53:52 volumiopi volumio[968]: info: Folder /data/temp removed Dec 28 12:53:52 volumiopi volumio[968]: info: Folder /tmp/downloaded_plugin.zip removed Dec 28 12:53:52 volumiopi volumio[968]: info: Connection to go-librespot Websocket closed Dec 28 12:53:53 volumiopi volumio[968]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/fusiondsp/volumio/buster/armhf Dec 28 12:53:53 volumiopi volumio[968]: info: FusionDsp - Stopping FusionDsp service Dec 28 12:53:53 volumiopi volumio[968]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 28 12:53:53 volumiopi volumio[968]: TypeError: Cannot read property 'stop' of null Dec 28 12:53:53 volumiopi volumio[968]: at FusionDsp.onStop (/data/plugins/audio_interface/fusiondsp/index.js:109:23) Dec 28 12:53:53 volumiopi volumio[968]: at PluginManager.stopPlugin (/volumio/app/pluginmanager.js:460:30) Dec 28 12:53:53 volumiopi volumio[968]: at /volumio/app/pluginmanager.js:956:12 Dec 28 12:53:53 volumiopi volumio[968]: at ChildProcess.exithandler (child_process.js:299:7) Dec 28 12:53:53 volumiopi volumio[968]: at ChildProcess.emit (events.js:315:20) Dec 28 12:53:53 volumiopi volumio[968]: at maybeClose (internal/child_process.js:1048:16) Dec 28 12:53:53 volumiopi volumio[968]: at Process.ChildProcess._handle.onexit (internal/child_process.js:288:5) Dec 28 12:53:53 volumiopi volumio[968]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 28 12:53:53 volumiopi sudo[9054]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-28 12:52 Dec 28 12:53:53 volumiopi sudo[9054]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b43c85cc0006d3f1efecba101311ec96e334d1fd" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 11 Dec 2025 05:43:24 PM CET" VOLUMIO_VERSION="3.886" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="15d0241b0cd805792809f3ddf4a0fc4e"