-- Logs begin at Sat 2025-05-17 23:57:40 CEST, end at Sun 2025-05-18 00:03:42 CEST. -- May 18 00:02:00 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:02:00 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:02:00 bright sudo[5555]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 18 00:02:00 bright sudo[5555]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 00:02:00 bright sudo[5555]: pam_unix(sudo:session): session closed for user root May 18 00:02:00 bright sudo[5557]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 18 00:02:00 bright sudo[5557]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 00:02:00 bright sudo[5557]: pam_unix(sudo:session): session closed for user root May 18 00:02:00 bright volumio[3404]: verbose: New Socket.io Connection to 192.168.1.124 from 192.168.1.27 UA: Mozilla/5.0 (Linux; Android 13; SM-G985F Build/TP1A.220624.014; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.61 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 May 18 00:02:01 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 18 00:02:01 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 18 00:02:01 bright sudo[5563]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 18 00:02:01 bright sudo[5563]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 00:02:01 bright volumio[3404]: info: Initializing connection to go-librespot Websocket May 18 00:02:01 bright volumio[3404]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 18 00:02:01 bright sudo[5563]: pam_unix(sudo:session): session closed for user root May 18 00:02:01 bright sudo[5566]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 18 00:02:01 bright sudo[5566]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 00:02:01 bright sudo[5566]: pam_unix(sudo:session): session closed for user root May 18 00:02:01 bright volumio[3404]: verbose: New Socket.io Connection to 192.168.1.124 from 192.168.1.27 UA: Mozilla/5.0 (Linux; Android 13; SM-G985F Build/TP1A.220624.014; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.61 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 May 18 00:02:01 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 18 00:02:01 bright volumio[3404]: info: CoreCommandRouter::volumioGetVisibleSources May 18 00:02:01 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 18 00:02:01 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:02:01 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:02:01 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 18 00:02:01 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 18 00:02:01 bright volumio[3404]: info: Received Get System Info May 18 00:02:01 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 18 00:02:01 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 00:02:01 bright volumio[3404]: info: Discovery: Getting this device information May 18 00:02:01 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:02:01 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:02:01 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 00:02:01 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:02:01 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:02:01 bright volumio[3404]: info: Listing playlists May 18 00:02:01 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 18 00:02:01 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 18 00:02:01 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 18 00:02:02 bright systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 18 00:02:02 bright systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 47. May 18 00:02:02 bright systemd[1]: Stopped go-librespot Daemon. May 18 00:02:02 bright systemd[1]: Started go-librespot Daemon. May 18 00:02:02 bright go-librespot[5570]: Librespot-go daemon starting... May 18 00:02:02 bright go-librespot[5570]: time="2025-05-18T00:02:02+02:00" level=info msg="generated new device id: d7b1e4d22cbc2c8e4d501ede2b7ab4d81dbf184f" May 18 00:02:02 bright go-librespot[5570]: time="2025-05-18T00:02:02+02:00" level=debug msg="stored credentials found for 11148314974" May 18 00:02:02 bright go-librespot[5570]: time="2025-05-18T00:02:02+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" May 18 00:02:02 bright go-librespot[5570]: time="2025-05-18T00:02:02+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 18 00:02:02 bright go-librespot[5570]: time="2025-05-18T00:02:02+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 18 00:02:02 bright go-librespot[5570]: time="2025-05-18T00:02:02+02:00" level=debug msg="zeroconf server listening on port 37593" May 18 00:02:03 bright go-librespot[5570]: time="2025-05-18T00:02:03+02:00" level=debug msg="obtained new client token: AABuPpaiIzuoTxf8BwTDFw3sDI/F5fDk6aTh2yYridcin69d6+zNdOz89hPkSoRFpvCLbZHc8aEJ1VgPKyQroq9B5UmDA09DXEP5zqNMXCFWc5gU1T1npG/mqekJz0ux8iILpTIY53ka4sb0TzEQK4kgLHq5diy2uNBZwZEJDFQSjhGH+oXmbcnd1yrGjTt6b8TmqGgG61E8V4wBdvXmHVgwbkPbV1YAdU1PSF9T4NHJza3mf7iKfG/le3bc" May 18 00:02:03 bright go-librespot[5570]: time="2025-05-18T00:02:03+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" May 18 00:02:03 bright go-librespot[5570]: time="2025-05-18T00:02:03+02:00" level=debug msg="completed keyexchange" May 18 00:02:03 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard May 18 00:02:03 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 18 00:02:03 bright volumio[3404]: info: Received Get System Info May 18 00:02:03 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 18 00:02:03 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 00:02:03 bright volumio[3404]: info: Discovery: Getting this device information May 18 00:02:03 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:02:03 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:02:03 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 00:02:03 bright go-librespot[5570]: time="2025-05-18T00:02:03+02:00" level=debug msg="completed challenge" May 18 00:02:03 bright go-librespot[5570]: time="2025-05-18T00:02:03+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 18 00:02:03 bright systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 18 00:02:03 bright systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 18 00:02:04 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 18 00:02:04 bright volumio[3404]: info: Received Get System Info May 18 00:02:04 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 18 00:02:04 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 00:02:04 bright volumio[3404]: info: Discovery: Getting this device information May 18 00:02:04 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:02:04 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:02:04 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 00:02:04 bright volumio[3404]: info: Initializing connection to go-librespot Websocket May 18 00:02:04 bright volumio[3404]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 18 00:02:04 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:02:04 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:02:05 bright sudo[5579]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 18 00:02:05 bright sudo[5579]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 00:02:05 bright sudo[5579]: pam_unix(sudo:session): session closed for user root May 18 00:02:05 bright sudo[5582]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 18 00:02:05 bright sudo[5582]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 00:02:05 bright sudo[5582]: pam_unix(sudo:session): session closed for user root May 18 00:02:05 bright volumio[3404]: verbose: New Socket.io Connection to 192.168.1.124 from 192.168.1.27 UA: Mozilla/5.0 (Linux; Android 13; SM-G985F Build/TP1A.220624.014; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.61 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 11 May 18 00:02:05 bright sudo[5587]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 18 00:02:05 bright sudo[5587]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 00:02:05 bright sudo[5587]: pam_unix(sudo:session): session closed for user root May 18 00:02:05 bright sudo[5591]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 18 00:02:05 bright sudo[5591]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 00:02:05 bright sudo[5591]: pam_unix(sudo:session): session closed for user root May 18 00:02:05 bright volumio[3404]: verbose: New Socket.io Connection to 192.168.1.124 from 192.168.1.27 UA: Mozilla/5.0 (Linux; Android 13; SM-G985F Build/TP1A.220624.014; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.61 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 12 May 18 00:02:05 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 18 00:02:06 bright volumio[3404]: info: CoreCommandRouter::volumioGetVisibleSources May 18 00:02:06 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 18 00:02:06 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:02:06 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:02:06 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 18 00:02:06 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 18 00:02:06 bright volumio[3404]: info: Received Get System Info May 18 00:02:06 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 18 00:02:06 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 00:02:06 bright volumio[3404]: info: Discovery: Getting this device information May 18 00:02:06 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:02:06 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:02:06 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 00:02:06 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:02:06 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:02:06 bright volumio[3404]: info: Listing playlists May 18 00:02:06 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 18 00:02:06 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 18 00:02:06 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 18 00:02:06 bright systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 18 00:02:06 bright systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 48. May 18 00:02:06 bright systemd[1]: Stopped go-librespot Daemon. May 18 00:02:06 bright systemd[1]: Started go-librespot Daemon. May 18 00:02:06 bright go-librespot[5594]: Librespot-go daemon starting... May 18 00:02:06 bright go-librespot[5594]: time="2025-05-18T00:02:06+02:00" level=info msg="generated new device id: 71efe423b3a170dbfb0cb344b787e649d7abc5b9" May 18 00:02:06 bright go-librespot[5594]: time="2025-05-18T00:02:06+02:00" level=debug msg="stored credentials found for 11148314974" May 18 00:02:07 bright go-librespot[5594]: time="2025-05-18T00:02:07+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" May 18 00:02:07 bright go-librespot[5594]: time="2025-05-18T00:02:07+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 18 00:02:07 bright go-librespot[5594]: time="2025-05-18T00:02:07+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 18 00:02:07 bright go-librespot[5594]: time="2025-05-18T00:02:07+02:00" level=debug msg="zeroconf server listening on port 39089" May 18 00:02:07 bright go-librespot[5594]: time="2025-05-18T00:02:07+02:00" level=debug msg="obtained new client token: AAAjv2QMUNbKF+uYVcEJIBxkfYJkMe+IS66yaOzYIfu+oWGk2rryqzWwKe46NRLWOaLky4v4Nwn7do65dz2o4GmTm8SU9omxQRYHp1tkcNUrqby3VMPPWblNGlqo7WKiR0Ixir/Yx50Vddwg/bEGuzqMecjRGF2gw0RdtM/lrEq17N6xFBqGyT9dLkqc4P2+RLUuUI7vA+FmX+yev/CuVw6Mx1PTm23fBOrEMmOm8kHI4fme2F3L5YsDmA==" May 18 00:02:07 bright volumio[3404]: info: Initializing connection to go-librespot Websocket May 18 00:02:07 bright go-librespot[5594]: time="2025-05-18T00:02:07+02:00" level=debug msg="new websocket client" May 18 00:02:07 bright volumio[3404]: info: Connection to go-librespot Websocket established May 18 00:02:07 bright go-librespot[5594]: time="2025-05-18T00:02:07+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" May 18 00:02:07 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 18 00:02:07 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 00:02:07 bright volumio[3404]: info: Discovery: Getting this device information May 18 00:02:07 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:02:07 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:02:07 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 00:02:07 bright go-librespot[5594]: time="2025-05-18T00:02:07+02:00" level=debug msg="completed keyexchange" May 18 00:02:07 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard May 18 00:02:07 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 18 00:02:07 bright volumio[3404]: info: Received Get System Info May 18 00:02:07 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 18 00:02:07 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 00:02:07 bright volumio[3404]: info: Discovery: Getting this device information May 18 00:02:07 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:02:07 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:02:07 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 00:02:07 bright volumio[3404]: info: CoreCommandRouter::volumioGetQueue May 18 00:02:07 bright volumio[3404]: info: CoreStateMachine::getQueue May 18 00:02:07 bright volumio[3404]: info: CorePlayQueue::getQueue May 18 00:02:07 bright go-librespot[5594]: time="2025-05-18T00:02:07+02:00" level=debug msg="completed challenge" May 18 00:02:07 bright go-librespot[5594]: time="2025-05-18T00:02:07+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 18 00:02:07 bright systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 18 00:02:07 bright volumio[3404]: info: Connection to go-librespot Websocket closed May 18 00:02:07 bright systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 18 00:02:08 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 18 00:02:08 bright volumio[3404]: info: Received Get System Info May 18 00:02:08 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 18 00:02:08 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 00:02:08 bright volumio[3404]: info: Discovery: Getting this device information May 18 00:02:08 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:02:08 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:02:08 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 00:02:10 bright volumio[3404]: info: Getting Spotify volume May 18 00:02:10 bright volumio[3404]: (node:3404) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 May 18 00:02:10 bright volumio[3404]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) May 18 00:02:10 bright volumio[3404]: (node:3404) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 16) May 18 00:02:10 bright volumio[3404]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 13 May 18 00:02:10 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:02:10 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:02:10 bright volumio[3404]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 May 18 00:02:10 bright volumio[3404]: info: Initializing connection to go-librespot Websocket May 18 00:02:10 bright volumio[3404]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 18 00:02:11 bright systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 18 00:02:11 bright systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 49. May 18 00:02:11 bright systemd[1]: Stopped go-librespot Daemon. May 18 00:02:11 bright systemd[1]: Started go-librespot Daemon. May 18 00:02:11 bright go-librespot[5623]: Librespot-go daemon starting... May 18 00:02:11 bright go-librespot[5623]: time="2025-05-18T00:02:11+02:00" level=info msg="generated new device id: 6b5db7571c93ed1f546e79ead5823db5bce1a49d" May 18 00:02:11 bright go-librespot[5623]: time="2025-05-18T00:02:11+02:00" level=debug msg="stored credentials found for 11148314974" May 18 00:02:11 bright go-librespot[5623]: time="2025-05-18T00:02:11+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" May 18 00:02:11 bright go-librespot[5623]: time="2025-05-18T00:02:11+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 18 00:02:11 bright go-librespot[5623]: time="2025-05-18T00:02:11+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 18 00:02:11 bright go-librespot[5623]: time="2025-05-18T00:02:11+02:00" level=debug msg="zeroconf server listening on port 40331" May 18 00:02:11 bright go-librespot[5623]: time="2025-05-18T00:02:11+02:00" level=debug msg="obtained new client token: AADzTtlIQuB6Pp+pX4fLr/M3OrIwKICqUqhu+GlL3q0a0YHMznTtQMYk30K9wPvgNPX87AVDH3iIvZVUHlShjAuGqm+EBYrStHRuVMROH69bta4W6wO14QKCaB0HxsvFA9fHqk3/q3J3UrDp6blSmWtirwKSmxtO0EKWsLckTw7Q4Vxt3noC2Gdv4qYaorkgGngQIsbtxYWC72Q/kMdE0xIw76dvsWKtSIufF5tsBCzXsmQLFUlF0yikHQrW" May 18 00:02:11 bright go-librespot[5623]: time="2025-05-18T00:02:11+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" May 18 00:02:11 bright go-librespot[5623]: time="2025-05-18T00:02:11+02:00" level=debug msg="completed keyexchange" May 18 00:02:12 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 18 00:02:12 bright go-librespot[5623]: time="2025-05-18T00:02:12+02:00" level=debug msg="completed challenge" May 18 00:02:12 bright go-librespot[5623]: time="2025-05-18T00:02:12+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 18 00:02:12 bright systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 18 00:02:12 bright systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 18 00:02:13 bright volumio[3404]: info: Initializing connection to go-librespot Websocket May 18 00:02:13 bright volumio[3404]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 18 00:02:14 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri May 18 00:02:14 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 18 00:02:14 bright volumio[3404]: info: Preload queue cleared May 18 00:02:15 bright systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 18 00:02:15 bright systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50. May 18 00:02:15 bright systemd[1]: Stopped go-librespot Daemon. May 18 00:02:15 bright systemd[1]: Started go-librespot Daemon. May 18 00:02:15 bright go-librespot[5631]: Librespot-go daemon starting... May 18 00:02:15 bright go-librespot[5631]: time="2025-05-18T00:02:15+02:00" level=info msg="generated new device id: 283a3aa8a1b74021c23c5be646dd8a6c3aef7c24" May 18 00:02:15 bright go-librespot[5631]: time="2025-05-18T00:02:15+02:00" level=debug msg="stored credentials found for 11148314974" May 18 00:02:15 bright go-librespot[5631]: time="2025-05-18T00:02:15+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" May 18 00:02:15 bright go-librespot[5631]: time="2025-05-18T00:02:15+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 18 00:02:15 bright go-librespot[5631]: time="2025-05-18T00:02:15+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 18 00:02:15 bright go-librespot[5631]: time="2025-05-18T00:02:15+02:00" level=debug msg="zeroconf server listening on port 37651" May 18 00:02:15 bright go-librespot[5631]: time="2025-05-18T00:02:15+02:00" level=debug msg="obtained new client token: AADF4SIB5agD4Y174qc3dQ2ObDmCnTH6I9q1fQ2mHaQCVUDU7tzJmhqXVpMtFjQM1GOIdW1HD61s2EyyUIXpYZtxWeDdDvwq6jGJzAt/GCktyYek7VxryCYPc9CLylNsZ+5hmHiedEuYmrLuzO1oaBqFDL3cjulST9IzS1X3XX4Hpmotmi6aqyoQFnU9dR3Dl3j3AikqDjVFnSaWzXxIWUcR4XegVNraVxpXs7hT6UqoCJIXzBemd9uYnfqm" May 18 00:02:15 bright go-librespot[5631]: time="2025-05-18T00:02:15+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" May 18 00:02:15 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 18 00:02:15 bright go-librespot[5631]: time="2025-05-18T00:02:15+02:00" level=debug msg="completed keyexchange" May 18 00:02:16 bright go-librespot[5631]: time="2025-05-18T00:02:16+02:00" level=debug msg="completed challenge" May 18 00:02:16 bright go-librespot[5631]: time="2025-05-18T00:02:16+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 18 00:02:16 bright systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 18 00:02:16 bright systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 18 00:02:16 bright volumio[3404]: info: Initializing connection to go-librespot Websocket May 18 00:02:16 bright volumio[3404]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 18 00:02:17 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 18 00:02:17 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 00:02:17 bright volumio[3404]: info: Discovery: Getting this device information May 18 00:02:17 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:02:17 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:02:17 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 00:02:17 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri May 18 00:02:18 bright volumio[3404]: info: Preload queue cleared May 18 00:02:19 bright systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 18 00:02:19 bright systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 51. May 18 00:02:19 bright systemd[1]: Stopped go-librespot Daemon. May 18 00:02:19 bright systemd[1]: Started go-librespot Daemon. May 18 00:02:19 bright go-librespot[5640]: Librespot-go daemon starting... May 18 00:02:19 bright go-librespot[5640]: time="2025-05-18T00:02:19+02:00" level=info msg="generated new device id: 0dffa12b18ed90be07c671806369fa66fc4b9127" May 18 00:02:19 bright go-librespot[5640]: time="2025-05-18T00:02:19+02:00" level=debug msg="stored credentials found for 11148314974" May 18 00:02:19 bright go-librespot[5640]: time="2025-05-18T00:02:19+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" May 18 00:02:19 bright go-librespot[5640]: time="2025-05-18T00:02:19+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 18 00:02:19 bright go-librespot[5640]: time="2025-05-18T00:02:19+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 18 00:02:19 bright go-librespot[5640]: time="2025-05-18T00:02:19+02:00" level=debug msg="zeroconf server listening on port 42649" May 18 00:02:19 bright volumio[3404]: info: Initializing connection to go-librespot Websocket May 18 00:02:19 bright go-librespot[5640]: time="2025-05-18T00:02:19+02:00" level=debug msg="new websocket client" May 18 00:02:19 bright volumio[3404]: info: Connection to go-librespot Websocket established May 18 00:02:19 bright go-librespot[5640]: time="2025-05-18T00:02:19+02:00" level=debug msg="obtained new client token: AACMVlzFmB+uAhcPF4LJB5DXNA0oqoSrxmPFocDqThy/k7OKnXs18M7SwArjlw5lpxtwthBCVS9JCXuG8KZTAaKoO0wH0bH/aPJUYwDVnk7Qh3siidanbV0P7ASBv1Dt3e8cdYEc/zuvSS1POrDq7ABGEXJAdZMepf/ZIS5pjUQDKOmlRy8m0RxqtvGCA8eqVDFN6ljfeGQcovFUdZyxMnvqh3lpjAsTjedFTbHmLkvLZUc2VAVhp8XtLast" May 18 00:02:20 bright go-librespot[5640]: time="2025-05-18T00:02:20+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" May 18 00:02:20 bright go-librespot[5640]: time="2025-05-18T00:02:20+02:00" level=debug msg="completed keyexchange" May 18 00:02:20 bright go-librespot[5640]: time="2025-05-18T00:02:20+02:00" level=debug msg="completed challenge" May 18 00:02:20 bright go-librespot[5640]: time="2025-05-18T00:02:20+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 18 00:02:20 bright volumio[3404]: info: Connection to go-librespot Websocket closed May 18 00:02:20 bright systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 18 00:02:20 bright systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 18 00:02:22 bright volumio[3404]: info: Getting Spotify volume May 18 00:02:22 bright volumio[3404]: (node:3404) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 May 18 00:02:22 bright volumio[3404]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) May 18 00:02:22 bright volumio[3404]: (node:3404) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 17) May 18 00:02:22 bright volumio[3404]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 May 18 00:02:22 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:02:22 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:02:23 bright volumio[3404]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 May 18 00:02:23 bright volumio[3404]: info: Initializing connection to go-librespot Websocket May 18 00:02:23 bright volumio[3404]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 18 00:02:23 bright systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 18 00:02:23 bright systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 52. May 18 00:02:23 bright systemd[1]: Stopped go-librespot Daemon. May 18 00:02:23 bright systemd[1]: Started go-librespot Daemon. May 18 00:02:23 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 18 00:02:23 bright volumio[3404]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined May 18 00:02:23 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates May 18 00:02:23 bright go-librespot[5665]: Librespot-go daemon starting... May 18 00:02:23 bright volumio[3404]: info: Received Get System Version May 18 00:02:23 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 18 00:02:23 bright volumio[3404]: info: Received Get System Info May 18 00:02:23 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 18 00:02:23 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 00:02:23 bright volumio[3404]: info: Discovery: Getting this device information May 18 00:02:23 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:02:23 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:02:23 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 00:02:23 bright go-librespot[5665]: time="2025-05-18T00:02:23+02:00" level=info msg="generated new device id: 098402f6b1d4383505edb271d7e689f1e30f880e" May 18 00:02:23 bright go-librespot[5665]: time="2025-05-18T00:02:23+02:00" level=debug msg="stored credentials found for 11148314974" May 18 00:02:24 bright go-librespot[5665]: time="2025-05-18T00:02:24+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" May 18 00:02:24 bright go-librespot[5665]: time="2025-05-18T00:02:24+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 18 00:02:24 bright go-librespot[5665]: time="2025-05-18T00:02:24+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 18 00:02:24 bright go-librespot[5665]: time="2025-05-18T00:02:24+02:00" level=debug msg="zeroconf server listening on port 34205" May 18 00:02:24 bright go-librespot[5665]: time="2025-05-18T00:02:24+02:00" level=debug msg="obtained new client token: AACRekWIXCZtoEI22J6sptIILgxiCZfCEAFaUAB/vGmlzb6nAsffbCdHZfZEYTWaIyDiutgJAZOtxoLIS8CzJVt/Yfq8GDmy25pWL/irAxNcZEFX6d384uF8V0TeW6OhwMyMd5Fbj0n8zPfSH83ArNOC1zqf2MumU/C5QjxIMg4EfRT1uCmcxeR38dqUhNKzQEbIpbD1x05Qkl0Sh4029MI5lmgteQJPl8erwZ6/z5irXx5XDDl7Mk2jkg==" May 18 00:02:24 bright go-librespot[5665]: time="2025-05-18T00:02:24+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" May 18 00:02:24 bright go-librespot[5665]: time="2025-05-18T00:02:24+02:00" level=debug msg="completed keyexchange" May 18 00:02:24 bright go-librespot[5665]: time="2025-05-18T00:02:24+02:00" level=debug msg="completed challenge" May 18 00:02:24 bright go-librespot[5665]: time="2025-05-18T00:02:24+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 18 00:02:24 bright systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 18 00:02:24 bright systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 18 00:02:26 bright volumio[3404]: Searching plugin music_service/webradio May 18 00:02:26 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: webradio , search May 18 00:02:26 bright volumio[3404]: info: Initializing connection to go-librespot Websocket May 18 00:02:26 bright volumio[3404]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 18 00:02:27 bright volumio[3404]: info: All search sources collected, pushing search results May 18 00:02:27 bright volumio[3404]: Searching plugin music_service/webradio May 18 00:02:27 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: webradio , search May 18 00:02:28 bright systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 18 00:02:28 bright systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 53. May 18 00:02:28 bright systemd[1]: Stopped go-librespot Daemon. May 18 00:02:28 bright systemd[1]: Started go-librespot Daemon. May 18 00:02:28 bright go-librespot[5691]: Librespot-go daemon starting... May 18 00:02:28 bright go-librespot[5691]: time="2025-05-18T00:02:28+02:00" level=info msg="generated new device id: e71043ac02537044e138a8d1684370f6b0eb27c9" May 18 00:02:28 bright go-librespot[5691]: time="2025-05-18T00:02:28+02:00" level=debug msg="stored credentials found for 11148314974" May 18 00:02:28 bright volumio[3404]: info: All search sources collected, pushing search results May 18 00:02:28 bright go-librespot[5691]: time="2025-05-18T00:02:28+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" May 18 00:02:28 bright go-librespot[5691]: time="2025-05-18T00:02:28+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 18 00:02:28 bright go-librespot[5691]: time="2025-05-18T00:02:28+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 18 00:02:28 bright go-librespot[5691]: time="2025-05-18T00:02:28+02:00" level=debug msg="zeroconf server listening on port 35719" May 18 00:02:28 bright go-librespot[5691]: time="2025-05-18T00:02:28+02:00" level=debug msg="obtained new client token: AAAGqWtPWg65llXU5LYjHhXlAOwFjfEgCYWKTIbJLDfWBR8uBksBOsX9vKAB3VOVBX46akGnQAO3Upe8GbQN9g7aQ9p5lhDn1EsnX9EFR/dgI1dcGgF31xG6VucPtCpplqKq0EI9O4T79pUZV7kbeuRiI94KNHLnOnTyLiNiDkScVSh+IIu5JKhipJxOJueJ6i6ej7zdT/LeGq1UDCshgB27BTRiiXe72uWcGzW2SJnAjfD6gAcavLFkvBfv" May 18 00:02:28 bright volumio[3404]: Searching plugin music_service/webradio May 18 00:02:28 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: webradio , search May 18 00:02:28 bright go-librespot[5691]: time="2025-05-18T00:02:28+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" May 18 00:02:28 bright go-librespot[5691]: time="2025-05-18T00:02:28+02:00" level=debug msg="completed keyexchange" May 18 00:02:29 bright go-librespot[5691]: time="2025-05-18T00:02:29+02:00" level=debug msg="completed challenge" May 18 00:02:29 bright go-librespot[5691]: time="2025-05-18T00:02:29+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 18 00:02:29 bright systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 18 00:02:29 bright systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 18 00:02:29 bright volumio[3404]: info: All search sources collected, pushing search results May 18 00:02:29 bright volumio[3404]: info: Initializing connection to go-librespot Websocket May 18 00:02:29 bright volumio[3404]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 18 00:02:32 bright systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 18 00:02:32 bright systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 54. May 18 00:02:32 bright systemd[1]: Stopped go-librespot Daemon. May 18 00:02:32 bright systemd[1]: Started go-librespot Daemon. May 18 00:02:32 bright go-librespot[5719]: Librespot-go daemon starting... May 18 00:02:32 bright go-librespot[5719]: time="2025-05-18T00:02:32+02:00" level=info msg="generated new device id: 989902a728f0780214ef619828f86a93abd82e0f" May 18 00:02:32 bright go-librespot[5719]: time="2025-05-18T00:02:32+02:00" level=debug msg="stored credentials found for 11148314974" May 18 00:02:32 bright go-librespot[5719]: time="2025-05-18T00:02:32+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" May 18 00:02:32 bright go-librespot[5719]: time="2025-05-18T00:02:32+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 18 00:02:32 bright go-librespot[5719]: time="2025-05-18T00:02:32+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 18 00:02:32 bright go-librespot[5719]: time="2025-05-18T00:02:32+02:00" level=debug msg="zeroconf server listening on port 43681" May 18 00:02:32 bright volumio[3404]: info: Initializing connection to go-librespot Websocket May 18 00:02:32 bright volumio[3404]: info: Connection to go-librespot Websocket established May 18 00:02:32 bright go-librespot[5719]: time="2025-05-18T00:02:32+02:00" level=debug msg="new websocket client" May 18 00:02:32 bright go-librespot[5719]: time="2025-05-18T00:02:32+02:00" level=debug msg="obtained new client token: AAAQ9XhCHXSu0G9jXyrPkgWqcvvsU5uPxhuqFTMQ65pzXOm/1WOEPYrX4uzUIm3Kfh25AnytV+f04DCSAIYE4iQPj2TpLWTsbxcbTiBC4N6M80unZZknLgC0NAmc3nivDfayjK5A5aJd9K37HLb/UhmMkX5D7Lz6aW42kl4V6f6R6NlE5mqT/yR+zQMBvpa2IcoT7/9JOubPUGPio6MzE7nlxsF6i8OHvTMmPcDTQVbOn3hZuHNzGqa00UaE" May 18 00:02:32 bright go-librespot[5719]: time="2025-05-18T00:02:32+02:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070 (error: dial tcp 104.199.65.9:4070: connect: connection refused), retrying with a different AP" May 18 00:02:32 bright go-librespot[5719]: time="2025-05-18T00:02:32+02:00" level=info msg="connected to ap-gew1.spotify.com:443" May 18 00:02:32 bright go-librespot[5719]: time="2025-05-18T00:02:32+02:00" level=debug msg="completed keyexchange" May 18 00:02:33 bright go-librespot[5719]: time="2025-05-18T00:02:33+02:00" level=debug msg="completed challenge" May 18 00:02:33 bright go-librespot[5719]: time="2025-05-18T00:02:33+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 18 00:02:33 bright volumio[3404]: info: Connection to go-librespot Websocket closed May 18 00:02:33 bright systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 18 00:02:33 bright systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 18 00:02:35 bright volumio[3404]: info: Getting Spotify volume May 18 00:02:35 bright volumio[3404]: (node:3404) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 May 18 00:02:35 bright volumio[3404]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) May 18 00:02:35 bright volumio[3404]: (node:3404) 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: 18) May 18 00:02:35 bright volumio[3404]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 May 18 00:02:35 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:02:35 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:02:35 bright volumio[3404]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 May 18 00:02:36 bright volumio[3404]: info: Initializing connection to go-librespot Websocket May 18 00:02:36 bright volumio[3404]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 18 00:02:36 bright systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 18 00:02:36 bright systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 55. May 18 00:02:36 bright systemd[1]: Stopped go-librespot Daemon. May 18 00:02:36 bright systemd[1]: Started go-librespot Daemon. May 18 00:02:36 bright go-librespot[5728]: Librespot-go daemon starting... May 18 00:02:36 bright go-librespot[5728]: time="2025-05-18T00:02:36+02:00" level=info msg="generated new device id: 66bd8c23cbe1647319c110255f07318e128f73a2" May 18 00:02:36 bright go-librespot[5728]: time="2025-05-18T00:02:36+02:00" level=debug msg="stored credentials found for 11148314974" May 18 00:02:37 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 18 00:02:37 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 00:02:37 bright volumio[3404]: info: Discovery: Getting this device information May 18 00:02:37 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:02:37 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:02:37 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 00:02:37 bright go-librespot[5728]: time="2025-05-18T00:02:37+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" May 18 00:02:37 bright go-librespot[5728]: time="2025-05-18T00:02:37+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 18 00:02:37 bright go-librespot[5728]: time="2025-05-18T00:02:37+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 18 00:02:37 bright go-librespot[5728]: time="2025-05-18T00:02:37+02:00" level=debug msg="zeroconf server listening on port 40537" May 18 00:02:37 bright go-librespot[5728]: time="2025-05-18T00:02:37+02:00" level=debug msg="obtained new client token: AAA95B6jLOe4iOyoOwQo+ulWL+JYeAsmc00j1y2cjDbdXoXeGzKCLJNYGm8O7odd3GzRrVpbJvykGfxZQWLKub9ewsd9A1naI8IFW54eD9w7K9KtxRGsgemCoKLfi+DzoaJW9kgsCMRCIgokCvS3k3QWoY1vu+aDuGBvhvV7xOsYqf/GbfGzudSfXCz3ajizRTKjSbXO6ofLQRqYZ8S59LW0Rm+nBHR6WRiUxatselZtei8dujSBmc8Vog==" May 18 00:02:37 bright go-librespot[5728]: time="2025-05-18T00:02:37+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" May 18 00:02:37 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 18 00:02:37 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 00:02:37 bright volumio[3404]: info: Discovery: Getting this device information May 18 00:02:37 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:02:37 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:02:37 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 00:02:37 bright go-librespot[5728]: time="2025-05-18T00:02:37+02:00" level=debug msg="completed keyexchange" May 18 00:02:37 bright go-librespot[5728]: time="2025-05-18T00:02:37+02:00" level=debug msg="completed challenge" May 18 00:02:37 bright go-librespot[5728]: time="2025-05-18T00:02:37+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 18 00:02:37 bright systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 18 00:02:37 bright systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 18 00:02:39 bright volumio[3404]: info: Initializing connection to go-librespot Websocket May 18 00:02:39 bright volumio[3404]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 18 00:02:41 bright systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 18 00:02:41 bright systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 56. May 18 00:02:41 bright systemd[1]: Stopped go-librespot Daemon. May 18 00:02:41 bright systemd[1]: Started go-librespot Daemon. May 18 00:02:41 bright go-librespot[5761]: Librespot-go daemon starting... May 18 00:02:41 bright go-librespot[5761]: time="2025-05-18T00:02:41+02:00" level=info msg="generated new device id: f73bd3cecbb8281599e9f47c77c86c1a4dcd24b6" May 18 00:02:41 bright go-librespot[5761]: time="2025-05-18T00:02:41+02:00" level=debug msg="stored credentials found for 11148314974" May 18 00:02:41 bright go-librespot[5761]: time="2025-05-18T00:02:41+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" May 18 00:02:41 bright go-librespot[5761]: time="2025-05-18T00:02:41+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 18 00:02:41 bright go-librespot[5761]: time="2025-05-18T00:02:41+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 18 00:02:41 bright go-librespot[5761]: time="2025-05-18T00:02:41+02:00" level=debug msg="zeroconf server listening on port 45269" May 18 00:02:41 bright go-librespot[5761]: time="2025-05-18T00:02:41+02:00" level=debug msg="obtained new client token: AAAhOwOf0SQM/jLSgv+N5F27GJQ3jSS9ojOK6lgqdOXDB5PW6MBeVUUfpN3VNxbDVY9B98/84HP361EmNtmPgRCRdcJsdTaB6pf53+1GpT1tuSdg7dHz7z7w3G2ITIEsosHMjQrdS659ULkR2WSrtMnFyAL0AoBApWKeh1tiljiW1cBgSqjLaCF/zFkA0EMYzpMGErQyXPoAad+aySsizV5ZgtJRkekIKgDiHOHNhaEpr/WTwIDXxzQ9KlzD" May 18 00:02:41 bright go-librespot[5761]: time="2025-05-18T00:02:41+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" May 18 00:02:41 bright go-librespot[5761]: time="2025-05-18T00:02:41+02:00" level=debug msg="completed keyexchange" May 18 00:02:42 bright go-librespot[5761]: time="2025-05-18T00:02:42+02:00" level=debug msg="completed challenge" May 18 00:02:42 bright go-librespot[5761]: time="2025-05-18T00:02:42+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 18 00:02:42 bright systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 18 00:02:42 bright systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 18 00:02:42 bright volumio[3404]: info: Initializing connection to go-librespot Websocket May 18 00:02:42 bright volumio[3404]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 18 00:02:44 bright volumio[3404]: Searching plugin music_service/webradio May 18 00:02:44 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: webradio , search May 18 00:02:44 bright volumio[3404]: info: All search sources collected, pushing search results May 18 00:02:45 bright volumio[3404]: Searching plugin music_service/webradio May 18 00:02:45 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: webradio , search May 18 00:02:45 bright systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 18 00:02:45 bright systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 57. May 18 00:02:45 bright systemd[1]: Stopped go-librespot Daemon. May 18 00:02:45 bright systemd[1]: Started go-librespot Daemon. May 18 00:02:45 bright go-librespot[5816]: Librespot-go daemon starting... May 18 00:02:45 bright go-librespot[5816]: time="2025-05-18T00:02:45+02:00" level=info msg="generated new device id: d7ac485bbcf04ffe52c938f6bc91b21595faf2e8" May 18 00:02:45 bright go-librespot[5816]: time="2025-05-18T00:02:45+02:00" level=debug msg="stored credentials found for 11148314974" May 18 00:02:45 bright volumio[3404]: info: Initializing connection to go-librespot Websocket May 18 00:02:45 bright go-librespot[5816]: time="2025-05-18T00:02:45+02:00" level=debug msg="new websocket client" May 18 00:02:45 bright volumio[3404]: info: Connection to go-librespot Websocket established May 18 00:02:45 bright go-librespot[5816]: time="2025-05-18T00:02:45+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" May 18 00:02:45 bright go-librespot[5816]: time="2025-05-18T00:02:45+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 18 00:02:45 bright go-librespot[5816]: time="2025-05-18T00:02:45+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 18 00:02:45 bright go-librespot[5816]: time="2025-05-18T00:02:45+02:00" level=debug msg="zeroconf server listening on port 33297" May 18 00:02:45 bright go-librespot[5816]: time="2025-05-18T00:02:45+02:00" level=debug msg="obtained new client token: AAALzuthiMsqVrHaXn3WWYNm5wh/6TzjxiAISfeWU9rNO/AwAcOwHt24JXehijVTWq2Q3OSX52Bjcl63JgdmzF9eVLlgztRVL06JxZ2yNc2lPz15sRyU7PeNRpwIliLEZvgbknRbapuK04qSpUYDJfKlvZp9mmtB3MP3vfShQSGDvp6NqhHiaGvdhQlNYdhf3HcfDAY3phRAmgC4Xs1V3VanP7vJT8ZX1HYeVyxHBl3rPpqTQ5nNc/kpGE2V" May 18 00:02:45 bright volumio[3404]: info: All search sources collected, pushing search results May 18 00:02:45 bright go-librespot[5816]: time="2025-05-18T00:02:45+02:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070 (error: dial tcp 104.199.65.9:4070: connect: connection refused), retrying with a different AP" May 18 00:02:45 bright go-librespot[5816]: time="2025-05-18T00:02:45+02:00" level=info msg="connected to ap-gew1.spotify.com:443" May 18 00:02:45 bright go-librespot[5816]: time="2025-05-18T00:02:45+02:00" level=debug msg="completed keyexchange" May 18 00:02:46 bright go-librespot[5816]: time="2025-05-18T00:02:46+02:00" level=debug msg="completed challenge" May 18 00:02:46 bright go-librespot[5816]: time="2025-05-18T00:02:46+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 18 00:02:46 bright volumio[3404]: info: Connection to go-librespot Websocket closed May 18 00:02:46 bright systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 18 00:02:46 bright systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 18 00:02:48 bright volumio[3404]: info: Getting Spotify volume May 18 00:02:48 bright volumio[3404]: (node:3404) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 May 18 00:02:48 bright volumio[3404]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) May 18 00:02:48 bright volumio[3404]: (node:3404) 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: 19) May 18 00:02:48 bright volumio[3404]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 May 18 00:02:48 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:02:48 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:02:48 bright volumio[3404]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 May 18 00:02:49 bright volumio[3404]: info: Initializing connection to go-librespot Websocket May 18 00:02:49 bright volumio[3404]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 18 00:02:49 bright systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 18 00:02:49 bright systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 58. May 18 00:02:49 bright systemd[1]: Stopped go-librespot Daemon. May 18 00:02:49 bright systemd[1]: Started go-librespot Daemon. May 18 00:02:49 bright go-librespot[5836]: Librespot-go daemon starting... May 18 00:02:49 bright go-librespot[5836]: time="2025-05-18T00:02:49+02:00" level=info msg="generated new device id: 8b3ecca97b0012dd7714350f866eebf459e020fc" May 18 00:02:49 bright go-librespot[5836]: time="2025-05-18T00:02:49+02:00" level=debug msg="stored credentials found for 11148314974" May 18 00:02:49 bright go-librespot[5836]: time="2025-05-18T00:02:49+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" May 18 00:02:49 bright go-librespot[5836]: time="2025-05-18T00:02:49+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 18 00:02:49 bright go-librespot[5836]: time="2025-05-18T00:02:49+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 18 00:02:49 bright go-librespot[5836]: time="2025-05-18T00:02:49+02:00" level=debug msg="zeroconf server listening on port 46317" May 18 00:02:49 bright go-librespot[5836]: time="2025-05-18T00:02:49+02:00" level=debug msg="obtained new client token: AACOE/QfR4bSgDjRk2gWHEkt+Cx4EWmnJkjPu4ftEyORYn1DzcHEG0N38ZEpjuXcepst1YeVQhsO/s9bnMrvotjgiDXirk1AjCPrKI8TNJLAv8TpmbbLUnteFX/fEMRxDIw0RLa8HIk+UDv0fj0B3pi8iDGPaIKihl7lO5c2668KNbMwA6SZGivQjsKM+B//Tj8EvNBSoSTKVidO3qhegKzy4EpyWmbBYXNgnNX4D2nK3DDg4Gl5NGrjZfkO" May 18 00:02:50 bright go-librespot[5836]: time="2025-05-18T00:02:50+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" May 18 00:02:50 bright go-librespot[5836]: time="2025-05-18T00:02:50+02:00" level=debug msg="completed keyexchange" May 18 00:02:50 bright go-librespot[5836]: time="2025-05-18T00:02:50+02:00" level=debug msg="completed challenge" May 18 00:02:50 bright go-librespot[5836]: time="2025-05-18T00:02:50+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 18 00:02:50 bright systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 18 00:02:50 bright systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 18 00:02:52 bright volumio[3404]: info: Initializing connection to go-librespot Websocket May 18 00:02:52 bright volumio[3404]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 18 00:02:53 bright systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 18 00:02:53 bright systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 59. May 18 00:02:53 bright systemd[1]: Stopped go-librespot Daemon. May 18 00:02:53 bright systemd[1]: Started go-librespot Daemon. May 18 00:02:53 bright go-librespot[5870]: Librespot-go daemon starting... May 18 00:02:53 bright go-librespot[5870]: time="2025-05-18T00:02:53+02:00" level=info msg="generated new device id: cb78073c3a38d104a422898f3a1b46047b162f0d" May 18 00:02:53 bright go-librespot[5870]: time="2025-05-18T00:02:53+02:00" level=debug msg="stored credentials found for 11148314974" May 18 00:02:54 bright go-librespot[5870]: time="2025-05-18T00:02:54+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" May 18 00:02:54 bright go-librespot[5870]: time="2025-05-18T00:02:54+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 18 00:02:54 bright go-librespot[5870]: time="2025-05-18T00:02:54+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 18 00:02:54 bright go-librespot[5870]: time="2025-05-18T00:02:54+02:00" level=debug msg="zeroconf server listening on port 40615" May 18 00:02:54 bright go-librespot[5870]: time="2025-05-18T00:02:54+02:00" level=debug msg="obtained new client token: AACRNGm/hnXBQgu8pb25drNIRldttp/2s91BBCHOCXRDthA8cN9u9ylc/8h4mE6a3FwbGBWWCg75tC86SsfAUNY4PS/5jywo0nJlmPrGTtMojxTVqZcZTrErt0ntHnEcgZVt5mjUXvnt1DG7/ajryzeeGlqxlZzkK0DRRuijCEUmazYgSt+rb75GnlGdMOYqOJpSWvPp6UI1f6SMr5hgW4xH8M5UzzUK6yVNbnsYMChSWOuzS7K0yBhP3g==" May 18 00:02:54 bright go-librespot[5870]: time="2025-05-18T00:02:54+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" May 18 00:02:54 bright go-librespot[5870]: time="2025-05-18T00:02:54+02:00" level=debug msg="completed keyexchange" May 18 00:02:54 bright go-librespot[5870]: time="2025-05-18T00:02:54+02:00" level=debug msg="completed challenge" May 18 00:02:54 bright go-librespot[5870]: time="2025-05-18T00:02:54+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 18 00:02:54 bright systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 18 00:02:54 bright systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 18 00:02:55 bright volumio[3404]: info: Initializing connection to go-librespot Websocket May 18 00:02:55 bright volumio[3404]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 18 00:02:57 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 18 00:02:57 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 00:02:57 bright volumio[3404]: info: Discovery: Getting this device information May 18 00:02:57 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:02:57 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:02:57 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 00:02:58 bright systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 18 00:02:58 bright systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 60. May 18 00:02:58 bright systemd[1]: Stopped go-librespot Daemon. May 18 00:02:58 bright systemd[1]: Started go-librespot Daemon. May 18 00:02:58 bright go-librespot[5881]: Librespot-go daemon starting... May 18 00:02:58 bright go-librespot[5881]: time="2025-05-18T00:02:58+02:00" level=info msg="generated new device id: 7a651a81dda777ac6fa94ff2a5d63c41e6102802" May 18 00:02:58 bright go-librespot[5881]: time="2025-05-18T00:02:58+02:00" level=debug msg="stored credentials found for 11148314974" May 18 00:02:58 bright go-librespot[5881]: time="2025-05-18T00:02:58+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" May 18 00:02:58 bright go-librespot[5881]: time="2025-05-18T00:02:58+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 18 00:02:58 bright go-librespot[5881]: time="2025-05-18T00:02:58+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 18 00:02:58 bright go-librespot[5881]: time="2025-05-18T00:02:58+02:00" level=debug msg="zeroconf server listening on port 45173" May 18 00:02:58 bright go-librespot[5881]: time="2025-05-18T00:02:58+02:00" level=debug msg="obtained new client token: AABa+CrILDmV+Quy0c5Q9XKlOXfBKEfXz+5Rs/GkxKXERNyC2QY01D5+hXpiJhJtdtXJ1tKxMDNjt850wU7sS6ghd9itOco6S5wv9mc+O73Jhvmed3rMMtiXfZu97UWJsWvY3AASDbjiEqNGqKP/UtgNaLv5w1g+3IA/3tk3I15TMl/6f9i6OjFL1RzqWHXxH22osYMqpNxtZMMRnoyMoGEZVGpKJYE08RRWs4fqYtBPImxlQhDSvXip0WYL" May 18 00:02:58 bright volumio[3404]: info: Initializing connection to go-librespot Websocket May 18 00:02:58 bright go-librespot[5881]: time="2025-05-18T00:02:58+02:00" level=debug msg="new websocket client" May 18 00:02:58 bright volumio[3404]: info: Connection to go-librespot Websocket established May 18 00:02:58 bright go-librespot[5881]: time="2025-05-18T00:02:58+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" May 18 00:02:58 bright go-librespot[5881]: time="2025-05-18T00:02:58+02:00" level=debug msg="completed keyexchange" May 18 00:02:59 bright go-librespot[5881]: time="2025-05-18T00:02:59+02:00" level=debug msg="completed challenge" May 18 00:02:59 bright go-librespot[5881]: time="2025-05-18T00:02:59+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 18 00:02:59 bright systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 18 00:02:59 bright systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 18 00:02:59 bright volumio[3404]: info: Connection to go-librespot Websocket closed May 18 00:03:00 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:03:00 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:03:01 bright sudo[5908]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 18 00:03:01 bright sudo[5908]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 00:03:01 bright sudo[5909]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 18 00:03:01 bright sudo[5909]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 00:03:01 bright sudo[5908]: pam_unix(sudo:session): session closed for user root May 18 00:03:01 bright sudo[5909]: pam_unix(sudo:session): session closed for user root May 18 00:03:01 bright volumio[3404]: verbose: New Socket.io Connection to 192.168.1.124 from 192.168.1.27 UA: Mozilla/5.0 (Linux; Android 13; SM-G985F Build/TP1A.220624.014; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.61 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 May 18 00:03:01 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 18 00:03:01 bright volumio[3404]: info: Getting Spotify volume May 18 00:03:01 bright volumio[3404]: (node:3404) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 May 18 00:03:01 bright volumio[3404]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) May 18 00:03:01 bright volumio[3404]: (node:3404) 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: 20) May 18 00:03:01 bright volumio[3404]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 May 18 00:03:01 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:03:01 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:03:01 bright volumio[3404]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 May 18 00:03:01 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 18 00:03:01 bright sudo[5915]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 18 00:03:01 bright sudo[5915]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 00:03:01 bright sudo[5915]: pam_unix(sudo:session): session closed for user root May 18 00:03:01 bright sudo[5918]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 18 00:03:01 bright sudo[5918]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 00:03:01 bright sudo[5918]: pam_unix(sudo:session): session closed for user root May 18 00:03:01 bright volumio[3404]: verbose: New Socket.io Connection to 192.168.1.124 from 192.168.1.27 UA: Mozilla/5.0 (Linux; Android 13; SM-G985F Build/TP1A.220624.014; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.61 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 11 May 18 00:03:01 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 18 00:03:01 bright volumio[3404]: info: CoreCommandRouter::volumioGetVisibleSources May 18 00:03:01 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 18 00:03:01 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:03:01 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:03:01 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 18 00:03:01 bright volumio[3404]: info: CoreCommandRouter::volumioGetQueue May 18 00:03:01 bright volumio[3404]: info: CoreStateMachine::getQueue May 18 00:03:01 bright volumio[3404]: info: CorePlayQueue::getQueue May 18 00:03:01 bright volumio[3404]: info: Listing playlists May 18 00:03:01 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 18 00:03:01 bright volumio[3404]: info: Received Get System Info May 18 00:03:01 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 18 00:03:01 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 00:03:01 bright volumio[3404]: info: Discovery: Getting this device information May 18 00:03:01 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:03:01 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:03:01 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 00:03:01 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:03:01 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:03:01 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 18 00:03:01 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 18 00:03:02 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 18 00:03:02 bright volumio[3404]: info: Initializing connection to go-librespot Websocket May 18 00:03:02 bright volumio[3404]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 18 00:03:02 bright systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 18 00:03:02 bright systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 61. May 18 00:03:02 bright systemd[1]: Stopped go-librespot Daemon. May 18 00:03:02 bright systemd[1]: Started go-librespot Daemon. May 18 00:03:02 bright go-librespot[5922]: Librespot-go daemon starting... May 18 00:03:02 bright go-librespot[5922]: time="2025-05-18T00:03:02+02:00" level=info msg="generated new device id: 2de13caff8c4ab0df97a22a8a291541329949c4b" May 18 00:03:02 bright go-librespot[5922]: time="2025-05-18T00:03:02+02:00" level=debug msg="stored credentials found for 11148314974" May 18 00:03:02 bright go-librespot[5922]: time="2025-05-18T00:03:02+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" May 18 00:03:02 bright go-librespot[5922]: time="2025-05-18T00:03:02+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 18 00:03:02 bright go-librespot[5922]: time="2025-05-18T00:03:02+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 18 00:03:02 bright go-librespot[5922]: time="2025-05-18T00:03:02+02:00" level=debug msg="zeroconf server listening on port 43943" May 18 00:03:02 bright go-librespot[5922]: time="2025-05-18T00:03:02+02:00" level=debug msg="obtained new client token: AACtP9Th8zE5IE1jXCB3++aKZ661eO0D74rXyJo7r+aZa17nLeeIMEm+ThK+oD4tD89jUpVcg6xdODoMriA8cWRA0OLUBx0X/vhWyddf4qD6w82s/Ak+jFBblDoTnD0oy9VwbaoY3FNg5VB77cPjd+9RpWhLUp7NIdcauhCSjvChSeV0EOe3FBWL8BSX7+sB//Lb+pT+AabCqv0YjkMgQNv2PGglI3JUB6DGycqVj2wfsrxv1xT2TePXVod4" May 18 00:03:02 bright go-librespot[5922]: time="2025-05-18T00:03:02+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" May 18 00:03:02 bright go-librespot[5922]: time="2025-05-18T00:03:02+02:00" level=debug msg="completed keyexchange" May 18 00:03:03 bright go-librespot[5922]: time="2025-05-18T00:03:03+02:00" level=debug msg="completed challenge" May 18 00:03:03 bright go-librespot[5922]: time="2025-05-18T00:03:03+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 18 00:03:03 bright systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 18 00:03:03 bright systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 18 00:03:03 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard May 18 00:03:03 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 18 00:03:03 bright volumio[3404]: info: Received Get System Info May 18 00:03:03 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 18 00:03:03 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 00:03:03 bright volumio[3404]: info: Discovery: Getting this device information May 18 00:03:03 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:03:03 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:03:03 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 00:03:04 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 18 00:03:04 bright volumio[3404]: info: Received Get System Info May 18 00:03:04 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 18 00:03:04 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 00:03:04 bright volumio[3404]: info: Discovery: Getting this device information May 18 00:03:04 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:03:04 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:03:04 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 00:03:05 bright volumio[3404]: info: Initializing connection to go-librespot Websocket May 18 00:03:05 bright volumio[3404]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 18 00:03:06 bright systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 18 00:03:06 bright systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 62. May 18 00:03:06 bright systemd[1]: Stopped go-librespot Daemon. May 18 00:03:06 bright systemd[1]: Started go-librespot Daemon. May 18 00:03:06 bright go-librespot[5938]: Librespot-go daemon starting... May 18 00:03:06 bright go-librespot[5938]: time="2025-05-18T00:03:06+02:00" level=info msg="generated new device id: e12ec93490b082337fbd9f79ca9347a221883734" May 18 00:03:06 bright go-librespot[5938]: time="2025-05-18T00:03:06+02:00" level=debug msg="stored credentials found for 11148314974" May 18 00:03:06 bright go-librespot[5938]: time="2025-05-18T00:03:06+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" May 18 00:03:06 bright go-librespot[5938]: time="2025-05-18T00:03:06+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 18 00:03:06 bright go-librespot[5938]: time="2025-05-18T00:03:06+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 18 00:03:06 bright go-librespot[5938]: time="2025-05-18T00:03:06+02:00" level=debug msg="zeroconf server listening on port 44689" May 18 00:03:07 bright go-librespot[5938]: time="2025-05-18T00:03:07+02:00" level=debug msg="obtained new client token: AACfwGX+cgIoTpkFI3sx24A4gYxYtvneuXWvSaq8onECW+/qIiE5rGKjlUNMJAKjl24/ME3/jfP68CNirYwFMJpBX0+tp4LkzFz8qMvPop/Gy8Dy7Znz7EXH+iWj26h6S18r6naHI7s4o2EHKsl4lxmu7I5V6bwUlM9BHMfiptgenfdokgwQvLMam7Q8PUqyjLe1U2Ce7eiraFd3UpJ8XlHiB1HrxEeJTBat9na0fiXSuUN7qDx8WyovhPKj" May 18 00:03:07 bright go-librespot[5938]: time="2025-05-18T00:03:07+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" May 18 00:03:07 bright go-librespot[5938]: time="2025-05-18T00:03:07+02:00" level=debug msg="completed keyexchange" May 18 00:03:07 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 18 00:03:07 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 00:03:07 bright volumio[3404]: info: Discovery: Getting this device information May 18 00:03:07 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:03:07 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:03:07 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 00:03:07 bright go-librespot[5938]: time="2025-05-18T00:03:07+02:00" level=debug msg="completed challenge" May 18 00:03:07 bright go-librespot[5938]: time="2025-05-18T00:03:07+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 18 00:03:07 bright systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 18 00:03:07 bright systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 18 00:03:08 bright volumio[3404]: info: Initializing connection to go-librespot Websocket May 18 00:03:08 bright volumio[3404]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 18 00:03:10 bright systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 18 00:03:10 bright systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 63. May 18 00:03:10 bright systemd[1]: Stopped go-librespot Daemon. May 18 00:03:10 bright systemd[1]: Started go-librespot Daemon. May 18 00:03:10 bright go-librespot[5967]: Librespot-go daemon starting... May 18 00:03:10 bright go-librespot[5967]: time="2025-05-18T00:03:10+02:00" level=info msg="generated new device id: 1c984a7d4cd03dc3ffe9e9fb76c83a47c969f4eb" May 18 00:03:10 bright go-librespot[5967]: time="2025-05-18T00:03:10+02:00" level=debug msg="stored credentials found for 11148314974" May 18 00:03:11 bright go-librespot[5967]: time="2025-05-18T00:03:11+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" May 18 00:03:11 bright go-librespot[5967]: time="2025-05-18T00:03:11+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 18 00:03:11 bright go-librespot[5967]: time="2025-05-18T00:03:11+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 18 00:03:11 bright go-librespot[5967]: time="2025-05-18T00:03:11+02:00" level=debug msg="zeroconf server listening on port 46429" May 18 00:03:11 bright volumio[3404]: info: Initializing connection to go-librespot Websocket May 18 00:03:11 bright go-librespot[5967]: time="2025-05-18T00:03:11+02:00" level=debug msg="new websocket client" May 18 00:03:11 bright volumio[3404]: info: Connection to go-librespot Websocket established May 18 00:03:11 bright go-librespot[5967]: time="2025-05-18T00:03:11+02:00" level=debug msg="obtained new client token: AABQmHGE6uMJD6IAkQI3CS8JNnJ6fiBinDC8Tbmx+XBCSSeEjDXjt/o//PW6cIpiNf+K8VNsqCQlayq/tQEvb+Kfj2ZqSARpLss7xEuvhE5jgQ3ClnmALMf64mpSIN9b1spcy+s9847A00RW5h4Bfxzfm1tzRaiiVMH2htXqeo3/8zivYhOJRGIPRMjJZMuAAlo/iRBybx8WtRRwJyQe01klBQOP5fO+HRecYoQ23iQf+DHkvZHXdj3SUA==" May 18 00:03:11 bright go-librespot[5967]: time="2025-05-18T00:03:11+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" May 18 00:03:11 bright go-librespot[5967]: time="2025-05-18T00:03:11+02:00" level=debug msg="completed keyexchange" May 18 00:03:11 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 18 00:03:11 bright go-librespot[5967]: time="2025-05-18T00:03:11+02:00" level=debug msg="completed challenge" May 18 00:03:11 bright go-librespot[5967]: time="2025-05-18T00:03:11+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 18 00:03:11 bright systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 18 00:03:11 bright systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 18 00:03:11 bright volumio[3404]: info: Connection to go-librespot Websocket closed May 18 00:03:14 bright volumio[3404]: info: Getting Spotify volume May 18 00:03:14 bright volumio[3404]: (node:3404) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 May 18 00:03:14 bright volumio[3404]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) May 18 00:03:14 bright volumio[3404]: (node:3404) 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: 21) May 18 00:03:14 bright volumio[3404]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 May 18 00:03:14 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:03:14 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:03:14 bright volumio[3404]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 May 18 00:03:14 bright volumio[3404]: info: Initializing connection to go-librespot Websocket May 18 00:03:14 bright volumio[3404]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 18 00:03:15 bright systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 18 00:03:15 bright systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 64. May 18 00:03:15 bright systemd[1]: Stopped go-librespot Daemon. May 18 00:03:15 bright systemd[1]: Started go-librespot Daemon. May 18 00:03:15 bright go-librespot[5975]: Librespot-go daemon starting... May 18 00:03:15 bright go-librespot[5975]: time="2025-05-18T00:03:15+02:00" level=info msg="generated new device id: b0232c84f46006e46e8952279b0287d409277142" May 18 00:03:15 bright go-librespot[5975]: time="2025-05-18T00:03:15+02:00" level=debug msg="stored credentials found for 11148314974" May 18 00:03:15 bright go-librespot[5975]: time="2025-05-18T00:03:15+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" May 18 00:03:15 bright go-librespot[5975]: time="2025-05-18T00:03:15+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 18 00:03:15 bright go-librespot[5975]: time="2025-05-18T00:03:15+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 18 00:03:15 bright go-librespot[5975]: time="2025-05-18T00:03:15+02:00" level=debug msg="zeroconf server listening on port 44859" May 18 00:03:15 bright go-librespot[5975]: time="2025-05-18T00:03:15+02:00" level=debug msg="obtained new client token: AACuzGKsIZ37qsloJ9MQGux+n6FJA9lXSC4qqTWOQL1zQfDnAjy44+StgLU6WvED+vqpOD9bbNCVS8SUIZEHpgGbdjhLlQfi128GEfT1UGGeEX0fmqSiGJBGSSCn+6Nj7pIZdhP/3tHZlxAx9MtPcAHF23t8GcKLN3a/KoXQCtWEBmtDkCir1pi13PrklO4DcPn0/MeYNoBxX3Zjci4saDiJ4xFvLf2J6EqVzNwnLmmTdNlGRF9QuuI1fIGL" May 18 00:03:15 bright go-librespot[5975]: time="2025-05-18T00:03:15+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" May 18 00:03:15 bright go-librespot[5975]: time="2025-05-18T00:03:15+02:00" level=debug msg="completed keyexchange" May 18 00:03:15 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri May 18 00:03:15 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 18 00:03:16 bright volumio[3404]: info: Preload queue cleared May 18 00:03:16 bright go-librespot[5975]: time="2025-05-18T00:03:16+02:00" level=debug msg="completed challenge" May 18 00:03:16 bright go-librespot[5975]: time="2025-05-18T00:03:16+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 18 00:03:16 bright systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 18 00:03:16 bright systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 18 00:03:17 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 18 00:03:17 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 00:03:17 bright volumio[3404]: info: Discovery: Getting this device information May 18 00:03:17 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:03:17 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:03:17 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 00:03:17 bright volumio[3404]: info: Initializing connection to go-librespot Websocket May 18 00:03:17 bright volumio[3404]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 18 00:03:19 bright systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 18 00:03:19 bright systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 65. May 18 00:03:19 bright systemd[1]: Stopped go-librespot Daemon. May 18 00:03:19 bright systemd[1]: Started go-librespot Daemon. May 18 00:03:19 bright go-librespot[5998]: Librespot-go daemon starting... May 18 00:03:19 bright go-librespot[5998]: time="2025-05-18T00:03:19+02:00" level=info msg="generated new device id: 19488a9565e10b380919b8de759bba0a5e0f16a0" May 18 00:03:19 bright go-librespot[5998]: time="2025-05-18T00:03:19+02:00" level=debug msg="stored credentials found for 11148314974" May 18 00:03:19 bright go-librespot[5998]: time="2025-05-18T00:03:19+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" May 18 00:03:19 bright go-librespot[5998]: time="2025-05-18T00:03:19+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 18 00:03:19 bright go-librespot[5998]: time="2025-05-18T00:03:19+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 18 00:03:19 bright go-librespot[5998]: time="2025-05-18T00:03:19+02:00" level=debug msg="zeroconf server listening on port 33179" May 18 00:03:19 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 18 00:03:19 bright volumio[3404]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined May 18 00:03:19 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates May 18 00:03:19 bright volumio[3404]: info: Received Get System Version May 18 00:03:19 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 18 00:03:19 bright volumio[3404]: info: Received Get System Info May 18 00:03:19 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 18 00:03:19 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 00:03:19 bright volumio[3404]: info: Discovery: Getting this device information May 18 00:03:19 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:03:19 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:03:19 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 00:03:19 bright go-librespot[5998]: time="2025-05-18T00:03:19+02:00" level=debug msg="obtained new client token: AACWHBcTT1iBpEbbML6ffIKS7Gpo5lcxTT2sy57wD81h+ZXezBBJn2XwNNXYlgCHc4FfINmC3XR/YCwW5KLZRYVO45PqSJCr7wvdWsfOD3B77+a3mYSZ6ak/4JL94AXcD3n0WMSk0pIcU9qNu8BaOTvb9WNd/lTAUf1mID7JKGYuU7DUM3PRDlpFgC1bE8j7RuTgoXPoQS1hvAyOdssElAC1d7Cp/8uB1h5cxop76FTPeZo1KcoDQHt0Y+pJ" May 18 00:03:19 bright go-librespot[5998]: time="2025-05-18T00:03:19+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" May 18 00:03:19 bright go-librespot[5998]: time="2025-05-18T00:03:19+02:00" level=debug msg="completed keyexchange" May 18 00:03:20 bright go-librespot[5998]: time="2025-05-18T00:03:20+02:00" level=debug msg="completed challenge" May 18 00:03:20 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri May 18 00:03:20 bright volumio[3404]: info: TuneIn handleBrowseUri: tunein/best May 18 00:03:20 bright go-librespot[5998]: time="2025-05-18T00:03:20+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 18 00:03:20 bright systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 18 00:03:20 bright systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 18 00:03:20 bright volumio[3404]: info: Preload queue cleared May 18 00:03:20 bright volumio[3404]: info: Initializing connection to go-librespot Websocket May 18 00:03:20 bright volumio[3404]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 18 00:03:23 bright systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 18 00:03:23 bright systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 66. May 18 00:03:23 bright systemd[1]: Stopped go-librespot Daemon. May 18 00:03:23 bright systemd[1]: Started go-librespot Daemon. May 18 00:03:23 bright go-librespot[6031]: Librespot-go daemon starting... May 18 00:03:23 bright go-librespot[6031]: time="2025-05-18T00:03:23+02:00" level=info msg="generated new device id: 9cdb2098b77017af2f10e2b3df719015cf0a72bd" May 18 00:03:23 bright go-librespot[6031]: time="2025-05-18T00:03:23+02:00" level=debug msg="stored credentials found for 11148314974" May 18 00:03:23 bright go-librespot[6031]: time="2025-05-18T00:03:23+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" May 18 00:03:23 bright go-librespot[6031]: time="2025-05-18T00:03:23+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 18 00:03:23 bright go-librespot[6031]: time="2025-05-18T00:03:23+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 18 00:03:23 bright go-librespot[6031]: time="2025-05-18T00:03:23+02:00" level=debug msg="zeroconf server listening on port 42191" May 18 00:03:23 bright go-librespot[6031]: time="2025-05-18T00:03:23+02:00" level=debug msg="obtained new client token: AABWhWcG1iSqrQRh+1ZZkLnQYZQBmFXpClFOJ9g5YUHdeCU6qpTvF15/WYfkQ51/5x+P40LcJUBgxdErSJyLb0D5ILcsafQZUuKACS/OfHSQDT0sNiqFweilUKmcVLqnlKQr8YYQkswqO2pJmGCZLg/bvToTWIm0tFTa2kF+7urSInWiRp9Z5Ud+68dzTw3cVL8QrSEAt10WJY9tbaWvVFq8dHnPsVsCp00vdfIwVZMs6MbKiWPI2S5RA367" May 18 00:03:23 bright volumio[3404]: info: Initializing connection to go-librespot Websocket May 18 00:03:23 bright go-librespot[6031]: time="2025-05-18T00:03:23+02:00" level=debug msg="new websocket client" May 18 00:03:23 bright volumio[3404]: info: Connection to go-librespot Websocket established May 18 00:03:24 bright go-librespot[6031]: time="2025-05-18T00:03:24+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" May 18 00:03:24 bright go-librespot[6031]: time="2025-05-18T00:03:24+02:00" level=debug msg="completed keyexchange" May 18 00:03:24 bright go-librespot[6031]: time="2025-05-18T00:03:24+02:00" level=debug msg="completed challenge" May 18 00:03:24 bright go-librespot[6031]: time="2025-05-18T00:03:24+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 18 00:03:24 bright volumio[3404]: info: Connection to go-librespot Websocket closed May 18 00:03:24 bright systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 18 00:03:24 bright systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 18 00:03:26 bright volumio[3404]: info: Getting Spotify volume May 18 00:03:27 bright volumio[3404]: (node:3404) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 May 18 00:03:27 bright volumio[3404]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) May 18 00:03:27 bright volumio[3404]: (node:3404) 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: 22) May 18 00:03:27 bright volumio[3404]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 May 18 00:03:27 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:03:27 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:03:27 bright volumio[3404]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 May 18 00:03:27 bright volumio[3404]: info: Initializing connection to go-librespot Websocket May 18 00:03:27 bright volumio[3404]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 18 00:03:27 bright systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 18 00:03:27 bright systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 67. May 18 00:03:27 bright systemd[1]: Stopped go-librespot Daemon. May 18 00:03:27 bright systemd[1]: Started go-librespot Daemon. May 18 00:03:27 bright go-librespot[6039]: Librespot-go daemon starting... May 18 00:03:27 bright go-librespot[6039]: time="2025-05-18T00:03:27+02:00" level=info msg="generated new device id: bb81717d4904ca228e0dcd907db7fbdff92c4ae1" May 18 00:03:27 bright go-librespot[6039]: time="2025-05-18T00:03:27+02:00" level=debug msg="stored credentials found for 11148314974" May 18 00:03:28 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:03:28 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:03:28 bright go-librespot[6039]: time="2025-05-18T00:03:28+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" May 18 00:03:28 bright go-librespot[6039]: time="2025-05-18T00:03:28+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 18 00:03:28 bright go-librespot[6039]: time="2025-05-18T00:03:28+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 18 00:03:28 bright go-librespot[6039]: time="2025-05-18T00:03:28+02:00" level=debug msg="zeroconf server listening on port 43349" May 18 00:03:28 bright go-librespot[6039]: time="2025-05-18T00:03:28+02:00" level=debug msg="obtained new client token: AACCJuLGM9D0rxTq2eefH7n41a84fL1+xCuyEgGumDgHnnvBvUaXvu1BznQP7d10FwhbPDL+yf0s9BY/Dv1DpoqeZr6rDGpeVBMSJfKiRB23414r/hTd3+bVGPz+ImneoFOPhlHCFN7f0eoRGM2CC+dLBuFO6wLn3YIdHCBDwLkF0TFh2AyXTq1Rk07LW6RnAVyd/TdGr5PvfziT7PLZVwKKdYZOZ53Uoiby4ZC2pXV0hoHAk2l/ANIzAw==" May 18 00:03:28 bright go-librespot[6039]: time="2025-05-18T00:03:28+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" May 18 00:03:28 bright go-librespot[6039]: time="2025-05-18T00:03:28+02:00" level=debug msg="completed keyexchange" May 18 00:03:28 bright sudo[6057]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 18 00:03:28 bright sudo[6057]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 00:03:28 bright sudo[6057]: pam_unix(sudo:session): session closed for user root May 18 00:03:28 bright sudo[6059]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 18 00:03:28 bright sudo[6059]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 00:03:28 bright sudo[6059]: pam_unix(sudo:session): session closed for user root May 18 00:03:28 bright volumio[3404]: verbose: New Socket.io Connection to 192.168.1.124 from 192.168.1.27 UA: Mozilla/5.0 (Linux; Android 13; SM-G985F Build/TP1A.220624.014; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.61 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 12 May 18 00:03:28 bright sudo[6068]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 18 00:03:28 bright sudo[6068]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 00:03:28 bright sudo[6068]: pam_unix(sudo:session): session closed for user root May 18 00:03:28 bright sudo[6072]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 18 00:03:28 bright sudo[6072]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 00:03:28 bright sudo[6072]: pam_unix(sudo:session): session closed for user root May 18 00:03:28 bright go-librespot[6039]: time="2025-05-18T00:03:28+02:00" level=debug msg="completed challenge" May 18 00:03:28 bright go-librespot[6039]: time="2025-05-18T00:03:28+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 18 00:03:28 bright systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 18 00:03:28 bright systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 18 00:03:28 bright volumio[3404]: verbose: New Socket.io Connection to 192.168.1.124 from 192.168.1.27 UA: Mozilla/5.0 (Linux; Android 13; SM-G985F Build/TP1A.220624.014; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.61 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 13 May 18 00:03:29 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 18 00:03:29 bright volumio[3404]: info: CoreCommandRouter::volumioGetVisibleSources May 18 00:03:29 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 18 00:03:29 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:03:29 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:03:29 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 18 00:03:29 bright volumio[3404]: info: CoreCommandRouter::volumioGetQueue May 18 00:03:29 bright volumio[3404]: info: CoreStateMachine::getQueue May 18 00:03:29 bright volumio[3404]: info: CorePlayQueue::getQueue May 18 00:03:29 bright volumio[3404]: info: Listing playlists May 18 00:03:29 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 18 00:03:29 bright volumio[3404]: info: Received Get System Info May 18 00:03:29 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 18 00:03:29 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 00:03:29 bright volumio[3404]: info: Discovery: Getting this device information May 18 00:03:29 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:03:29 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:03:29 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 00:03:29 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:03:29 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:03:29 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 18 00:03:29 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 18 00:03:29 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 18 00:03:30 bright volumio[3404]: info: Initializing connection to go-librespot Websocket May 18 00:03:30 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard May 18 00:03:30 bright volumio[3404]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 18 00:03:30 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 18 00:03:30 bright volumio[3404]: info: Received Get System Info May 18 00:03:30 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 18 00:03:30 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 00:03:30 bright volumio[3404]: info: Discovery: Getting this device information May 18 00:03:30 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:03:30 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:03:30 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 00:03:31 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 18 00:03:31 bright volumio[3404]: info: Received Get System Info May 18 00:03:31 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 18 00:03:31 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 00:03:31 bright volumio[3404]: info: Discovery: Getting this device information May 18 00:03:31 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:03:31 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:03:31 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 00:03:32 bright systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 18 00:03:32 bright systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 68. May 18 00:03:32 bright systemd[1]: Stopped go-librespot Daemon. May 18 00:03:32 bright systemd[1]: Started go-librespot Daemon. May 18 00:03:32 bright go-librespot[6092]: Librespot-go daemon starting... May 18 00:03:32 bright go-librespot[6092]: time="2025-05-18T00:03:32+02:00" level=info msg="generated new device id: 7aef32728547c34f3a99b57c062f0f25565fc731" May 18 00:03:32 bright go-librespot[6092]: time="2025-05-18T00:03:32+02:00" level=debug msg="stored credentials found for 11148314974" May 18 00:03:32 bright go-librespot[6092]: time="2025-05-18T00:03:32+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" May 18 00:03:32 bright go-librespot[6092]: time="2025-05-18T00:03:32+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 18 00:03:32 bright go-librespot[6092]: time="2025-05-18T00:03:32+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 18 00:03:32 bright go-librespot[6092]: time="2025-05-18T00:03:32+02:00" level=debug msg="zeroconf server listening on port 36327" May 18 00:03:32 bright go-librespot[6092]: time="2025-05-18T00:03:32+02:00" level=debug msg="obtained new client token: AACJVgYkskNQOcK3NJdNUsraUJGXcdnvJFtvbnsnn8+k5V9mnKx5JB3W79EXAm0banoChMMWzYDWa2070nAn0pRMqSHeOto6Lpzf5Vt8WfvvQnP6SG5gwJFnsgIZjzaV2Qw5nMw7LqallrWKfoow7aZXaIA5f6voAupsKk7LsFNqp0/hdUzp/VA4Jkv/rHqod8wQsA+ECAOTv4jkCQ9GKQaHH33H8bb8SJFXa5Gtb0ck47ERDHN7/lp9B6Kb" May 18 00:03:32 bright go-librespot[6092]: time="2025-05-18T00:03:32+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" May 18 00:03:32 bright go-librespot[6092]: time="2025-05-18T00:03:32+02:00" level=debug msg="completed keyexchange" May 18 00:03:33 bright go-librespot[6092]: time="2025-05-18T00:03:33+02:00" level=debug msg="completed challenge" May 18 00:03:33 bright go-librespot[6092]: time="2025-05-18T00:03:33+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 18 00:03:33 bright systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 18 00:03:33 bright systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 18 00:03:33 bright volumio[3404]: info: Initializing connection to go-librespot Websocket May 18 00:03:33 bright volumio[3404]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 18 00:03:34 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 18 00:03:34 bright volumio[3404]: info: Preload queue cleared May 18 00:03:36 bright systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 18 00:03:36 bright systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 69. May 18 00:03:36 bright systemd[1]: Stopped go-librespot Daemon. May 18 00:03:36 bright systemd[1]: Started go-librespot Daemon. May 18 00:03:36 bright go-librespot[6106]: Librespot-go daemon starting... May 18 00:03:36 bright go-librespot[6106]: time="2025-05-18T00:03:36+02:00" level=info msg="generated new device id: 4b0d3268db2ac5120f10fb748e6b3ec4b6e2d837" May 18 00:03:36 bright go-librespot[6106]: time="2025-05-18T00:03:36+02:00" level=debug msg="stored credentials found for 11148314974" May 18 00:03:36 bright go-librespot[6106]: time="2025-05-18T00:03:36+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" May 18 00:03:36 bright go-librespot[6106]: time="2025-05-18T00:03:36+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 18 00:03:36 bright go-librespot[6106]: time="2025-05-18T00:03:36+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 18 00:03:36 bright go-librespot[6106]: time="2025-05-18T00:03:36+02:00" level=debug msg="zeroconf server listening on port 39391" May 18 00:03:36 bright volumio[3404]: info: Initializing connection to go-librespot Websocket May 18 00:03:36 bright go-librespot[6106]: time="2025-05-18T00:03:36+02:00" level=debug msg="new websocket client" May 18 00:03:36 bright volumio[3404]: info: Connection to go-librespot Websocket established May 18 00:03:36 bright go-librespot[6106]: time="2025-05-18T00:03:36+02:00" level=debug msg="obtained new client token: AADVIlaiOGifhCOo7bjz5xeMUe9gqza8QlbUiL7NOkssAfnk0ZznBoBDGwj3VU0+V4UDa76v6tFDSnPBKDYAQioq7j4PIq4PIswBraYm6LvKL8olO2kN9HAYpihkao9oJ+7h9tGZ9sWglScpU5JB1+nPKNkUm68vrQ/4xPMhPC4fehIRN+KHb2WyVP/osR481qT6MQGa5hPAhqUXHrX7hB6KKA9bRWM5mhiT4V+K4aLWeZMFGbiDDgrZUekq" May 18 00:03:36 bright go-librespot[6106]: time="2025-05-18T00:03:36+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" May 18 00:03:36 bright go-librespot[6106]: time="2025-05-18T00:03:36+02:00" level=debug msg="completed keyexchange" May 18 00:03:37 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 18 00:03:37 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 00:03:37 bright volumio[3404]: info: Discovery: Getting this device information May 18 00:03:37 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:03:37 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:03:37 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 00:03:37 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 18 00:03:37 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 00:03:37 bright volumio[3404]: info: Discovery: Getting this device information May 18 00:03:37 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:03:37 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:03:37 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 00:03:37 bright go-librespot[6106]: time="2025-05-18T00:03:37+02:00" level=debug msg="completed challenge" May 18 00:03:37 bright go-librespot[6106]: time="2025-05-18T00:03:37+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 18 00:03:37 bright systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 18 00:03:37 bright systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 18 00:03:37 bright volumio[3404]: info: Connection to go-librespot Websocket closed May 18 00:03:37 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 18 00:03:38 bright volumio[3404]: info: Preload queue cleared May 18 00:03:38 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 18 00:03:39 bright volumio[3404]: info: Getting Spotify volume May 18 00:03:39 bright volumio[3404]: (node:3404) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 May 18 00:03:39 bright volumio[3404]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) May 18 00:03:39 bright volumio[3404]: (node:3404) 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: 23) May 18 00:03:39 bright volumio[3404]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 13 May 18 00:03:39 bright volumio[3404]: info: CoreCommandRouter::volumioGetState May 18 00:03:39 bright volumio[3404]: info: CorePlayQueue::getTrack 0 May 18 00:03:39 bright volumio[3404]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 May 18 00:03:40 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 18 00:03:40 bright volumio[3404]: info: Initializing connection to go-librespot Websocket May 18 00:03:40 bright volumio[3404]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 18 00:03:40 bright systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 18 00:03:40 bright systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 70. May 18 00:03:40 bright systemd[1]: Stopped go-librespot Daemon. May 18 00:03:40 bright systemd[1]: Started go-librespot Daemon. May 18 00:03:40 bright go-librespot[6134]: Librespot-go daemon starting... May 18 00:03:40 bright go-librespot[6134]: time="2025-05-18T00:03:40+02:00" level=info msg="generated new device id: e6f03e878c10621a7a3bb01fd6be22ebdf17af41" May 18 00:03:40 bright go-librespot[6134]: time="2025-05-18T00:03:40+02:00" level=debug msg="stored credentials found for 11148314974" May 18 00:03:40 bright volumio[3404]: info: Preload queue cleared May 18 00:03:40 bright go-librespot[6134]: time="2025-05-18T00:03:40+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" May 18 00:03:40 bright go-librespot[6134]: time="2025-05-18T00:03:40+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 18 00:03:40 bright go-librespot[6134]: time="2025-05-18T00:03:40+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 18 00:03:40 bright go-librespot[6134]: time="2025-05-18T00:03:40+02:00" level=debug msg="zeroconf server listening on port 39235" May 18 00:03:41 bright go-librespot[6134]: time="2025-05-18T00:03:41+02:00" level=debug msg="obtained new client token: AAC2rsqvh84YrBH8wv6f70rQywLlenIMqJ13ycj/Ryn/BxshQzeMmyeQM8/AAoCDZU9Lq34gXqlvngTqudE280dKb1SvkQsX9QugEmx7Ni8xv3V1g+I0/6Ewiv6r0zS0awPzwifiMOp/FMxhMatPC3mhsXJF8i+oXa/0amAwAW89LwKn+HoFqYytGcRAy24BrPr+WFHdWWjb7uMZH3lWzntsXeasR12UqMsUdUqJR5bZ9Vx1EFWeJbPK3w==" May 18 00:03:41 bright go-librespot[6134]: time="2025-05-18T00:03:41+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" May 18 00:03:41 bright go-librespot[6134]: time="2025-05-18T00:03:41+02:00" level=debug msg="completed keyexchange" May 18 00:03:41 bright go-librespot[6134]: time="2025-05-18T00:03:41+02:00" level=debug msg="completed challenge" May 18 00:03:41 bright go-librespot[6134]: time="2025-05-18T00:03:41+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 18 00:03:41 bright systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 18 00:03:41 bright systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 18 00:03:41 bright volumio[3404]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 18 00:03:42 bright volumio[3404]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 18 00:03:42 bright volumio[3404]: TypeError: Cannot read property 'length' of undefined May 18 00:03:42 bright volumio[3404]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 May 18 00:03:42 bright volumio[3404]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 May 18 00:03:42 bright volumio[3404]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) May 18 00:03:42 bright volumio[3404]: at Parser.emit (events.js:400:28) May 18 00:03:42 bright volumio[3404]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) May 18 00:03:42 bright volumio[3404]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) May 18 00:03:42 bright volumio[3404]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) May 18 00:03:42 bright volumio[3404]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) May 18 00:03:42 bright volumio[3404]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) May 18 00:03:42 bright volumio[3404]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) May 18 00:03:42 bright volumio[3404]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) May 18 00:03:42 bright volumio[3404]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) May 18 00:03:42 bright volumio[3404]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) May 18 00:03:42 bright volumio[3404]: at IncomingMessage.emit (events.js:412:35) May 18 00:03:42 bright volumio[3404]: at endReadableNT (internal/streams/readable.js:1333:12) May 18 00:03:42 bright volumio[3404]: at processTicksAndRejections (internal/process/task_queues.js:82:21) May 18 00:03:42 bright volumio[3404]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 18 00:03:42 bright sudo[6151]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-18 00:02 May 18 00:03:42 bright sudo[6151]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="570c5791513f5bac7da274aba6690c1a961705de" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 13 May 2025 06:24:39 PM CEST" VOLUMIO_VERSION="3.812" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="c8a59422b1bfedffc72f72cef58ad20b"