-- Logs begin at Sun 2026-04-12 10:29:14 UTC, end at Sun 2026-04-12 12:40:44 UTC. -- Apr 12 12:39:00 volumio go-librespot[29993]: time="2026-04-12T12:39:00Z" level=debug msg="completed challenge" Apr 12 12:39:00 volumio go-librespot[29993]: time="2026-04-12T12:39:00Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 12 12:39:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 12:39:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 12:39:00 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Apr 12 12:39:00 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 12 12:39:00 volumio volumio[863]: info: Received Get System Info Apr 12 12:39:00 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 12:39:00 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 12:39:00 volumio volumio[863]: info: Discovery: Getting this device information Apr 12 12:39:00 volumio volumio[863]: info: CoreCommandRouter::volumioGetState Apr 12 12:39:00 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 12:39:00 volumio volumio[863]: info: Initializing connection to go-librespot Websocket Apr 12 12:39:00 volumio volumio[863]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 12 12:39:01 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 12 12:39:01 volumio volumio[863]: info: Received Get System Info Apr 12 12:39:01 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 12:39:01 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 12:39:01 volumio volumio[863]: info: Discovery: Getting this device information Apr 12 12:39:01 volumio volumio[863]: info: CoreCommandRouter::volumioGetState Apr 12 12:39:01 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 12:39:01 volumio volumio[863]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 12 12:39:02 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 12 12:39:02 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 12:39:02 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 12 12:39:02 volumio volumio[863]: Invalid card number. Apr 12 12:39:02 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 12 12:39:02 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 12 12:39:02 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 12 12:39:02 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 12 12:39:02 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 12 12:39:02 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 12 12:39:02 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 12 12:39:02 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Apr 12 12:39:02 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 12 12:39:03 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 12 12:39:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 124363. Apr 12 12:39:03 volumio systemd[1]: Stopped go-librespot Daemon. Apr 12 12:39:03 volumio systemd[1]: Started go-librespot Daemon. Apr 12 12:39:03 volumio go-librespot[30019]: Librespot-go daemon starting... Apr 12 12:39:03 volumio go-librespot[30019]: time="2026-04-12T12:39:03Z" level=info msg="generated new device id: ffa7c318af3b09f396a06141c8d1ef79f718894f" Apr 12 12:39:03 volumio go-librespot[30019]: time="2026-04-12T12:39:03Z" level=debug msg="stored credentials found for 31mvnzn5yiy6ejh4emnlwctzi2mi" Apr 12 12:39:03 volumio volumio[863]: info: Initializing connection to go-librespot Websocket Apr 12 12:39:03 volumio go-librespot[30019]: time="2026-04-12T12:39:03Z" level=debug msg="new websocket client" Apr 12 12:39:03 volumio volumio[863]: info: Connection to go-librespot Websocket established Apr 12 12:39:03 volumio go-librespot[30019]: time="2026-04-12T12:39:03Z" level=debug msg="obtained new client token: AAB4t18WD4D5U3XIKM98x0wGuMJVABN0K5FHU1KLZyg+soiLbmjovgTEqXQRq/UB8JKHzqnwTLjmYAhrPeDzqJ/QlWLRp4OolWlAUs84O7azH8OPpf9p0VhV/1zSTbRCCrbx3A5bYILZWQixKYHHe8y5ZSIm2Z01Oyg6/sL2LUuhVY27vF0b9D3PQLOI6Db2fSOuz+meblHyR2CJNqMxWp6e1Dlhj9No0jvCw6VU0aKYIVBsQGljmw4qs7zJ1C4=" Apr 12 12:39:03 volumio go-librespot[30019]: time="2026-04-12T12:39:03Z" 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]" Apr 12 12:39:03 volumio go-librespot[30019]: time="2026-04-12T12:39:03Z" level=debug msg="completed keyexchange" Apr 12 12:39:04 volumio go-librespot[30019]: time="2026-04-12T12:39:04Z" level=debug msg="completed challenge" Apr 12 12:39:04 volumio go-librespot[30019]: time="2026-04-12T12:39:04Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 12 12:39:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 12:39:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 12:39:04 volumio volumio[863]: info: Connection to go-librespot Websocket closed Apr 12 12:39:06 volumio volumio[863]: info: Getting Spotify volume Apr 12 12:39:06 volumio volumio[863]: (node:863) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 12 12:39:06 volumio volumio[863]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 12 12:39:06 volumio volumio[863]: (node:863) 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: 40889) Apr 12 12:39:06 volumio volumio[863]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Apr 12 12:39:06 volumio volumio[863]: info: CoreCommandRouter::volumioGetState Apr 12 12:39:07 volumio volumio[863]: info: Initializing connection to go-librespot Websocket Apr 12 12:39:07 volumio volumio[863]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 12 12:39:07 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 12 12:39:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 124364. Apr 12 12:39:07 volumio systemd[1]: Stopped go-librespot Daemon. Apr 12 12:39:07 volumio systemd[1]: Started go-librespot Daemon. Apr 12 12:39:07 volumio go-librespot[30028]: Librespot-go daemon starting... Apr 12 12:39:07 volumio go-librespot[30028]: time="2026-04-12T12:39:07Z" level=info msg="generated new device id: e92f763800e280c3f3e49c0423b0653488785397" Apr 12 12:39:07 volumio go-librespot[30028]: time="2026-04-12T12:39:07Z" level=debug msg="stored credentials found for 31mvnzn5yiy6ejh4emnlwctzi2mi" Apr 12 12:39:07 volumio go-librespot[30028]: time="2026-04-12T12:39:07Z" level=debug msg="obtained new client token: AABQeVJYcW8J0RoreUFaAbAijLyygnFNcT8k5exyiz5NhKXdPdxN2Qi29RpFt3FjmxjzXGYYYTclXf8Vyva+3MHif++Gwl0NhjESYnxP8Q7MS0t4cEjsTSng+o2Zaw0jpCJJQt2b9dI5bkzPP7SXIAl8zCqZArNHbKYAIvOJvvN/QZzQoY++LL/i+4OPLO/ib/ce6FToEspxo9Xdp73z5JEfhb3UiPPT2UaNNCVXCDk/uQDiAuUxRBrXQYHgETY=" Apr 12 12:39:07 volumio go-librespot[30028]: time="2026-04-12T12:39:07Z" 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]" Apr 12 12:39:08 volumio go-librespot[30028]: time="2026-04-12T12:39:08Z" level=debug msg="completed keyexchange" Apr 12 12:39:08 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Apr 12 12:39:08 volumio go-librespot[30028]: time="2026-04-12T12:39:08Z" level=debug msg="completed challenge" Apr 12 12:39:08 volumio go-librespot[30028]: time="2026-04-12T12:39:08Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 12 12:39:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 12:39:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 12:39:10 volumio volumio[863]: info: Initializing connection to go-librespot Websocket Apr 12 12:39:10 volumio volumio[863]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 12 12:39:10 volumio volumio[863]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 12 12:39:10 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 12 12:39:10 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Apr 12 12:39:10 volumio sudo[30054]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Apr 12 12:39:10 volumio sudo[30054]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 12:39:10 volumio sudo[30060]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Apr 12 12:39:10 volumio sudo[30060]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 12:39:10 volumio sudo[30054]: pam_unix(sudo:session): session closed for user root Apr 12 12:39:10 volumio sudo[30060]: pam_unix(sudo:session): session closed for user root Apr 12 12:39:10 volumio sudo[30067]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Apr 12 12:39:10 volumio sudo[30067]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 12:39:10 volumio sudo[30067]: pam_unix(sudo:session): session closed for user root Apr 12 12:39:11 volumio sudo[30074]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Apr 12 12:39:11 volumio sudo[30074]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 12:39:11 volumio sudo[30074]: pam_unix(sudo:session): session closed for user root Apr 12 12:39:11 volumio sudo[30079]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 12 12:39:11 volumio sudo[30079]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 12:39:11 volumio sudo[30079]: pam_unix(sudo:session): session closed for user root Apr 12 12:39:11 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Apr 12 12:39:11 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Apr 12 12:39:11 volumio sudo[30083]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 12 12:39:11 volumio sudo[30083]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 12:39:11 volumio sudo[30083]: pam_unix(sudo:session): session closed for user root Apr 12 12:39:11 volumio sudo[30086]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 12 12:39:11 volumio sudo[30086]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 12:39:11 volumio sudo[30086]: pam_unix(sudo:session): session closed for user root Apr 12 12:39:12 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 12 12:39:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 124365. Apr 12 12:39:12 volumio systemd[1]: Stopped go-librespot Daemon. Apr 12 12:39:12 volumio systemd[1]: Started go-librespot Daemon. Apr 12 12:39:12 volumio go-librespot[30088]: Librespot-go daemon starting... Apr 12 12:39:12 volumio go-librespot[30088]: time="2026-04-12T12:39:12Z" level=info msg="generated new device id: f6a566f46bd8209b39d6ae046cda336e85c95e25" Apr 12 12:39:12 volumio go-librespot[30088]: time="2026-04-12T12:39:12Z" level=debug msg="stored credentials found for 31mvnzn5yiy6ejh4emnlwctzi2mi" Apr 12 12:39:12 volumio volumio[863]: info: Received Get System Info Apr 12 12:39:12 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 12:39:12 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 12:39:12 volumio volumio[863]: info: Discovery: Getting this device information Apr 12 12:39:12 volumio volumio[863]: info: CoreCommandRouter::volumioGetState Apr 12 12:39:12 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 12:39:12 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 12 12:39:12 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 12 12:39:12 volumio go-librespot[30088]: time="2026-04-12T12:39:12Z" level=debug msg="obtained new client token: AAApFiBEyJXBvWkzLzjPIZLQSXl29pn0Hg0Iv5qfaGajZ/Bicu0nlBpPvm66U4TgEih5owgmD4NqgG3CdI74przxpvnmQI//Uxl34lmX98vBif89XDpLmBpT6xPWRhWMdLxCzHl+pOrwE2YPUnsoCfuO2GCwmQVJvAYKKrGnsjwgggZFXNqxt15AtIkAnsDiJ2lfmagC4oY5zx7d8YXILHAe6IIuhfaz6CWHyvpNSzE34tnH5Eg6Y0oZz+SwcxY=" Apr 12 12:39:12 volumio go-librespot[30088]: time="2026-04-12T12:39:12Z" 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]" Apr 12 12:39:12 volumio go-librespot[30088]: time="2026-04-12T12:39:12Z" level=debug msg="completed keyexchange" Apr 12 12:39:13 volumio volumio5-onboarding[1421]: time=2026-04-12T12:39:13.127Z level=INFO msg="service successfully established" component=discovery/localnet Apr 12 12:39:13 volumio go-librespot[30088]: time="2026-04-12T12:39:13Z" level=debug msg="completed challenge" Apr 12 12:39:13 volumio go-librespot[30088]: time="2026-04-12T12:39:13Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 12 12:39:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 12:39:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 12:39:13 volumio volumio[863]: info: Initializing connection to go-librespot Websocket Apr 12 12:39:13 volumio volumio[863]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 12 12:39:16 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 12 12:39:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 124366. Apr 12 12:39:16 volumio systemd[1]: Stopped go-librespot Daemon. Apr 12 12:39:16 volumio systemd[1]: Started go-librespot Daemon. Apr 12 12:39:16 volumio go-librespot[30096]: Librespot-go daemon starting... Apr 12 12:39:16 volumio go-librespot[30096]: time="2026-04-12T12:39:16Z" level=info msg="generated new device id: a6299a307d0b33a4128afe0d4df16c908c965498" Apr 12 12:39:16 volumio go-librespot[30096]: time="2026-04-12T12:39:16Z" level=debug msg="stored credentials found for 31mvnzn5yiy6ejh4emnlwctzi2mi" Apr 12 12:39:16 volumio volumio[863]: info: Initializing connection to go-librespot Websocket Apr 12 12:39:16 volumio go-librespot[30096]: time="2026-04-12T12:39:16Z" level=debug msg="new websocket client" Apr 12 12:39:16 volumio volumio[863]: info: Connection to go-librespot Websocket established Apr 12 12:39:16 volumio go-librespot[30096]: time="2026-04-12T12:39:16Z" level=debug msg="obtained new client token: AACH9g9js14pZGZAe7uK5co8Hqh0S59+5vrSBUr3BJBa8681uCkvIBbO8+/TdfezMzGeGOxIeHNI7tj6248ugRqH0c9Tb9t1j3nBASGYpmYZSvqp0moqRWBqg5TH5dw0mDl1m3L3ZE2OlGUbMthvj2ukGnmEMrZGWzLWnB9OY7hqNg4L/9UXibXXGw3Mmom2WBpFlzv4E5H2zO2sC4zpMMPqBSuECR7iemcy98skS5q+f9KtKOGfaKBX4qCw8L0=" Apr 12 12:39:16 volumio go-librespot[30096]: time="2026-04-12T12:39:16Z" 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]" Apr 12 12:39:16 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 12 12:39:16 volumio volumio[863]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Apr 12 12:39:16 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Apr 12 12:39:16 volumio volumio[863]: info: Received Get System Version Apr 12 12:39:16 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 12 12:39:16 volumio volumio[863]: info: Received Get System Info Apr 12 12:39:16 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 12:39:16 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 12:39:16 volumio volumio[863]: info: Discovery: Getting this device information Apr 12 12:39:16 volumio volumio[863]: info: CoreCommandRouter::volumioGetState Apr 12 12:39:16 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 12:39:16 volumio go-librespot[30096]: time="2026-04-12T12:39:16Z" level=debug msg="completed keyexchange" Apr 12 12:39:17 volumio go-librespot[30096]: time="2026-04-12T12:39:17Z" level=debug msg="completed challenge" Apr 12 12:39:17 volumio go-librespot[30096]: time="2026-04-12T12:39:17Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 12 12:39:17 volumio volumio[863]: info: Connection to go-librespot Websocket closed Apr 12 12:39:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 12:39:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 12:39:19 volumio volumio[863]: info: Getting Spotify volume Apr 12 12:39:19 volumio volumio[863]: (node:863) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 12 12:39:19 volumio volumio[863]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 12 12:39:19 volumio volumio[863]: (node:863) 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: 40890) Apr 12 12:39:19 volumio volumio[863]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Apr 12 12:39:19 volumio volumio[863]: info: CoreCommandRouter::volumioGetState Apr 12 12:39:20 volumio volumio[863]: info: Initializing connection to go-librespot Websocket Apr 12 12:39:20 volumio volumio[863]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 12 12:39:20 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 12 12:39:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 124367. Apr 12 12:39:20 volumio systemd[1]: Stopped go-librespot Daemon. Apr 12 12:39:20 volumio systemd[1]: Started go-librespot Daemon. Apr 12 12:39:20 volumio go-librespot[30118]: Librespot-go daemon starting... Apr 12 12:39:20 volumio go-librespot[30118]: time="2026-04-12T12:39:20Z" level=info msg="generated new device id: 37151cb8e81292cc9a1b32dfc13ed62ffc2e35f1" Apr 12 12:39:20 volumio go-librespot[30118]: time="2026-04-12T12:39:20Z" level=debug msg="stored credentials found for 31mvnzn5yiy6ejh4emnlwctzi2mi" Apr 12 12:39:20 volumio go-librespot[30118]: time="2026-04-12T12:39:20Z" level=debug msg="obtained new client token: AAD/e8p6Y28XG6uM1qBVG9CpDIsUB3Mc7A/n9XOR4gU7viwOiZp+q5wRFJiTJ/T5GuDO7+C+ZyQUmW02LSSwiZ3Cb/pkCGp0frhq+l/B384Avpq4JPHXRAZ7XR9KDEmlSsdysYyj8UTuSO8nMictjgXgDfQp15L4XtyGBL7RBlWzpgqISnFE6LmmDhxQXBSoK6xxxBppcXaMUw1AL0QsowPjJ3G9nNefNaqGftbK0KUWUrq167FZ6wwtaH7pnZ0=" Apr 12 12:39:20 volumio go-librespot[30118]: time="2026-04-12T12:39:20Z" 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]" Apr 12 12:39:21 volumio go-librespot[30118]: time="2026-04-12T12:39:21Z" level=debug msg="completed keyexchange" Apr 12 12:39:22 volumio go-librespot[30118]: time="2026-04-12T12:39:22Z" level=debug msg="completed challenge" Apr 12 12:39:22 volumio go-librespot[30118]: time="2026-04-12T12:39:22Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 12 12:39:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 12:39:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 12:39:23 volumio volumio[863]: info: Initializing connection to go-librespot Websocket Apr 12 12:39:23 volumio volumio[863]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 12 12:39:25 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 12 12:39:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 124368. Apr 12 12:39:25 volumio systemd[1]: Stopped go-librespot Daemon. Apr 12 12:39:25 volumio systemd[1]: Started go-librespot Daemon. Apr 12 12:39:25 volumio go-librespot[30127]: Librespot-go daemon starting... Apr 12 12:39:25 volumio go-librespot[30127]: time="2026-04-12T12:39:25Z" level=info msg="generated new device id: 2bdbdd5a53eb38a9725bd85d3f2a6a30f9e886e9" Apr 12 12:39:25 volumio go-librespot[30127]: time="2026-04-12T12:39:25Z" level=debug msg="stored credentials found for 31mvnzn5yiy6ejh4emnlwctzi2mi" Apr 12 12:39:25 volumio go-librespot[30127]: time="2026-04-12T12:39:25Z" level=debug msg="obtained new client token: AABnrpNI9zjCEbj9pYKjPb2fe/bkHNW1gDZs5lNyEywuGtggZtKcRmob11cI2t/v1GHStBSIe9gdsfBS6VbkCOAsnHERANA2hk+QHlLZD+OdeUPcscxhqytg8h2f2Ob00l/LxueaHw8yeBFNJIprtSqILCbPkdlPe2IoGiUicPjA4BpfIh/ptRuwaNIel3ZR9SyZ25Op9Rp3OFHoKWnyTDGbjBK+eWceKsfftrkSr0fcZF3IXpGUDiHRGOIEH3g=" Apr 12 12:39:25 volumio go-librespot[30127]: time="2026-04-12T12:39:25Z" 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]" Apr 12 12:39:25 volumio go-librespot[30127]: time="2026-04-12T12:39:25Z" level=debug msg="completed keyexchange" Apr 12 12:39:26 volumio go-librespot[30127]: time="2026-04-12T12:39:26Z" level=debug msg="completed challenge" Apr 12 12:39:26 volumio go-librespot[30127]: time="2026-04-12T12:39:26Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 12 12:39:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 12:39:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 12:39:26 volumio volumio[863]: info: Initializing connection to go-librespot Websocket Apr 12 12:39:26 volumio volumio[863]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 12 12:39:29 volumio volumio[863]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 12 12:39:29 volumio volumio[863]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 12 12:39:29 volumio volumio[863]: info: Retrieving Cloud Streaming UI Apr 12 12:39:29 volumio volumio[863]: info: Getting Tidal Cloud Configuration Apr 12 12:39:29 volumio volumio[863]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 12 12:39:29 volumio volumio[863]: info: Getting Qobuz Cloud Configuration Apr 12 12:39:29 volumio volumio[863]: info: Asking plugin for UI Config Apr 12 12:39:29 volumio volumio[863]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 12 12:39:29 volumio volumio[863]: info: Getting Spotify Cloud Configuration Apr 12 12:39:29 volumio volumio[863]: info: Asking plugin for UI Config Apr 12 12:39:29 volumio volumio[863]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 12 12:39:29 volumio volumio[863]: info: Saving Spotify Acccount Apr 12 12:39:29 volumio volumio[863]: info: Got Tidal Cloud Configuration Apr 12 12:39:29 volumio volumio[863]: info: Got it Apr 12 12:39:29 volumio volumio[863]: info: Got it Apr 12 12:39:29 volumio volumio[863]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Apr 12 12:39:29 volumio volumio[863]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 12 12:39:29 volumio volumio[863]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Apr 12 12:39:29 volumio volumio[863]: info: Initializing connection to go-librespot Websocket Apr 12 12:39:29 volumio volumio[863]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 12 12:39:29 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 12 12:39:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 124369. Apr 12 12:39:29 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 12 12:39:29 volumio systemd[1]: Stopped go-librespot Daemon. Apr 12 12:39:29 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Apr 12 12:39:29 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Apr 12 12:39:29 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Apr 12 12:39:29 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 12 12:39:29 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 12 12:39:29 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 12 12:39:29 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 12 12:39:29 volumio volumio[863]: info: CoreCommandRouter::volumioGetBrowseSources Apr 12 12:39:29 volumio volumio[863]: info: CoreCommandRouter::volumioGetBrowseSources Apr 12 12:39:29 volumio volumio[863]: info: CoreCommandRouter::volumioGetBrowseSources Apr 12 12:39:29 volumio systemd[1]: Started go-librespot Daemon. Apr 12 12:39:29 volumio go-librespot[30136]: Librespot-go daemon starting... Apr 12 12:39:29 volumio go-librespot[30136]: time="2026-04-12T12:39:29Z" level=info msg="generated new device id: b9e7befcc3a096861ac90d4919f6bb38407bfef3" Apr 12 12:39:29 volumio go-librespot[30136]: time="2026-04-12T12:39:29Z" level=debug msg="stored credentials found for 31mvnzn5yiy6ejh4emnlwctzi2mi" Apr 12 12:39:29 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 12 12:39:29 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Apr 12 12:39:29 volumio go-librespot[30136]: time="2026-04-12T12:39:29Z" level=debug msg="obtained new client token: AACeW3we8kYS8bqCQHNV46gxkAb8KFwzG3KEFiS+fxHCso1XKLxsNoAmOimS8hvpdMmZIE6XBznYKMNjLNCBbH4SrvXUF/GFwR/C1AuSFCNmKH1irOqyi7xbjSyJ6fLnTjN1Mu5BIfNJNFh6mch8hZuHkeQOASrvLFXJ0o0r1pZZ7rT0bB/LE3FAAaifgeyRJo43dwaLLCUwwJTkHlGecARlSypgTvyEKO0Xu0FkZ48nK56EMz19AlYe1q6snLc=" Apr 12 12:39:29 volumio go-librespot[30136]: time="2026-04-12T12:39:29Z" 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]" Apr 12 12:39:30 volumio go-librespot[30136]: time="2026-04-12T12:39:30Z" level=debug msg="completed keyexchange" Apr 12 12:39:30 volumio go-librespot[30136]: time="2026-04-12T12:39:30Z" level=debug msg="completed challenge" Apr 12 12:39:30 volumio go-librespot[30136]: time="2026-04-12T12:39:30Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 12 12:39:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 12:39:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 12:39:32 volumio volumio[863]: info: Initializing connection to go-librespot Websocket Apr 12 12:39:32 volumio volumio[863]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 12 12:39:33 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 12 12:39:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 124370. Apr 12 12:39:33 volumio systemd[1]: Stopped go-librespot Daemon. Apr 12 12:39:33 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 12 12:39:33 volumio volumio[863]: info: Disabling MyMusic plugin upnp Apr 12 12:39:33 volumio systemd[1]: Started go-librespot Daemon. Apr 12 12:39:33 volumio go-librespot[30158]: Librespot-go daemon starting... Apr 12 12:39:33 volumio go-librespot[30158]: time="2026-04-12T12:39:33Z" level=info msg="generated new device id: 2bb9f483be4df11f6f99d867447d9566dce671ef" Apr 12 12:39:33 volumio go-librespot[30158]: time="2026-04-12T12:39:33Z" level=debug msg="stored credentials found for 31mvnzn5yiy6ejh4emnlwctzi2mi" Apr 12 12:39:33 volumio sudo[30161]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Apr 12 12:39:33 volumio sudo[30161]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 12:39:33 volumio systemd[1]: Stopping UPnP Renderer front-end to MPD... Apr 12 12:39:33 volumio volumio[863]: error: Upnp client error: Error: This socket has been ended by the other party Apr 12 12:39:34 volumio go-librespot[30158]: time="2026-04-12T12:39:34Z" level=debug msg="obtained new client token: AACxzXokYAWrVGsPvQidsEcu9VhFGL94l/rgUDXkgFeAJLqFEln4bhmBgR1B8Ef9fW0F9BD1GMjZ0SBnEwoaM0bvtDXIl+1OHE3Y0jLVWpGgtl4swGDv00/yWPGgAjR1EqtPM6A7YIlTwjwLA1RbY9y9gMWoYueqqMeLBCCiafSjmqbapGLq0Gg+uJsNe/EEechrKY9rpibj/SVFB08xSlCqFc9iz/6Z4rfPatY5lNGKbIm943pTBQi1cRm8" Apr 12 12:39:34 volumio go-librespot[30158]: time="2026-04-12T12:39:34Z" 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]" Apr 12 12:39:34 volumio go-librespot[30158]: time="2026-04-12T12:39:34Z" level=debug msg="completed keyexchange" Apr 12 12:39:34 volumio go-librespot[30158]: time="2026-04-12T12:39:34Z" level=debug msg="completed challenge" Apr 12 12:39:35 volumio go-librespot[30158]: time="2026-04-12T12:39:35Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 12 12:39:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 12:39:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 12:39:35 volumio volumio[863]: info: Initializing connection to go-librespot Websocket Apr 12 12:39:35 volumio volumio[863]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 12 12:39:37 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 12 12:39:38 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 12 12:39:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 124371. Apr 12 12:39:38 volumio systemd[1]: Stopped go-librespot Daemon. Apr 12 12:39:38 volumio systemd[1]: Started go-librespot Daemon. Apr 12 12:39:38 volumio go-librespot[30169]: Librespot-go daemon starting... Apr 12 12:39:38 volumio go-librespot[30169]: time="2026-04-12T12:39:38Z" level=info msg="generated new device id: a2ce62370c456f9ec4c02893279952c1fa9929b1" Apr 12 12:39:38 volumio go-librespot[30169]: time="2026-04-12T12:39:38Z" level=debug msg="stored credentials found for 31mvnzn5yiy6ejh4emnlwctzi2mi" Apr 12 12:39:38 volumio volumio[863]: info: Initializing connection to go-librespot Websocket Apr 12 12:39:38 volumio go-librespot[30169]: time="2026-04-12T12:39:38Z" level=debug msg="new websocket client" Apr 12 12:39:38 volumio volumio[863]: info: Connection to go-librespot Websocket established Apr 12 12:39:38 volumio go-librespot[30169]: time="2026-04-12T12:39:38Z" level=debug msg="obtained new client token: AABnfmB/5GhN8fEjnonHxUhZjLDS5sqbADSrSQMDwGoaMgOoyxisG1GXpj7zm0nIM4XysyBkQGQzS/wKiswB82vMCcrrONzU2uFeFRmRTpvkWF6aAGi/kl6FkwhDQxqkFuOn6R6WUuKZZpsNjEzQ0hh6SSoGkIpIhbo/wRoxekYQBmCv+juvbNBqcDI6gmYk2IOxnUCaQUT/s8bT4bDWHspIs6T4Au4qAUJNo3GzZufOPUc4KEreFO7ft1H3dM0=" Apr 12 12:39:38 volumio go-librespot[30169]: time="2026-04-12T12:39:38Z" 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]" Apr 12 12:39:38 volumio go-librespot[30169]: time="2026-04-12T12:39:38Z" level=debug msg="completed keyexchange" Apr 12 12:39:39 volumio go-librespot[30169]: time="2026-04-12T12:39:39Z" level=debug msg="completed challenge" Apr 12 12:39:39 volumio go-librespot[30169]: time="2026-04-12T12:39:39Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 12 12:39:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 12:39:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 12:39:39 volumio volumio[863]: info: Connection to go-librespot Websocket closed Apr 12 12:39:41 volumio volumio[863]: info: Getting Spotify volume Apr 12 12:39:41 volumio volumio[863]: (node:863) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 12 12:39:41 volumio volumio[863]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 12 12:39:41 volumio volumio[863]: (node:863) 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: 40891) Apr 12 12:39:41 volumio volumio[863]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Apr 12 12:39:41 volumio volumio[863]: info: CoreCommandRouter::volumioGetState Apr 12 12:39:41 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 12 12:39:42 volumio volumio[863]: info: Initializing connection to go-librespot Websocket Apr 12 12:39:42 volumio volumio[863]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 12 12:39:42 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 12 12:39:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 124372. Apr 12 12:39:42 volumio systemd[1]: Stopped go-librespot Daemon. Apr 12 12:39:42 volumio systemd[1]: Started go-librespot Daemon. Apr 12 12:39:42 volumio go-librespot[30229]: Librespot-go daemon starting... Apr 12 12:39:42 volumio go-librespot[30229]: time="2026-04-12T12:39:42Z" level=info msg="generated new device id: 16048e479a0ccd08a6ac542bbc6deda2e89c5fd1" Apr 12 12:39:42 volumio go-librespot[30229]: time="2026-04-12T12:39:42Z" level=debug msg="stored credentials found for 31mvnzn5yiy6ejh4emnlwctzi2mi" Apr 12 12:39:42 volumio go-librespot[30229]: time="2026-04-12T12:39:42Z" level=debug msg="obtained new client token: AAB42BDUd2ljH1l5PMH2GQsb9v/9rHvHL64L3yHPi85p25kO+hAbFaP1cufQMD+StTV99AbwxUUSuYhXV11mOEkzweVqZ2g7nJ6DHXacOEdAYZ7X8B7tbpeGr2hxkpEYDnls1z6eB3FD3ZsscJ4qHPY64dIXTtq+Jy/ZFH2TlPhfKFkhZl7UNYJwpxWY/ANZfwqIPtp8EhGrZlhcILwN240SWxE1Y1iwwEixC1ZeIgXXYVSsDIPfGvTGFrMuXyA=" Apr 12 12:39:42 volumio go-librespot[30229]: time="2026-04-12T12:39:42Z" 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]" Apr 12 12:39:43 volumio go-librespot[30229]: time="2026-04-12T12:39:43Z" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 104.199.241.202:4070: connect: connection refused" Apr 12 12:39:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 12:39:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 12:39:45 volumio volumio[863]: info: Initializing connection to go-librespot Websocket Apr 12 12:39:45 volumio volumio[863]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 12 12:39:45 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 12 12:39:46 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 12 12:39:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 124373. Apr 12 12:39:46 volumio systemd[1]: Stopped go-librespot Daemon. Apr 12 12:39:46 volumio systemd[1]: Started go-librespot Daemon. Apr 12 12:39:46 volumio go-librespot[30237]: Librespot-go daemon starting... Apr 12 12:39:46 volumio go-librespot[30237]: time="2026-04-12T12:39:46Z" level=info msg="generated new device id: cf83a5a94c04c36e3b259eed28909210489efc48" Apr 12 12:39:46 volumio go-librespot[30237]: time="2026-04-12T12:39:46Z" level=debug msg="stored credentials found for 31mvnzn5yiy6ejh4emnlwctzi2mi" Apr 12 12:39:46 volumio go-librespot[30237]: time="2026-04-12T12:39:46Z" level=debug msg="obtained new client token: AAB0yTF04ELM5Emdjqr/ynpq+wUzNOgDEJx0WHi2Ftk2iy36FK8YM0d1Ut8/ODyChd+uN8OdUWF1LIbsPSzbObyN5EztfZU5moCOZ6KQjLvlyL6GJQSmb8w2zdgYjg0lU8DdMtBx+q5GA0z4NxqVrCmn3I8oofjgPP2S5PThYePKG8wiVviaSWMKY3Xp0AXq3pQzBEqIPdlSpxGGdGsVy5oGhfvyTVCBlp8WQer81tbzMk/8A4mlvvstL7ipSBU=" Apr 12 12:39:46 volumio go-librespot[30237]: time="2026-04-12T12:39:46Z" 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]" Apr 12 12:39:46 volumio go-librespot[30237]: time="2026-04-12T12:39:46Z" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 104.199.241.202:4070: connect: connection refused" Apr 12 12:39:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 12:39:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 12:39:47 volumio volumio[863]: info: Enabling MyMusic plugin qobuzconnect Apr 12 12:39:47 volumio volumio[863]: info: [MyVolumio PluginManager] Enabling and starting plugin music_service qobuzconnect Apr 12 12:39:47 volumio volumio[863]: info: [MyVolumio PluginManager] Plugin music_service qobuzconnect not in user plan, not enabling Apr 12 12:39:47 volumio volumio[863]: info: Error: Plugin music_service qobuzconnect not in user plan, not enabling Apr 12 12:39:47 volumio volumio[863]: error: Could not Enable MyMusic Plugin: Error Apr 12 12:39:48 volumio volumio[863]: info: Initializing connection to go-librespot Websocket Apr 12 12:39:48 volumio volumio[863]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 12 12:39:49 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 12 12:39:50 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 12 12:39:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 124374. Apr 12 12:39:50 volumio systemd[1]: Stopped go-librespot Daemon. Apr 12 12:39:50 volumio systemd[1]: Started go-librespot Daemon. Apr 12 12:39:50 volumio go-librespot[30261]: Librespot-go daemon starting... Apr 12 12:39:50 volumio go-librespot[30261]: time="2026-04-12T12:39:50Z" level=info msg="generated new device id: fa10fedb158b13e27d292dd734266439ab97c60c" Apr 12 12:39:50 volumio go-librespot[30261]: time="2026-04-12T12:39:50Z" level=debug msg="stored credentials found for 31mvnzn5yiy6ejh4emnlwctzi2mi" Apr 12 12:39:50 volumio go-librespot[30261]: time="2026-04-12T12:39:50Z" level=debug msg="obtained new client token: AABL6GZ2rpKj+U2f+BUo0jvq1bOVP1L2lxw+6Ojb7F6IRrzsbV/cIlMTNSscD4hjWosTj8cEC/pz2Xsxhwz5LC1p2zbeSIOCkpf8xzdbShUwOX6R6Uf81L6g8m2MLDAqByP2yHeZsoekVlhhlCopjby8+bLcfKpgvLKcWHmxW8nq+u7uX+1TcEEdV6xrlydeEeOCnnrSKoiepRa4f8xDyl52z7pRRiNROQTOTW0lstOyUjlMPDN5ymDgZFW+8Wo=" Apr 12 12:39:50 volumio go-librespot[30261]: time="2026-04-12T12:39:50Z" 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]" Apr 12 12:39:50 volumio go-librespot[30261]: time="2026-04-12T12:39:50Z" level=debug msg="completed keyexchange" Apr 12 12:39:51 volumio go-librespot[30261]: time="2026-04-12T12:39:51Z" level=debug msg="completed challenge" Apr 12 12:39:51 volumio go-librespot[30261]: time="2026-04-12T12:39:51Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 12 12:39:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 12:39:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 12:39:51 volumio volumio[863]: info: Initializing connection to go-librespot Websocket Apr 12 12:39:51 volumio volumio[863]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 12 12:39:53 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 12 12:39:54 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 12 12:39:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 124375. Apr 12 12:39:54 volumio systemd[1]: Stopped go-librespot Daemon. Apr 12 12:39:54 volumio systemd[1]: Started go-librespot Daemon. Apr 12 12:39:54 volumio go-librespot[30269]: Librespot-go daemon starting... Apr 12 12:39:54 volumio go-librespot[30269]: time="2026-04-12T12:39:54Z" level=info msg="generated new device id: 748ad04256903cdfc7fda48cfdad10a6b026a716" Apr 12 12:39:54 volumio go-librespot[30269]: time="2026-04-12T12:39:54Z" level=debug msg="stored credentials found for 31mvnzn5yiy6ejh4emnlwctzi2mi" Apr 12 12:39:54 volumio volumio[863]: info: Initializing connection to go-librespot Websocket Apr 12 12:39:54 volumio go-librespot[30269]: time="2026-04-12T12:39:54Z" level=debug msg="new websocket client" Apr 12 12:39:54 volumio volumio[863]: info: Connection to go-librespot Websocket established Apr 12 12:39:54 volumio go-librespot[30269]: time="2026-04-12T12:39:54Z" level=debug msg="obtained new client token: AACr5yKXWfBR833OPqrxmlB7DI7YypitPPagJBdK1rbjfQVTtbYxa86CUFrb8XCIEsAcGiER1s4qN7Hv5ZhsT9CDeMQt/jvmNYy2+kRKGRqq0xV25wj6xz3IUJnvwB4Hyhg5XVX3nC2zveun4QaINPUkkAOQ8WKQdelRDCiB/3K2IT30A9vAOPKdRPDBCLjVS45C+A6aKiHJfxBeux0ZKG8RDYuGfEMktdzqEQCUMVUa6JgkEwj+JN+xyi9XcC8=" Apr 12 12:39:54 volumio go-librespot[30269]: time="2026-04-12T12:39:54Z" 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]" Apr 12 12:39:54 volumio go-librespot[30269]: time="2026-04-12T12:39:54Z" level=debug msg="completed keyexchange" Apr 12 12:39:54 volumio go-librespot[30269]: time="2026-04-12T12:39:54Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed solving challenge: failed login: BadCredentials" Apr 12 12:39:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 12:39:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 12:39:54 volumio volumio[863]: info: Connection to go-librespot Websocket closed Apr 12 12:39:57 volumio volumio[863]: info: Getting Spotify volume Apr 12 12:39:57 volumio volumio[863]: (node:863) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 12 12:39:57 volumio volumio[863]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 12 12:39:57 volumio volumio[863]: (node:863) 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: 40892) Apr 12 12:39:57 volumio volumio[863]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Apr 12 12:39:57 volumio volumio[863]: info: CoreCommandRouter::volumioGetState Apr 12 12:39:57 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 12 12:39:57 volumio volumio[863]: info: Initializing connection to go-librespot Websocket Apr 12 12:39:57 volumio volumio[863]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 12 12:39:58 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 12 12:39:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 124376. Apr 12 12:39:58 volumio systemd[1]: Stopped go-librespot Daemon. Apr 12 12:39:58 volumio systemd[1]: Started go-librespot Daemon. Apr 12 12:39:58 volumio go-librespot[30277]: Librespot-go daemon starting... Apr 12 12:39:58 volumio go-librespot[30277]: time="2026-04-12T12:39:58Z" level=info msg="generated new device id: c94fa7d8dec2ba0db1823dc2717919a139c4bc27" Apr 12 12:39:58 volumio go-librespot[30277]: time="2026-04-12T12:39:58Z" level=debug msg="stored credentials found for 31mvnzn5yiy6ejh4emnlwctzi2mi" Apr 12 12:39:58 volumio go-librespot[30277]: time="2026-04-12T12:39:58Z" level=debug msg="obtained new client token: AABAAChV2X2lU/+e/3p9RpLK+Xi4+zU9JbSb9wkSKxRExcedXm3TiEY5bRTi7eWX0DbpI4PhXyX0oFX2/IXBoYtofcnso36YdL6APTeTnMmzPnjGf9nfbO83csRTLpmsu/sumzDekrE9lm5CmiOe4NwPkyu8yK2mcr9KYUzLPZwDN7eXhzUKnaXGGAY4pLpSMDJEBBC7HCS2Vvm2tBnSsXq4o2km7hHBH3UDtGGkIoEriLuf4UNMx50P/cpVpeY=" Apr 12 12:39:58 volumio go-librespot[30277]: time="2026-04-12T12:39:58Z" 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]" Apr 12 12:39:58 volumio go-librespot[30277]: time="2026-04-12T12:39:58Z" level=debug msg="completed keyexchange" Apr 12 12:39:59 volumio volumio[863]: info: CALLMETHOD: miscellanea my_music updateMusicLibraryBrowseSourcesVisibility [object Object] Apr 12 12:39:59 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: my_music , updateMusicLibraryBrowseSourcesVisibility Apr 12 12:39:59 volumio volumio[863]: info: CoreCommandRouter::volumioUpdateToBrowseSources Apr 12 12:39:59 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 12 12:39:59 volumio volumio[863]: Cannot find translation for source YouTube2 Apr 12 12:39:59 volumio go-librespot[30277]: time="2026-04-12T12:39:59Z" level=debug msg="completed challenge" Apr 12 12:39:59 volumio go-librespot[30277]: time="2026-04-12T12:39:59Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 12 12:39:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 12:39:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 12:40:00 volumio volumio[863]: info: Initializing connection to go-librespot Websocket Apr 12 12:40:00 volumio volumio[863]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 12 12:40:01 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 12 12:40:02 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 12 12:40:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 124377. Apr 12 12:40:02 volumio systemd[1]: Stopped go-librespot Daemon. Apr 12 12:40:02 volumio systemd[1]: Started go-librespot Daemon. Apr 12 12:40:02 volumio go-librespot[30299]: Librespot-go daemon starting... Apr 12 12:40:02 volumio go-librespot[30299]: time="2026-04-12T12:40:02Z" level=info msg="generated new device id: 2979d9ca811845c380e87ee0aa4d0bc3907bda8a" Apr 12 12:40:02 volumio go-librespot[30299]: time="2026-04-12T12:40:02Z" level=debug msg="stored credentials found for 31mvnzn5yiy6ejh4emnlwctzi2mi" Apr 12 12:40:02 volumio go-librespot[30299]: time="2026-04-12T12:40:02Z" level=debug msg="obtained new client token: AADDs3ODs+9iRkTrs74qHUtHIbPOwtO3aB280zwMGWqRLjbGT2uvCLqFFxuZwnnGWL0qAZwJaUDR5Bz2DQHFtV92lFCZYkbLvUEXX2pDVUxmeFFUUyE5ZsJrHHJuNFcqFD1JzrxDooNrGmsG1dTvQJS5L1yxs0j7Ogbfu/XMsK/TaleQY8vxt5iLpczodkawEslKQL6/nQsG7S30GURQSUgBkh2QJEgs8Lwx+tDPus4l8zjpJushc7IDrVuSe/M=" Apr 12 12:40:02 volumio go-librespot[30299]: time="2026-04-12T12:40:02Z" 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]" Apr 12 12:40:02 volumio go-librespot[30299]: time="2026-04-12T12:40:02Z" level=debug msg="completed keyexchange" Apr 12 12:40:03 volumio go-librespot[30299]: time="2026-04-12T12:40:03Z" level=debug msg="completed challenge" Apr 12 12:40:03 volumio go-librespot[30299]: time="2026-04-12T12:40:03Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 12 12:40:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 12:40:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 12:40:03 volumio ntpd[803]: Soliciting pool server 240b:400d:3:3300:aeda:71da:9779:d4f1 Apr 12 12:40:03 volumio volumio[863]: info: Initializing connection to go-librespot Websocket Apr 12 12:40:03 volumio volumio[863]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 12 12:40:05 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 12 12:40:06 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 12 12:40:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 124378. Apr 12 12:40:06 volumio systemd[1]: Stopped go-librespot Daemon. Apr 12 12:40:06 volumio systemd[1]: Started go-librespot Daemon. Apr 12 12:40:06 volumio go-librespot[30307]: Librespot-go daemon starting... Apr 12 12:40:06 volumio go-librespot[30307]: time="2026-04-12T12:40:06Z" level=info msg="generated new device id: c24d584b24c6ded02ccd48b131dab7f0b31af46b" Apr 12 12:40:06 volumio go-librespot[30307]: time="2026-04-12T12:40:06Z" level=debug msg="stored credentials found for 31mvnzn5yiy6ejh4emnlwctzi2mi" Apr 12 12:40:06 volumio go-librespot[30307]: time="2026-04-12T12:40:06Z" level=debug msg="obtained new client token: AAC15hROmwq51ccmI+8/FJYDL7FbHoWBEtGPbP2k7I46qx7s1kOfSK5n08yqmfzVmq+GEa+FerXZndPh7mfkfLuK21onpd2hEdB+ZavL9xIgW/DlXrmKlPa1+XYq5Dplf/RcgfoY41Afphy4qXLn9489Sm6RUUqFrS0S/oyfWb391k5Zwt2Alv6RbCQvaqSK5GNd9CXX/4mYUu8XQVOXjFHNjFbXCM6zjlapxLzwg6pyeZieAhJGRscQTz0Ho4c=" Apr 12 12:40:06 volumio go-librespot[30307]: time="2026-04-12T12:40:06Z" 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]" Apr 12 12:40:06 volumio volumio[863]: info: Initializing connection to go-librespot Websocket Apr 12 12:40:06 volumio go-librespot[30307]: time="2026-04-12T12:40:06Z" level=debug msg="new websocket client" Apr 12 12:40:06 volumio volumio[863]: info: Connection to go-librespot Websocket established Apr 12 12:40:07 volumio go-librespot[30307]: time="2026-04-12T12:40:07Z" level=debug msg="completed keyexchange" Apr 12 12:40:07 volumio go-librespot[30307]: time="2026-04-12T12:40:07Z" level=debug msg="completed challenge" Apr 12 12:40:07 volumio go-librespot[30307]: time="2026-04-12T12:40:07Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 12 12:40:07 volumio volumio[863]: info: Connection to go-librespot Websocket closed Apr 12 12:40:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 12:40:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 12:40:09 volumio volumio[863]: info: Getting Spotify volume Apr 12 12:40:09 volumio volumio[863]: (node:863) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 12 12:40:09 volumio volumio[863]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 12 12:40:09 volumio volumio[863]: (node:863) 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: 40893) Apr 12 12:40:09 volumio volumio[863]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Apr 12 12:40:09 volumio volumio[863]: info: CoreCommandRouter::volumioGetState Apr 12 12:40:10 volumio volumio[863]: info: Initializing connection to go-librespot Websocket Apr 12 12:40:10 volumio volumio[863]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 12 12:40:10 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 12 12:40:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 124379. Apr 12 12:40:10 volumio systemd[1]: Stopped go-librespot Daemon. Apr 12 12:40:10 volumio systemd[1]: Started go-librespot Daemon. Apr 12 12:40:10 volumio go-librespot[30330]: Librespot-go daemon starting... Apr 12 12:40:10 volumio go-librespot[30330]: time="2026-04-12T12:40:10Z" level=info msg="generated new device id: d4816a827029ee7d3d2245a6416dfb9731785e36" Apr 12 12:40:10 volumio go-librespot[30330]: time="2026-04-12T12:40:10Z" level=debug msg="stored credentials found for 31mvnzn5yiy6ejh4emnlwctzi2mi" Apr 12 12:40:10 volumio volumio[863]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 12 12:40:10 volumio volumio[863]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 12 12:40:10 volumio volumio[863]: info: Retrieving Cloud Streaming UI Apr 12 12:40:10 volumio volumio[863]: info: Getting Tidal Cloud Configuration Apr 12 12:40:10 volumio volumio[863]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 12 12:40:10 volumio volumio[863]: info: Getting Qobuz Cloud Configuration Apr 12 12:40:10 volumio volumio[863]: info: Asking plugin for UI Config Apr 12 12:40:10 volumio volumio[863]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 12 12:40:10 volumio volumio[863]: info: Getting Spotify Cloud Configuration Apr 12 12:40:10 volumio volumio[863]: info: Asking plugin for UI Config Apr 12 12:40:10 volumio volumio[863]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 12 12:40:10 volumio volumio[863]: info: Saving Spotify Acccount Apr 12 12:40:10 volumio volumio[863]: info: Got Tidal Cloud Configuration Apr 12 12:40:10 volumio volumio[863]: info: Got it Apr 12 12:40:10 volumio volumio[863]: info: Got it Apr 12 12:40:10 volumio volumio[863]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Apr 12 12:40:10 volumio volumio[863]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 12 12:40:10 volumio volumio[863]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Apr 12 12:40:10 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 12 12:40:10 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Apr 12 12:40:10 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 12 12:40:10 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 12 12:40:10 volumio volumio[863]: info: CoreCommandRouter::volumioGetBrowseSources Apr 12 12:40:10 volumio volumio[863]: info: CoreCommandRouter::volumioGetBrowseSources Apr 12 12:40:11 volumio go-librespot[30330]: time="2026-04-12T12:40:11Z" level=debug msg="obtained new client token: AAC0HOxlWcPo2s4chzyt3hzPvSMWNXP5T4n39Po/IEZ9tenxvMhqT9UlBTVGstc3N5/JU8qjkqHR/9YURVKTeH2kWIAPeTgnWHiEZxUgSgFBzki15OpxSLxUqeNPWT5J825LYcbNpS/c8Wcx9mq9Vzb1MBYqEo9jk5k2THdI2AcPptJH/HczWdKCUg4VGCHYw+r9kw8m+dSrdAs+fIVs7gZGuppjktJmCh1OHAtnV2WULpbtpUGJnBK5Q8iT" Apr 12 12:40:11 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 12 12:40:11 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Apr 12 12:40:11 volumio go-librespot[30330]: time="2026-04-12T12:40:11Z" 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]" Apr 12 12:40:11 volumio go-librespot[30330]: time="2026-04-12T12:40:11Z" level=debug msg="completed keyexchange" Apr 12 12:40:11 volumio go-librespot[30330]: time="2026-04-12T12:40:11Z" level=debug msg="completed challenge" Apr 12 12:40:11 volumio go-librespot[30330]: time="2026-04-12T12:40:11Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 12 12:40:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 12:40:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 12:40:13 volumio volumio[863]: info: Initializing connection to go-librespot Websocket Apr 12 12:40:13 volumio volumio[863]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 12 12:40:15 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 12 12:40:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 124380. Apr 12 12:40:15 volumio systemd[1]: Stopped go-librespot Daemon. Apr 12 12:40:15 volumio systemd[1]: Started go-librespot Daemon. Apr 12 12:40:15 volumio go-librespot[30338]: Librespot-go daemon starting... Apr 12 12:40:15 volumio go-librespot[30338]: time="2026-04-12T12:40:15Z" level=info msg="generated new device id: b8b23f96f5784f65f37fd134cd5edc6ba0765c5e" Apr 12 12:40:15 volumio go-librespot[30338]: time="2026-04-12T12:40:15Z" level=debug msg="stored credentials found for 31mvnzn5yiy6ejh4emnlwctzi2mi" Apr 12 12:40:15 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 12 12:40:15 volumio go-librespot[30338]: time="2026-04-12T12:40:15Z" level=debug msg="obtained new client token: AADgTPMuhD+bCBbpXsJLNqM6ElrqcXc/vaHBsxMSDgkXUThVuxM5sIKDMxUkURkuIVcISxpBdkRC7cX+HIUxeZKCXOg/MmAtVsEEaAgsQawa8Nj1vQQAqWPdrQKEPrT8LQNG/e7HfZCnhi6JkzewdLbty/cOIk2iNLA7omFlqkx5QAd5sPnQcK1OLJOxKXEGURFoP2XQ/+IzoDg/IUanlcNlDX0gKaogLtLx/n2+h9GM8TU6lVWLNwYvh2lXrkA=" Apr 12 12:40:15 volumio go-librespot[30338]: time="2026-04-12T12:40:15Z" 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]" Apr 12 12:40:15 volumio go-librespot[30338]: time="2026-04-12T12:40:15Z" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 104.199.241.202:4070: connect: connection refused" Apr 12 12:40:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 12:40:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 12:40:16 volumio volumio[863]: info: Initializing connection to go-librespot Websocket Apr 12 12:40:16 volumio volumio[863]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 12 12:40:18 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 12 12:40:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 124381. Apr 12 12:40:18 volumio systemd[1]: Stopped go-librespot Daemon. Apr 12 12:40:18 volumio systemd[1]: Started go-librespot Daemon. Apr 12 12:40:18 volumio go-librespot[30348]: Librespot-go daemon starting... Apr 12 12:40:18 volumio go-librespot[30348]: time="2026-04-12T12:40:18Z" level=info msg="generated new device id: cfe9decea1de2c35a93659f56963cb29f53462d0" Apr 12 12:40:18 volumio go-librespot[30348]: time="2026-04-12T12:40:18Z" level=debug msg="stored credentials found for 31mvnzn5yiy6ejh4emnlwctzi2mi" Apr 12 12:40:19 volumio go-librespot[30348]: time="2026-04-12T12:40:19Z" level=debug msg="obtained new client token: AACqkakbPIodzkyuIfXNLiuCBicC0R7nlUiM3OMsYbpVxjTIco3sY3yzWIubmaMDRarusMudHnM8kAidMf3FLAUeNJPgVT+U5e0E6kRk7EehBhgBM+PRUpbdXhPwVJZxKzNZfRx9QkI2ynKt3RHQ33T8BoPovZgRTaLGo9nnV55lti6dfMk/ysCtExGc0Tit+8pjToe27otKz5efe4ybuk78dkqtZcLljHV56KoQPLc0SDFODo80+L9Eb2aM" Apr 12 12:40:19 volumio go-librespot[30348]: time="2026-04-12T12:40:19Z" 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]" Apr 12 12:40:19 volumio go-librespot[30348]: time="2026-04-12T12:40:19Z" level=debug msg="completed keyexchange" Apr 12 12:40:19 volumio volumio[863]: info: Initializing connection to go-librespot Websocket Apr 12 12:40:19 volumio go-librespot[30348]: time="2026-04-12T12:40:19Z" level=debug msg="new websocket client" Apr 12 12:40:19 volumio volumio[863]: info: Connection to go-librespot Websocket established Apr 12 12:40:19 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 12 12:40:19 volumio go-librespot[30348]: time="2026-04-12T12:40:19Z" level=debug msg="completed challenge" Apr 12 12:40:19 volumio go-librespot[30348]: time="2026-04-12T12:40:19Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 12 12:40:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 12:40:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 12:40:19 volumio volumio[863]: info: Connection to go-librespot Websocket closed Apr 12 12:40:20 volumio volumio[863]: error: Upnp client error: Error: This socket has been ended by the other party Apr 12 12:40:22 volumio volumio[863]: info: Getting Spotify volume Apr 12 12:40:22 volumio volumio[863]: (node:863) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 12 12:40:22 volumio volumio[863]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 12 12:40:22 volumio volumio[863]: (node:863) 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: 40894) Apr 12 12:40:22 volumio volumio[863]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Apr 12 12:40:22 volumio volumio[863]: info: CoreCommandRouter::volumioGetState Apr 12 12:40:22 volumio volumio[863]: info: Initializing connection to go-librespot Websocket Apr 12 12:40:22 volumio volumio[863]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 12 12:40:23 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 12 12:40:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 124382. Apr 12 12:40:23 volumio systemd[1]: Stopped go-librespot Daemon. Apr 12 12:40:23 volumio systemd[1]: Started go-librespot Daemon. Apr 12 12:40:23 volumio go-librespot[30376]: Librespot-go daemon starting... Apr 12 12:40:23 volumio go-librespot[30376]: time="2026-04-12T12:40:23Z" level=info msg="generated new device id: 25fc17475f1d6030df8d7306c50e816dab776e40" Apr 12 12:40:23 volumio go-librespot[30376]: time="2026-04-12T12:40:23Z" level=debug msg="stored credentials found for 31mvnzn5yiy6ejh4emnlwctzi2mi" Apr 12 12:40:23 volumio go-librespot[30376]: time="2026-04-12T12:40:23Z" level=debug msg="obtained new client token: AAD39bYlqnUq43ylvtZctODTPHioU3Iwd135hP6r+f8TzKSQNv1D/SFNXadkFId1LKh3DKSAVNq1eWvas3MglElodtCT9TUxTFLOzy+nabKN8SJa/3ob3RdZ5f4eANS48Fy9G9nXcXd9RPLD+yT1SBV6JeQQxZq7gj8zY1KFXMCvSHFm1IhzC70txglk8OOhHA0tjPSz1iCyvHvwyJK/EhXcNxR0W7WJ8I4aBYOA6H0+P/0JrTiMBTJvd5IexiU=" Apr 12 12:40:23 volumio go-librespot[30376]: time="2026-04-12T12:40:23Z" 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]" Apr 12 12:40:23 volumio go-librespot[30376]: time="2026-04-12T12:40:23Z" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 104.199.241.202:4070: connect: connection refused" Apr 12 12:40:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 12:40:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 12:40:23 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 12 12:40:25 volumio volumio[863]: info: Initializing connection to go-librespot Websocket Apr 12 12:40:25 volumio volumio[863]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 12 12:40:26 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 12 12:40:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 124383. Apr 12 12:40:26 volumio systemd[1]: Stopped go-librespot Daemon. Apr 12 12:40:26 volumio systemd[1]: Started go-librespot Daemon. Apr 12 12:40:26 volumio go-librespot[30384]: Librespot-go daemon starting... Apr 12 12:40:26 volumio go-librespot[30384]: time="2026-04-12T12:40:26Z" level=info msg="generated new device id: af1abbdb53740d88769de89706ee309c42d37399" Apr 12 12:40:26 volumio go-librespot[30384]: time="2026-04-12T12:40:26Z" level=debug msg="stored credentials found for 31mvnzn5yiy6ejh4emnlwctzi2mi" Apr 12 12:40:27 volumio go-librespot[30384]: time="2026-04-12T12:40:27Z" level=debug msg="obtained new client token: AAB5ZVOG1qEfIdNIeIGOI6j1oJn25Xi0Z0y8VrKOml+0H2vuDC/cf5jawewM0e9xrMe6z9gJiwN8dWMgGmT/B5BUW30ocXlnt/ZxONldQ2/eC58Y7vRhLyJ5VtC75E8GVlrosEtH+GYnVZ+rpVZNu5gF7xn4kaFzT5aasFeYHgw9F7ZA37u1yeEsugOIawp+10gUhBoWuutrSjDzApv2E+JqMGFXW6hPbZC1lDzSBCTofs82sP0W1KNuBmHf" Apr 12 12:40:27 volumio go-librespot[30384]: time="2026-04-12T12:40:27Z" 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]" Apr 12 12:40:27 volumio go-librespot[30384]: time="2026-04-12T12:40:27Z" level=debug msg="completed keyexchange" Apr 12 12:40:27 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 12 12:40:27 volumio volumio[863]: info: Clearing queue after UPNP request Apr 12 12:40:27 volumio go-librespot[30384]: time="2026-04-12T12:40:27Z" level=debug msg="completed challenge" Apr 12 12:40:27 volumio go-librespot[30384]: time="2026-04-12T12:40:27Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 12 12:40:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 12:40:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 12:40:28 volumio volumio[863]: info: CoreStateMachine::ClearQueue Apr 12 12:40:28 volumio volumio[863]: info: CoreStateMachine::stop Apr 12 12:40:28 volumio volumio[863]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 12:40:28 volumio volumio[863]: info: CorePlayQueue::clearPlayQueue Apr 12 12:40:28 volumio volumio[863]: info: CorePlayQueue::saveQueue Apr 12 12:40:28 volumio volumio[863]: info: CoreCommandRouter::volumioPushState Apr 12 12:40:28 volumio volumio[863]: info: CoreCommandRouter::volumioPushQueue Apr 12 12:40:28 volumio volumio[863]: info: Apr 12 12:40:28 volumio volumio[863]: ---------------------------- MPD announces system playlist update Apr 12 12:40:28 volumio volumio[863]: info: Ignoring MPD Status Update Apr 12 12:40:28 volumio volumio[863]: info: Apr 12 12:40:28 volumio volumio[863]: ---------------------------- MPD announces state update: player Apr 12 12:40:28 volumio volumio[863]: info: ControllerMpd::getState Apr 12 12:40:28 volumio volumio[863]: verbose: ControllerMpd::sendMpdCommand status Apr 12 12:40:28 volumio volumio[863]: info: Apr 12 12:40:28 volumio volumio[863]: ---------------------------- MPD announces system playlist update Apr 12 12:40:28 volumio volumio[863]: info: Ignoring MPD Status Update Apr 12 12:40:28 volumio volumio[863]: info: Apr 12 12:40:28 volumio volumio[863]: ---------------------------- MPD announces state update: player Apr 12 12:40:28 volumio volumio[863]: info: ControllerMpd::getState Apr 12 12:40:28 volumio volumio[863]: verbose: ControllerMpd::sendMpdCommand status Apr 12 12:40:28 volumio volumio[863]: error: updateQueue error: null Apr 12 12:40:28 volumio volumio[863]: error: updateQueue error: null Apr 12 12:40:28 volumio volumio[863]: info: ------------------------------ 5ms Apr 12 12:40:28 volumio volumio[863]: info: sendMpdCommand status took 4 milliseconds Apr 12 12:40:28 volumio volumio[863]: info: ------------------------------ 4ms Apr 12 12:40:28 volumio volumio[863]: info: sendMpdCommand status took 3 milliseconds Apr 12 12:40:28 volumio volumio[863]: verbose: ControllerMpd::parseState Apr 12 12:40:28 volumio volumio[863]: verbose: ControllerMpd::parseState Apr 12 12:40:28 volumio volumio[863]: info: ControllerMpd::pushState Apr 12 12:40:28 volumio volumio[863]: info: CoreCommandRouter::servicePushState Apr 12 12:40:28 volumio volumio[863]: info: CoreStateMachine::pushState Apr 12 12:40:28 volumio volumio[863]: info: CorePlayQueue::getTrack 0 Apr 12 12:40:28 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 12:40:28 volumio volumio[863]: info: CoreCommandRouter::volumioPushState Apr 12 12:40:28 volumio volumio[863]: info: CorePlayQueue::getTrack 0 Apr 12 12:40:28 volumio volumio[863]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 12 12:40:28 volumio volumio[863]: verbose: CURRENT POSITION 0 Apr 12 12:40:28 volumio volumio[863]: info: CoreStateMachine::syncState stateService stop Apr 12 12:40:28 volumio volumio[863]: info: CoreStateMachine::syncState currentStatus stop Apr 12 12:40:28 volumio volumio[863]: info: CoreStateMachine::pushState Apr 12 12:40:28 volumio volumio[863]: info: CorePlayQueue::getTrack 0 Apr 12 12:40:28 volumio volumio[863]: info: CoreCommandRouter::volumioPushState Apr 12 12:40:28 volumio volumio[863]: info: No code Apr 12 12:40:28 volumio volumio[863]: info: CoreStateMachine::pushState Apr 12 12:40:28 volumio volumio[863]: info: CorePlayQueue::getTrack 0 Apr 12 12:40:28 volumio volumio[863]: info: CoreCommandRouter::volumioPushState Apr 12 12:40:28 volumio volumio[863]: info: ControllerMpd::pushState Apr 12 12:40:28 volumio volumio[863]: info: CoreCommandRouter::servicePushState Apr 12 12:40:28 volumio volumio[863]: info: CoreStateMachine::pushState Apr 12 12:40:28 volumio volumio[863]: info: CorePlayQueue::getTrack 0 Apr 12 12:40:28 volumio volumio[863]: info: CoreCommandRouter::volumioPushState Apr 12 12:40:28 volumio volumio[863]: info: CorePlayQueue::getTrack 0 Apr 12 12:40:28 volumio volumio[863]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 12 12:40:28 volumio volumio[863]: verbose: CURRENT POSITION 0 Apr 12 12:40:28 volumio volumio[863]: info: CoreStateMachine::syncState stateService stop Apr 12 12:40:28 volumio volumio[863]: info: CoreStateMachine::syncState currentStatus stop Apr 12 12:40:28 volumio volumio[863]: info: CoreStateMachine::pushState Apr 12 12:40:28 volumio volumio[863]: info: CorePlayQueue::getTrack 0 Apr 12 12:40:28 volumio volumio[863]: info: CoreCommandRouter::volumioPushState Apr 12 12:40:28 volumio volumio[863]: info: No code Apr 12 12:40:28 volumio volumio[863]: info: CoreStateMachine::pushState Apr 12 12:40:28 volumio volumio[863]: info: CorePlayQueue::getTrack 0 Apr 12 12:40:28 volumio volumio[863]: info: CoreCommandRouter::volumioPushState Apr 12 12:40:28 volumio volumio[863]: info: ------------------------------ 36ms Apr 12 12:40:28 volumio volumio[863]: info: ------------------------------ 35ms Apr 12 12:40:28 volumio volumio[863]: info: Starting UPNP Playback Apr 12 12:40:28 volumio volumio[863]: info: Preparing playback through UPNP Apr 12 12:40:28 volumio volumio[863]: info: CoreCommandRouter::volumioGetState Apr 12 12:40:28 volumio volumio[863]: info: CorePlayQueue::getTrack 0 Apr 12 12:40:28 volumio volumio[863]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 12 12:40:28 volumio volumio[863]: info: Apr 12 12:40:28 volumio volumio[863]: ---------------------------- MPD announces system playlist update Apr 12 12:40:28 volumio volumio[863]: info: Ignoring MPD Status Update Apr 12 12:40:28 volumio volumio[863]: info: Apr 12 12:40:28 volumio volumio[863]: ---------------------------- MPD announces system playlist update Apr 12 12:40:28 volumio volumio[863]: info: Ignoring MPD Status Update Apr 12 12:40:28 volumio volumio[863]: info: Apr 12 12:40:28 volumio volumio[863]: ---------------------------- MPD announces system playlist update Apr 12 12:40:28 volumio volumio[863]: info: Ignoring MPD Status Update Apr 12 12:40:28 volumio volumio[863]: info: ------------------------------ 3ms Apr 12 12:40:28 volumio volumio[863]: info: Apr 12 12:40:28 volumio volumio[863]: ---------------------------- MPD announces system playlist update Apr 12 12:40:28 volumio volumio[863]: info: Ignoring MPD Status Update Apr 12 12:40:28 volumio volumio[863]: info: Apr 12 12:40:28 volumio volumio[863]: ---------------------------- MPD announces system playlist update Apr 12 12:40:28 volumio volumio[863]: info: Ignoring MPD Status Update Apr 12 12:40:28 volumio volumio[863]: info: Apr 12 12:40:28 volumio volumio[863]: ---------------------------- MPD announces system playlist update Apr 12 12:40:28 volumio volumio[863]: info: Ignoring MPD Status Update Apr 12 12:40:28 volumio volumio[863]: info: ------------------------------ 4ms Apr 12 12:40:28 volumio volumio[863]: info: ------------------------------ 3ms Apr 12 12:40:28 volumio volumio[863]: info: ------------------------------ 2ms Apr 12 12:40:28 volumio volumio[863]: info: Apr 12 12:40:28 volumio volumio[863]: ---------------------------- MPD announces system playlist update Apr 12 12:40:28 volumio volumio[863]: info: Ignoring MPD Status Update Apr 12 12:40:28 volumio volumio[863]: info: Apr 12 12:40:28 volumio volumio[863]: ---------------------------- MPD announces system playlist update Apr 12 12:40:28 volumio volumio[863]: info: Ignoring MPD Status Update Apr 12 12:40:28 volumio volumio[863]: info: Apr 12 12:40:28 volumio volumio[863]: ---------------------------- MPD announces system playlist update Apr 12 12:40:28 volumio volumio[863]: info: Ignoring MPD Status Update Apr 12 12:40:28 volumio volumio[863]: info: ------------------------------ 3ms Apr 12 12:40:28 volumio volumio[863]: info: ------------------------------ 2ms Apr 12 12:40:28 volumio volumio[863]: info: Apr 12 12:40:28 volumio volumio[863]: ---------------------------- MPD announces system playlist update Apr 12 12:40:28 volumio volumio[863]: info: Ignoring MPD Status Update Apr 12 12:40:28 volumio volumio[863]: info: ------------------------------ 2ms Apr 12 12:40:28 volumio volumio[863]: info: ------------------------------ 2ms Apr 12 12:40:28 volumio volumio[863]: info: Apr 12 12:40:28 volumio volumio[863]: ---------------------------- MPD announces system playlist update Apr 12 12:40:28 volumio volumio[863]: info: Ignoring MPD Status Update Apr 12 12:40:28 volumio volumio[863]: info: Apr 12 12:40:28 volumio volumio[863]: ---------------------------- MPD announces system playlist update Apr 12 12:40:28 volumio volumio[863]: info: Ignoring MPD Status Update Apr 12 12:40:28 volumio volumio[863]: info: ------------------------------ 2ms Apr 12 12:40:28 volumio volumio[863]: info: ------------------------------ 2ms Apr 12 12:40:28 volumio volumio[863]: info: Initializing connection to go-librespot Websocket Apr 12 12:40:28 volumio volumio[863]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 12 12:40:31 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 12 12:40:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 124384. Apr 12 12:40:31 volumio systemd[1]: Stopped go-librespot Daemon. Apr 12 12:40:31 volumio systemd[1]: Started go-librespot Daemon. Apr 12 12:40:31 volumio go-librespot[30410]: Librespot-go daemon starting... Apr 12 12:40:31 volumio go-librespot[30410]: time="2026-04-12T12:40:31Z" level=info msg="generated new device id: d4a816cbd35f0befd95a4a07bf7418cde3715457" Apr 12 12:40:31 volumio go-librespot[30410]: time="2026-04-12T12:40:31Z" level=debug msg="stored credentials found for 31mvnzn5yiy6ejh4emnlwctzi2mi" Apr 12 12:40:31 volumio go-librespot[30410]: time="2026-04-12T12:40:31Z" level=debug msg="obtained new client token: AABq6uX0furepA8cZOxV8/Ru8JbqHXJYL4DuovYtbLaxyfU7eACoYKnnmNNVQrXFKmW4aoWkaj6RgLanPNP1btHmFqNRO5JzF+TstqeSZN2Yh6KvGGHFPITDVPUW02D8VD1+BnHv3qOGdEA36hHT6iprpx28mxKwC6m2mShkslWcNivAqKFlnPetf/3IQwt/g+7+Ka9YoStuQfvQxqlVnMi0eUWswAM087ZF73nuGCPXNBOVTAEcsd11k1dvhRM=" Apr 12 12:40:31 volumio go-librespot[30410]: time="2026-04-12T12:40:31Z" 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]" Apr 12 12:40:31 volumio go-librespot[30410]: time="2026-04-12T12:40:31Z" level=debug msg="completed keyexchange" Apr 12 12:40:31 volumio volumio[863]: info: Apr 12 12:40:31 volumio volumio[863]: ---------------------------- MPD announces state update: player Apr 12 12:40:31 volumio volumio[863]: info: ControllerMpd::getState Apr 12 12:40:31 volumio volumio[863]: verbose: ControllerMpd::sendMpdCommand status Apr 12 12:40:31 volumio volumio[863]: info: Apr 12 12:40:31 volumio volumio[863]: ---------------------------- MPD announces state update: player Apr 12 12:40:31 volumio volumio[863]: info: ControllerMpd::getState Apr 12 12:40:31 volumio volumio[863]: verbose: ControllerMpd::sendMpdCommand status Apr 12 12:40:31 volumio volumio[863]: info: Apr 12 12:40:31 volumio volumio[863]: ---------------------------- MPD announces state update: player Apr 12 12:40:31 volumio volumio[863]: info: ControllerMpd::getState Apr 12 12:40:31 volumio volumio[863]: verbose: ControllerMpd::sendMpdCommand status Apr 12 12:40:31 volumio volumio[863]: error: MPD returned error for command status: Failed to open "alsa" (alsa); Failed to open ALSA device "volumio": No such device Apr 12 12:40:31 volumio volumio[863]: verbose: ControllerMpd::sendMpdCommand clearerror Apr 12 12:40:31 volumio volumio[863]: info: sendMpdCommand status took 6 milliseconds Apr 12 12:40:31 volumio volumio[863]: verbose: ControllerMpd::parseState Apr 12 12:40:31 volumio volumio[863]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 12:40:31 volumio volumio[863]: info: Apr 12 12:40:31 volumio volumio[863]: ---------------------------- MPD announces state update: player Apr 12 12:40:31 volumio volumio[863]: info: ControllerMpd::getState Apr 12 12:40:31 volumio volumio[863]: verbose: ControllerMpd::sendMpdCommand status Apr 12 12:40:31 volumio volumio[863]: error: MPD returned error for command status: Failed to open "alsa" (alsa); Failed to open ALSA device "volumio": No such device Apr 12 12:40:31 volumio volumio[863]: verbose: ControllerMpd::sendMpdCommand clearerror Apr 12 12:40:31 volumio volumio[863]: info: sendMpdCommand status took 13 milliseconds Apr 12 12:40:31 volumio volumio[863]: error: MPD returned error for command status: Failed to open "alsa" (alsa); Failed to open ALSA device "volumio": No such device Apr 12 12:40:31 volumio volumio[863]: verbose: ControllerMpd::sendMpdCommand clearerror Apr 12 12:40:31 volumio volumio[863]: info: sendMpdCommand status took 13 milliseconds Apr 12 12:40:31 volumio volumio[863]: info: sendMpdCommand clearerror took 10 milliseconds Apr 12 12:40:31 volumio volumio[863]: info: sendMpdCommand playlistinfo took 9 milliseconds Apr 12 12:40:31 volumio volumio[863]: info: sendMpdCommand status took 6 milliseconds Apr 12 12:40:31 volumio volumio[863]: verbose: ControllerMpd::parseState Apr 12 12:40:31 volumio volumio[863]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 12:40:31 volumio volumio[863]: verbose: ControllerMpd::parseState Apr 12 12:40:31 volumio volumio[863]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 12:40:31 volumio volumio[863]: verbose: ControllerMpd::parseTrackInfo Apr 12 12:40:31 volumio volumio[863]: verbose: ControllerMpd::parseState Apr 12 12:40:31 volumio volumio[863]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 12:40:31 volumio volumio[863]: info: ControllerMpd::pushState Apr 12 12:40:31 volumio volumio[863]: info: CoreCommandRouter::servicePushState Apr 12 12:40:31 volumio volumio[863]: verbose: In UPNP mode Apr 12 12:40:31 volumio volumio[863]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":404,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Jerusalem","artist":"Simon Finn","album":"Pass the Distance","uri":"http://192.168.1.77:57645/proxy/tidal/7B83C44F9E79AF916A93255243B1F4C0.flac","trackType":"tidal"} Apr 12 12:40:31 volumio volumio[863]: verbose: CURRENT POSITION 0 Apr 12 12:40:31 volumio volumio[863]: info: CoreStateMachine::syncState stateService pause Apr 12 12:40:31 volumio volumio[863]: info: CoreStateMachine::syncState currentStatus stop Apr 12 12:40:31 volumio volumio[863]: info: CoreStateMachine::pushState Apr 12 12:40:31 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 12:40:31 volumio volumio[863]: info: CoreCommandRouter::volumioPushState Apr 12 12:40:31 volumio volumio5-onboarding[1421]: time=2026-04-12T12:40:31.660Z level=WARN msg="received unknown player status" component=volumio status="" Apr 12 12:40:31 volumio volumio[863]: info: ------------------------------ 32ms Apr 12 12:40:31 volumio volumio[863]: info: sendMpdCommand clearerror took 22 milliseconds Apr 12 12:40:31 volumio volumio[863]: info: sendMpdCommand clearerror took 21 milliseconds Apr 12 12:40:31 volumio volumio[863]: info: sendMpdCommand playlistinfo took 17 milliseconds Apr 12 12:40:31 volumio volumio[863]: info: sendMpdCommand playlistinfo took 16 milliseconds Apr 12 12:40:31 volumio volumio[863]: verbose: ControllerMpd::parseTrackInfo Apr 12 12:40:31 volumio volumio[863]: verbose: ControllerMpd::parseTrackInfo Apr 12 12:40:31 volumio volumio[863]: info: ControllerMpd::pushState Apr 12 12:40:31 volumio volumio[863]: info: CoreCommandRouter::servicePushState Apr 12 12:40:31 volumio volumio[863]: verbose: In UPNP mode Apr 12 12:40:31 volumio volumio[863]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":404,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Jerusalem","artist":"Simon Finn","album":"Pass the Distance","uri":"http://192.168.1.77:57645/proxy/tidal/7B83C44F9E79AF916A93255243B1F4C0.flac","trackType":"tidal"} Apr 12 12:40:31 volumio volumio[863]: verbose: CURRENT POSITION 0 Apr 12 12:40:31 volumio volumio[863]: info: CoreStateMachine::syncState stateService pause Apr 12 12:40:31 volumio volumio[863]: info: CoreStateMachine::syncState currentStatus stop Apr 12 12:40:31 volumio volumio[863]: info: CoreStateMachine::pushState Apr 12 12:40:31 volumio volumio[863]: info: CoreCommandRouter::volumioPushState Apr 12 12:40:31 volumio volumio[863]: info: ControllerMpd::pushState Apr 12 12:40:31 volumio volumio[863]: info: CoreCommandRouter::servicePushState Apr 12 12:40:31 volumio volumio[863]: verbose: In UPNP mode Apr 12 12:40:31 volumio volumio[863]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":404,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Jerusalem","artist":"Simon Finn","album":"Pass the Distance","uri":"http://192.168.1.77:57645/proxy/tidal/7B83C44F9E79AF916A93255243B1F4C0.flac","trackType":"tidal"} Apr 12 12:40:31 volumio volumio[863]: verbose: CURRENT POSITION 0 Apr 12 12:40:31 volumio volumio[863]: info: CoreStateMachine::syncState stateService pause Apr 12 12:40:31 volumio volumio[863]: info: CoreStateMachine::syncState currentStatus stop Apr 12 12:40:31 volumio volumio[863]: info: CoreStateMachine::pushState Apr 12 12:40:31 volumio volumio[863]: info: CoreCommandRouter::volumioPushState Apr 12 12:40:31 volumio volumio[863]: info: ControllerMpd::pushState Apr 12 12:40:31 volumio volumio[863]: info: CoreCommandRouter::servicePushState Apr 12 12:40:31 volumio volumio[863]: verbose: In UPNP mode Apr 12 12:40:31 volumio volumio[863]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":404,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Jerusalem","artist":"Simon Finn","album":"Pass the Distance","uri":"http://192.168.1.77:57645/proxy/tidal/7B83C44F9E79AF916A93255243B1F4C0.flac","trackType":"tidal"} Apr 12 12:40:31 volumio volumio[863]: verbose: CURRENT POSITION 0 Apr 12 12:40:31 volumio volumio[863]: info: CoreStateMachine::syncState stateService pause Apr 12 12:40:31 volumio volumio[863]: info: CoreStateMachine::syncState currentStatus stop Apr 12 12:40:31 volumio volumio[863]: info: CoreStateMachine::pushState Apr 12 12:40:31 volumio volumio[863]: info: CoreCommandRouter::volumioPushState Apr 12 12:40:31 volumio volumio5-onboarding[1421]: time=2026-04-12T12:40:31.689Z level=WARN msg="received unknown player status" component=volumio status="" Apr 12 12:40:31 volumio volumio5-onboarding[1421]: time=2026-04-12T12:40:31.690Z level=WARN msg="received unknown player status" component=volumio status="" Apr 12 12:40:31 volumio volumio[863]: info: ------------------------------ 62ms Apr 12 12:40:31 volumio volumio[863]: info: ------------------------------ 62ms Apr 12 12:40:31 volumio volumio[863]: info: ------------------------------ 57ms Apr 12 12:40:31 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 12 12:40:31 volumio volumio[863]: info: Initializing connection to go-librespot Websocket Apr 12 12:40:31 volumio go-librespot[30410]: time="2026-04-12T12:40:31Z" level=debug msg="new websocket client" Apr 12 12:40:31 volumio volumio[863]: info: Connection to go-librespot Websocket established Apr 12 12:40:32 volumio go-librespot[30410]: time="2026-04-12T12:40:32Z" level=debug msg="completed challenge" Apr 12 12:40:32 volumio go-librespot[30410]: time="2026-04-12T12:40:32Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 12 12:40:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 12:40:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 12:40:32 volumio volumio[863]: info: Connection to go-librespot Websocket closed Apr 12 12:40:34 volumio volumio[863]: info: Apr 12 12:40:34 volumio volumio[863]: ---------------------------- MPD announces state update: player Apr 12 12:40:34 volumio volumio[863]: info: ControllerMpd::getState Apr 12 12:40:34 volumio volumio[863]: verbose: ControllerMpd::sendMpdCommand status Apr 12 12:40:34 volumio volumio[863]: info: Apr 12 12:40:34 volumio volumio[863]: ---------------------------- MPD announces state update: player Apr 12 12:40:34 volumio volumio[863]: info: ControllerMpd::getState Apr 12 12:40:34 volumio volumio[863]: verbose: ControllerMpd::sendMpdCommand status Apr 12 12:40:34 volumio volumio[863]: info: sendMpdCommand status took 2 milliseconds Apr 12 12:40:34 volumio volumio[863]: info: sendMpdCommand status took 2 milliseconds Apr 12 12:40:34 volumio volumio[863]: verbose: ControllerMpd::parseState Apr 12 12:40:34 volumio volumio[863]: verbose: ControllerMpd::parseState Apr 12 12:40:34 volumio volumio[863]: info: ControllerMpd::pushState Apr 12 12:40:34 volumio volumio[863]: info: CoreCommandRouter::servicePushState Apr 12 12:40:34 volumio volumio[863]: info: CoreStateMachine::pushState Apr 12 12:40:34 volumio volumio[863]: info: CoreCommandRouter::volumioPushState Apr 12 12:40:34 volumio volumio[863]: info: CorePlayQueue::getTrack 0 Apr 12 12:40:34 volumio volumio[863]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 12 12:40:34 volumio volumio[863]: verbose: CURRENT POSITION 0 Apr 12 12:40:34 volumio volumio[863]: info: CoreStateMachine::syncState stateService stop Apr 12 12:40:34 volumio volumio[863]: info: CoreStateMachine::syncState currentStatus stop Apr 12 12:40:34 volumio volumio[863]: info: CoreStateMachine::pushState Apr 12 12:40:34 volumio volumio[863]: info: CoreCommandRouter::volumioPushState Apr 12 12:40:34 volumio volumio[863]: info: No code Apr 12 12:40:34 volumio volumio[863]: info: CoreStateMachine::pushState Apr 12 12:40:34 volumio volumio[863]: info: CoreCommandRouter::volumioPushState Apr 12 12:40:34 volumio volumio[863]: info: ControllerMpd::pushState Apr 12 12:40:34 volumio volumio[863]: info: CoreCommandRouter::servicePushState Apr 12 12:40:34 volumio volumio[863]: info: CoreStateMachine::pushState Apr 12 12:40:34 volumio volumio[863]: info: CoreCommandRouter::volumioPushState Apr 12 12:40:34 volumio volumio[863]: info: CorePlayQueue::getTrack 0 Apr 12 12:40:34 volumio volumio[863]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 12 12:40:34 volumio volumio[863]: verbose: CURRENT POSITION 0 Apr 12 12:40:34 volumio volumio[863]: info: CoreStateMachine::syncState stateService stop Apr 12 12:40:34 volumio volumio[863]: info: CoreStateMachine::syncState currentStatus stop Apr 12 12:40:34 volumio volumio[863]: info: CoreStateMachine::pushState Apr 12 12:40:34 volumio volumio[863]: info: CoreCommandRouter::volumioPushState Apr 12 12:40:34 volumio volumio[863]: info: No code Apr 12 12:40:34 volumio volumio[863]: info: CoreStateMachine::pushState Apr 12 12:40:34 volumio volumio[863]: info: CoreCommandRouter::volumioPushState Apr 12 12:40:34 volumio volumio5-onboarding[1421]: time=2026-04-12T12:40:34.536Z level=WARN msg="received unknown player status" component=volumio status="" Apr 12 12:40:34 volumio volumio5-onboarding[1421]: time=2026-04-12T12:40:34.537Z level=WARN msg="received unknown player status" component=volumio status="" Apr 12 12:40:34 volumio volumio5-onboarding[1421]: time=2026-04-12T12:40:34.539Z level=WARN msg="received unknown player status" component=volumio status="" Apr 12 12:40:34 volumio volumio5-onboarding[1421]: time=2026-04-12T12:40:34.540Z level=WARN msg="received unknown player status" component=volumio status="" Apr 12 12:40:34 volumio volumio5-onboarding[1421]: time=2026-04-12T12:40:34.542Z level=WARN msg="received unknown player status" component=volumio status="" Apr 12 12:40:34 volumio volumio[863]: info: ------------------------------ 33ms Apr 12 12:40:34 volumio volumio[863]: info: ------------------------------ 32ms Apr 12 12:40:34 volumio volumio[863]: info: Getting Spotify volume Apr 12 12:40:34 volumio volumio[863]: (node:863) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 12 12:40:34 volumio volumio[863]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 12 12:40:34 volumio volumio[863]: (node:863) 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: 40895) Apr 12 12:40:34 volumio volumio[863]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Apr 12 12:40:35 volumio volumio[863]: info: CoreCommandRouter::volumioGetState Apr 12 12:40:35 volumio volumio[863]: info: Initializing connection to go-librespot Websocket Apr 12 12:40:35 volumio volumio[863]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 12 12:40:35 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 12 12:40:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 124385. Apr 12 12:40:35 volumio systemd[1]: Stopped go-librespot Daemon. Apr 12 12:40:35 volumio systemd[1]: Started go-librespot Daemon. Apr 12 12:40:35 volumio go-librespot[30420]: Librespot-go daemon starting... Apr 12 12:40:35 volumio go-librespot[30420]: time="2026-04-12T12:40:35Z" level=info msg="generated new device id: 5654211e6d53b25fd30a729908f1a9c123a9e7ad" Apr 12 12:40:35 volumio go-librespot[30420]: time="2026-04-12T12:40:35Z" level=debug msg="stored credentials found for 31mvnzn5yiy6ejh4emnlwctzi2mi" Apr 12 12:40:35 volumio go-librespot[30420]: time="2026-04-12T12:40:35Z" level=debug msg="obtained new client token: AADhjKx0cDem0j2arNRj9nH42wF/k37MINpHVBuv5UR4J/nqEFDsstXLpR6CnRU+QDi7J6sMZQ8fpDMkpEDrzCoMO8ouQrKakiZNCWTBv+JuHpZSrsnZvXL1knMXg51wIXHgQOhKGlPQ0NLkOIJTPahPIAhwyTMqpMWQFeSg/N3gBTRCuuFiBh3hvxBC6OGrDbRfdWtUJ/1EptS7LIQSqLynaOHObixa27XvAPZKj9Dvow46te/vei13qN6RGC8=" Apr 12 12:40:35 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 12 12:40:35 volumio go-librespot[30420]: time="2026-04-12T12:40:35Z" 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]" Apr 12 12:40:35 volumio go-librespot[30420]: time="2026-04-12T12:40:35Z" level=debug msg="completed keyexchange" Apr 12 12:40:36 volumio go-librespot[30420]: time="2026-04-12T12:40:36Z" level=debug msg="completed challenge" Apr 12 12:40:36 volumio go-librespot[30420]: time="2026-04-12T12:40:36Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 12 12:40:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 12:40:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 12:40:38 volumio volumio[863]: info: Initializing connection to go-librespot Websocket Apr 12 12:40:38 volumio volumio[863]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 12 12:40:39 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 12 12:40:39 volumio volumio[863]: info: Disabling MyMusic plugin upnp Apr 12 12:40:39 volumio sudo[30432]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Apr 12 12:40:39 volumio sudo[30432]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 12:40:39 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 12 12:40:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 124386. Apr 12 12:40:39 volumio systemd[1]: Stopped go-librespot Daemon. Apr 12 12:40:39 volumio systemd[1]: Started go-librespot Daemon. Apr 12 12:40:39 volumio go-librespot[30434]: Librespot-go daemon starting... Apr 12 12:40:39 volumio go-librespot[30434]: time="2026-04-12T12:40:39Z" level=info msg="generated new device id: e7503ce0f0dcc8be5e2fb9d831268581a5a68ac6" Apr 12 12:40:39 volumio go-librespot[30434]: time="2026-04-12T12:40:39Z" level=debug msg="stored credentials found for 31mvnzn5yiy6ejh4emnlwctzi2mi" Apr 12 12:40:39 volumio go-librespot[30434]: time="2026-04-12T12:40:39Z" level=debug msg="obtained new client token: AAAs38tEvWh+EcTE44+2G6qioq8I+DmCQbewujUqFkdbut2v+1qkhpzeWfYWyfnd+XrgcqVVMq2iiThyeR5NJGjlRDqTpyqUNOdz11zlGEVKXa0tqU2d7HNqKIO2mMm1LrIVKRmVAykN9F0JmaiFQ1M+Z2KTes5Nj+uxUwP1rVylOED0SYVJyZltNT0sAEvcP+PZ9CnwisiwQCXEAeonDwK7+gRcMna1RDyAD3i1BjEgfZPw0rubYO2D5uidopQ=" Apr 12 12:40:39 volumio go-librespot[30434]: time="2026-04-12T12:40:39Z" 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]" Apr 12 12:40:40 volumio go-librespot[30434]: time="2026-04-12T12:40:40Z" level=debug msg="completed keyexchange" Apr 12 12:40:40 volumio go-librespot[30434]: time="2026-04-12T12:40:40Z" level=debug msg="completed challenge" Apr 12 12:40:40 volumio go-librespot[30434]: time="2026-04-12T12:40:40Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 12 12:40:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 12:40:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 12:40:41 volumio volumio[863]: info: Initializing connection to go-librespot Websocket Apr 12 12:40:41 volumio volumio[863]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 12 12:40:43 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 12 12:40:43 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 12 12:40:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 124387. Apr 12 12:40:43 volumio systemd[1]: Stopped go-librespot Daemon. Apr 12 12:40:43 volumio systemd[1]: Started go-librespot Daemon. Apr 12 12:40:43 volumio go-librespot[30494]: Librespot-go daemon starting... Apr 12 12:40:43 volumio go-librespot[30494]: time="2026-04-12T12:40:43Z" level=info msg="generated new device id: 5f3468d67b217552ffce17551e7895bee6d638fc" Apr 12 12:40:43 volumio go-librespot[30494]: time="2026-04-12T12:40:43Z" level=debug msg="stored credentials found for 31mvnzn5yiy6ejh4emnlwctzi2mi" Apr 12 12:40:44 volumio go-librespot[30494]: time="2026-04-12T12:40:44Z" level=debug msg="obtained new client token: AAD1XvnCRDC/kZEGu419sOT3XT1m89F7TfWJ1cr0fmQQRX/kCrUx9sF/uByndpF47BqAsGuRE7lvq8eGj1kOKJa+7wcNYUIcmEAYhUipNugA9AlCpN3vJ7aFeTwPbt0OCuAl/u1k8fC3MXhvndj2gs8krFrULi00BeOsnml3uNM2ijjToUNYoUt3+SllDr4PTUnOIk+Qk9g6K4g2jUwLSru1XEo/Tz/NIkBv2WvrGIEZ2jB+v8mfa2x+u0QB" Apr 12 12:40:44 volumio volumio[863]: info: Enabling MyMusic plugin upnp Apr 12 12:40:44 volumio volumio[863]: info: Enabling plugin upnp Apr 12 12:40:44 volumio volumio[863]: info: Loading plugin "upnp"... Apr 12 12:40:44 volumio volumio[863]: info: [1775997644093] Starting Upmpd Daemon Apr 12 12:40:44 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 12 12:40:44 volumio volumio[863]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 12 12:40:44 volumio volumio[863]: Error: listen EADDRINUSE: address already in use :::6599 Apr 12 12:40:44 volumio volumio[863]: at Server.setupListenHandle [as _listen2] (net.js:1318:16) Apr 12 12:40:44 volumio volumio[863]: at listenInCluster (net.js:1366:12) Apr 12 12:40:44 volumio volumio[863]: at Server.listen (net.js:1452:7) Apr 12 12:40:44 volumio volumio[863]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Apr 12 12:40:44 volumio volumio[863]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Apr 12 12:40:44 volumio volumio[863]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Apr 12 12:40:44 volumio volumio[863]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Apr 12 12:40:44 volumio volumio[863]: at processTicksAndRejections (internal/process/task_queues.js:75:11) { Apr 12 12:40:44 volumio volumio[863]: code: 'EADDRINUSE', Apr 12 12:40:44 volumio volumio[863]: errno: -98, Apr 12 12:40:44 volumio volumio[863]: syscall: 'listen', Apr 12 12:40:44 volumio volumio[863]: address: '::', Apr 12 12:40:44 volumio volumio[863]: port: 6599 Apr 12 12:40:44 volumio volumio[863]: } Apr 12 12:40:44 volumio volumio[863]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 12 12:40:44 volumio go-librespot[30494]: time="2026-04-12T12:40:44Z" 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]" Apr 12 12:40:44 volumio go-librespot[30494]: time="2026-04-12T12:40:44Z" level=debug msg="completed keyexchange" Apr 12 12:40:44 volumio sudo[30511]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-04-12 12:39 Apr 12 12:40:44 volumio sudo[30511]: 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="e9612ec5034fb2e958508aaefbca2962fd6f6654" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="464fc672d77d3df6ee72b331d36cdf1fa936e1ec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 27 Feb 2026 10:59:40 AM CET" VOLUMIO_VERSION="3.912" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="37c6ab864cb114e1344d540995c69f86"