Jan 11 06:13:00 volumio volumio[15903]: info: [squeezelite_mc] Proxy server started on port 40197 Jan 11 06:13:00 volumio volumio[15903]: info: Preparing to generate the ALSA configuration file Jan 11 06:13:00 volumio volumio[15903]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 06:13:00 volumio volumio[15903]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 11 06:13:00 volumio volumio[15903]: info: Reading ALSA contributions from plugins. Jan 11 06:13:00 volumio volumio[15903]: info: MPD Permissions set Jan 11 06:13:00 volumio volumio[15903]: info: MPD Permissions set Jan 11 06:13:00 volumio volumio[15903]: info: Upmpdcli Daemon Started Jan 11 06:13:00 volumio volumio[15903]: info: Spotify config file written Jan 11 06:13:00 volumio sudo[16294]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 11 06:13:00 volumio sudo[16294]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:00 volumio volumio[15903]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 11 06:13:00 volumio volumio[15903]: info: VolumeController:: Volume=100 Mute =false Jan 11 06:13:00 volumio volumio[15903]: info: CoreStateMachine::pushState Jan 11 06:13:00 volumio volumio[15903]: info: CorePlayQueue::getTrack 0 Jan 11 06:13:00 volumio volumio[15903]: info: CoreCommandRouter::volumioPushState Jan 11 06:13:00 volumio volumio[15903]: info: [squeezelite_mc] Server discovery started Jan 11 06:13:00 volumio volumio[15903]: info: [squeezelite_mc] Player finder started Jan 11 06:13:00 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:00 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:00 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:00 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 06:13:00 volumio volumio[15903]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Jan 11 06:13:00 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 11 06:13:00 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 11 06:13:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:13:00 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:00 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:00 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:00 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:00 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:00 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:00 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:00 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:00 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 06:13:00 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:00 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:00 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:00 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:00 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:00 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:00 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:00 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:00 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:00 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 06:13:00 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:00 volumio volumio[15903]: info: No need to fix Spotify hosts Jan 11 06:13:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:13:00 volumio go-librespot[16300]: go-librespot daemon starting... Jan 11 06:13:00 volumio sudo[16294]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:00 volumio go-librespot[16309]: time="2026-01-11T06:13:00-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 06:13:00 volumio go-librespot[16309]: time="2026-01-11T06:13:00-06:00" level=debug msg="app state loaded" Jan 11 06:13:00 volumio go-librespot[16309]: time="2026-01-11T06:13:00-06:00" level=debug msg="stored credentials not found" Jan 11 06:13:00 volumio go-librespot[16309]: time="2026-01-11T06:13:00-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 06:13:00 volumio volumio[15903]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 11 06:13:00 volumio volumio[15903]: info: Volumio called home Jan 11 06:13:00 volumio volumio[15903]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Jan 11 06:13:00 volumio volumio[15903]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Jan 11 06:13:00 volumio volumio[15903]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf Jan 11 06:13:00 volumio go-librespot[16309]: time="2026-01-11T06:13:00-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 11 06:13:00 volumio go-librespot[16309]: time="2026-01-11T06:13:00-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 11 06:13:00 volumio go-librespot[16309]: time="2026-01-11T06:13:00-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 11 06:13:00 volumio go-librespot[16309]: time="2026-01-11T06:13:00-06:00" level=info msg="zeroconf server listening on port 39491" Jan 11 06:13:00 volumio volumio[15903]: info: Starting Shairport Sync Jan 11 06:13:00 volumio volumio[15903]: info: Starting Shairport Sync Jan 11 06:13:00 volumio sudo[16318]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf Jan 11 06:13:00 volumio sudo[16318]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:00 volumio sudo[16321]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 06:13:00 volumio sudo[16321]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:00 volumio volumio[15903]: info: Starting Shairport Sync Jan 11 06:13:00 volumio sudo[16318]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:00 volumio sudo[16324]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 06:13:00 volumio sudo[16324]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:00 volumio go-librespot[16309]: time="2026-01-11T06:13:00-06:00" level=debug msg="obtained new client token: AACyvRGimk36O3YssZ0jiGAvmzEFlzHqes5Q/y1i8XVxpFsFhTDvFGczPOob449gvCUbLEp5Y4UphN9/EHyXUpBdXtRcELpHWVCwRfDP3LJs9tOXnraTeLhlrZ+5C+uOEXa40SfRei66Uo5ZQ/NTRc5wdw8X3ZRbt+ISbbuRyeiobJiqC+ITsEZlIEV5iJDmABWH6SIWvJjWuUcBtBzEYgGUJZAa1x+Lt+ZxcU5ROlw4iJtoe79kRkSz8Q==" Jan 11 06:13:00 volumio sudo[16327]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 06:13:00 volumio sudo[16327]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:01 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 11 06:13:01 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 11 06:13:01 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 11 06:13:01 volumio systemd[1]: shairport-sync.service: Consumed 1.917s CPU time. Jan 11 06:13:01 volumio volumio[15903]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 11 06:13:01 volumio volumio[15903]: SPOTIFY: BQDeXVElX-kAAE7Xp2OnUDfM8Y8yPcvhiwTc_P4DaZ8_NWLOP0YOVjJxJ1tACBhoZYBm0mXyzLxL1ow9YrgFPPBi6DNDS084LYKtzaH_oZGEIEAcWfvp9_I5dh4-ytQT-GSyvVmARJf2hm8ndg_pRXEH_6tffqShlq6zWMYlWI-PBapHj9FCGSuj_NJSFrcvkNKpVO5j0PJGNDwAdGroH3toq8Vn1hBVqBJzqAQ Jan 11 06:13:01 volumio volumio[15903]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 11 06:13:01 volumio volumio[15903]: info: New Spotify access token = BQDeXVElX-kAAE7Xp2OnUDfM8Y8yPcvhiwTc_P4DaZ8_NWLOP0YOVjJxJ1tACBhoZYBm0mXyzLxL1ow9YrgFPPBi6DNDS084LYKtzaH_oZGEIEAcWfvp9_I5dh4-ytQT-GSyvVmARJf2hm8ndg_pRXEH_6tffqShlq6zWMYlWI-PBapHj9FCGSuj_NJSFrcvkNKpVO5j0PJGNDwAdGroH3toq8Vn1hBVqBJzqAQ Jan 11 06:13:01 volumio volumio[15903]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 11 06:13:01 volumio go-librespot[16309]: time="2026-01-11T06:13:01-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 06:13:01 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.168.147 Jan 11 06:13:01 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 11 06:13:01 volumio avahi-daemon[664]: Registering new address record for 169.254.168.147 on eth0.IPv4. Jan 11 06:13:01 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 11 06:13:01 volumio go-librespot[16309]: time="2026-01-11T06:13:01-06:00" level=debug msg="completed keyexchange" Jan 11 06:13:01 volumio sudo[16321]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:01 volumio go-librespot[16309]: time="2026-01-11T06:13:01-06:00" level=debug msg="completed challenge" Jan 11 06:13:01 volumio sudo[16324]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:01 volumio go-librespot[16309]: time="2026-01-11T06:13:01-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 11 06:13:01 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:01 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 06:13:01 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:01 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 11 06:13:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 06:13:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 06:13:01 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 11 06:13:01 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 11 06:13:01 volumio volumio[15903]: info: Shairport-Sync Started Jan 11 06:13:01 volumio volumio[15903]: Error adding Membership: Error: addMembership EINVAL Jan 11 06:13:01 volumio volumio[15903]: info: Shairport-Sync Started Jan 11 06:13:01 volumio volumio[15903]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Jan 11 06:13:01 volumio volumio[15903]: info: Asound.conf file unchanged, so no further update is needed Jan 11 06:13:01 volumio volumio[15903]: info: Output device has changed, restarting MPD Jan 11 06:13:01 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 11 06:13:01 volumio sudo[16327]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:01 volumio sudo[16351]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Jan 11 06:13:01 volumio sudo[16351]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:01 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.168.147 Jan 11 06:13:01 volumio volumio[15903]: info: Output device has changed, restarting Shairport Sync Jan 11 06:13:01 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:01 volumio sudo[16354]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 06:13:01 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 06:13:01 volumio sudo[16354]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:01 volumio sudo[16354]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:01 volumio sudo[16357]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 06:13:01 volumio sudo[16357]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:01 volumio volumio[15903]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 06:13:01 volumio sudo[16351]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:01 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.168.147 Jan 11 06:13:01 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.168.147 Jan 11 06:13:01 volumio avahi-daemon[664]: Withdrawing address record for 169.254.168.147 on eth0. Jan 11 06:13:01 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 11 06:13:01 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 11 06:13:01 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:01 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 06:13:01 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:01 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 11 06:13:01 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 11 06:13:01 volumio systemd[1]: mpd.service: Consumed 1.815s CPU time. Jan 11 06:13:01 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 11 06:13:01 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 11 06:13:01 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 11 06:13:01 volumio volumio[15903]: info: MPD Permissions set Jan 11 06:13:01 volumio volumio[15903]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Jan 11 06:13:01 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 11 06:13:01 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 11 06:13:01 volumio volumio[15903]: info: Shairport-Sync Started Jan 11 06:13:01 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:01 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:01 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:01 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:01 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:01 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:01 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:01 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:01 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 06:13:01 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:01 volumio sudo[16401]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Jan 11 06:13:01 volumio sudo[16401]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:01 volumio volumio[15903]: info: CoreCommandRouter::volumioGetState Jan 11 06:13:01 volumio sudo[16401]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:01 volumio volumio[15903]: info: CorePlayQueue::getTrack 0 Jan 11 06:13:01 volumio volumio[15903]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Jan 11 06:13:01 volumio volumio[15903]: info: Starting Shairport Sync Jan 11 06:13:01 volumio sudo[16409]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Jan 11 06:13:01 volumio sudo[16409]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:01 volumio volumio[15903]: SPOTIFY: User informations: {"display_name":"Clint Smith","external_urls":{"spotify":"https://open.spotify.com/user/clintsmith1"},"followers":{"href":null,"total":7},"href":"https://api.spotify.com/v1/users/clintsmith1","id":"clintsmith1","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee856520409d25d9cc210472a0fd","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b826520409d25d9cc210472a0fd","width":64}],"type":"user","uri":"spotify:user:clintsmith1"} Jan 11 06:13:01 volumio volumio[15903]: info: Spotify Successfully logged in Jan 11 06:13:01 volumio volumio[15903]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 06:13:01 volumio volumio[15903]: info: [1768133581954] CoreMusicLibrary::Adding element Spotify Jan 11 06:13:01 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:13:01 volumio volumio[15903]: Cannot find translation for source Bandcamp Discover Jan 11 06:13:01 volumio volumio[15903]: Cannot find translation for source SoundCloud Jan 11 06:13:01 volumio volumio[15903]: Cannot find translation for source YouTube2 Jan 11 06:13:01 volumio volumio[15903]: Cannot find translation for source YouTube Music Jan 11 06:13:01 volumio volumio[15903]: Cannot find translation for source Podcast Jan 11 06:13:01 volumio volumio[15903]: Cannot find translation for source Volusonic Jan 11 06:13:01 volumio volumio[15903]: Cannot find translation for source Spotify Jan 11 06:13:02 volumio sudo[16399]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 11 06:13:02 volumio sudo[16399]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 11 06:13:02 volumio sudo[16399]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:02 volumio sudo[16411]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 06:13:02 volumio sudo[16411]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:02 volumio systemd[1]: Reloading. Jan 11 06:13:02 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:02 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:02 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:02 volumio volumio[15903]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 06:13:03 volumio volumio[15903]: info: go-librespot daemon successfully initialized Jan 11 06:13:05 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 11 06:13:05 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 11 06:13:05 volumio sudo[16409]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:05 volumio volumio[15903]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 11 06:13:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 11 06:13:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:13:05 volumio sudo[16448]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 11 06:13:05 volumio sudo[16448]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:13:05 volumio go-librespot[16449]: go-librespot daemon starting... Jan 11 06:13:05 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 11 06:13:05 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 11 06:13:05 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 11 06:13:05 volumio systemd[1]: shairport-sync.service: Consumed 1.473s CPU time. Jan 11 06:13:05 volumio go-librespot[16451]: time="2026-01-11T06:13:05-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 06:13:05 volumio go-librespot[16451]: time="2026-01-11T06:13:05-06:00" level=debug msg="app state loaded" Jan 11 06:13:05 volumio go-librespot[16451]: time="2026-01-11T06:13:05-06:00" level=debug msg="stored credentials not found" Jan 11 06:13:05 volumio go-librespot[16451]: time="2026-01-11T06:13:05-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 06:13:05 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 11 06:13:05 volumio sudo[16411]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:05 volumio volumio[15903]: info: Shairport-Sync Started Jan 11 06:13:05 volumio sudo[16448]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:05 volumio volumio[15903]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Jan 11 06:13:05 volumio sudo[16472]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Jan 11 06:13:05 volumio sudo[16472]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:05 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Jan 11 06:13:05 volumio go-librespot[16451]: time="2026-01-11T06:13:05-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 11 06:13:05 volumio go-librespot[16451]: time="2026-01-11T06:13:05-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 11 06:13:05 volumio go-librespot[16451]: time="2026-01-11T06:13:05-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 11 06:13:05 volumio go-librespot[16451]: time="2026-01-11T06:13:05-06:00" level=info msg="zeroconf server listening on port 39431" Jan 11 06:13:05 volumio systemd[1]: squeezelite.service: Deactivated successfully. Jan 11 06:13:05 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Jan 11 06:13:06 volumio sudo[16472]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:06 volumio go-librespot[16451]: time="2026-01-11T06:13:06-06:00" level=debug msg="obtained new client token: AADWzeJx2Yqu4dV8jHJ6ISxe6FUa3zMpytzTAK5W3F2o4in5AHQyDfVIRTy+TfZbHFLCww3ok/gfI7cKlCBqcGtUMRDjmsbMWj+s16XIiCqTGUzHNqa9o65BR4NdXUbARmzZC9nIGMzayPU/sW03wmFrF6NRVl+jRYQyqDrXVsrbJ3Ply9eOoow3fZUfErKqkUazFc43ceXl7zEueza4PZS/azSYOtGUMhoqIJTHUOmF3DJhvnj+T04=" Jan 11 06:13:06 volumio go-librespot[16451]: time="2026-01-11T06:13:06-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 06:13:06 volumio go-librespot[16451]: time="2026-01-11T06:13:06-06:00" level=debug msg="completed keyexchange" Jan 11 06:13:06 volumio go-librespot[16451]: time="2026-01-11T06:13:06-06:00" level=debug msg="completed challenge" Jan 11 06:13:06 volumio go-librespot[16451]: time="2026-01-11T06:13:06-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 11 06:13:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 06:13:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 06:13:06 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.230.254 Jan 11 06:13:06 volumio avahi-daemon[664]: Registering new address record for 169.254.230.254 on eth0.IPv4. Jan 11 06:13:06 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 11 06:13:06 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:06 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 06:13:06 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:06 volumio volumio[15903]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 11 06:13:06 volumio sudo[16493]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 11 06:13:06 volumio sudo[16493]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:06 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.230.254 Jan 11 06:13:06 volumio sudo[16493]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:06 volumio volumio[15903]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Jan 11 06:13:06 volumio sudo[16497]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Jan 11 06:13:06 volumio sudo[16497]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:06 volumio sudo[16497]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:06 volumio volumio[15903]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Jan 11 06:13:06 volumio volumio[15903]: info: Initializing connection to go-librespot Websocket Jan 11 06:13:06 volumio sudo[16500]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Jan 11 06:13:06 volumio sudo[16500]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:06 volumio volumio[15903]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 11 06:13:06 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Jan 11 06:13:06 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Jan 11 06:13:06 volumio mpd[16419]: 2026-01-11T06:13:06 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 11 06:13:06 volumio sudo[16500]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:07 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.230.254 Jan 11 06:13:07 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.230.254 Jan 11 06:13:07 volumio avahi-daemon[664]: Withdrawing address record for 169.254.230.254 on eth0. Jan 11 06:13:07 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 11 06:13:07 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 11 06:13:07 volumio sudo[16248]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:07 volumio sudo[16260]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:07 volumio sudo[16357]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:07 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 11 06:13:07 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:07 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 06:13:07 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:07 volumio volumio[15903]: error: MPD error: The expression evaluated to a falsy value: Jan 11 06:13:07 volumio volumio[15903]: assert.ok(self.idling) Jan 11 06:13:07 volumio volumio[15903]: error: The expression evaluated to a falsy value: Jan 11 06:13:07 volumio volumio[15903]: assert.ok(self.idling) Jan 11 06:13:07 volumio volumio[15903]: error: MPD error: The expression evaluated to a falsy value: Jan 11 06:13:07 volumio volumio[15903]: assert.ok(self.idling) Jan 11 06:13:07 volumio volumio[15903]: error: The expression evaluated to a falsy value: Jan 11 06:13:07 volumio volumio[15903]: assert.ok(self.idling) Jan 11 06:13:07 volumio volumio[15903]: info: MPD running with PID16419 Jan 11 06:13:07 volumio volumio[15903]: ,establishing connection Jan 11 06:13:07 volumio volumio[15903]: error: updateQueue error: null Jan 11 06:13:07 volumio volumio[15903]: error: updateQueue error: null Jan 11 06:13:07 volumio volumio[15903]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 11 06:13:07 volumio sudo[16527]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 11 06:13:07 volumio sudo[16527]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:07 volumio sudo[16527]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:08 volumio volumio[15903]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 11 06:13:08 volumio sudo[16530]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 11 06:13:08 volumio sudo[16530]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:08 volumio sudo[16530]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:08 volumio volumio[15903]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 11 06:13:08 volumio sudo[16533]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 11 06:13:08 volumio sudo[16533]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:08 volumio sudo[16533]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:09 volumio kernel: hwmon hwmon1: Voltage normalised Jan 11 06:13:09 volumio volumio[15903]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 11 06:13:09 volumio sudo[16537]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 11 06:13:09 volumio sudo[16537]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 11 06:13:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:13:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:13:09 volumio go-librespot[16539]: go-librespot daemon starting... Jan 11 06:13:09 volumio sudo[16537]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:09 volumio go-librespot[16540]: time="2026-01-11T06:13:09-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 06:13:09 volumio go-librespot[16540]: time="2026-01-11T06:13:09-06:00" level=debug msg="app state loaded" Jan 11 06:13:09 volumio go-librespot[16540]: time="2026-01-11T06:13:09-06:00" level=debug msg="stored credentials not found" Jan 11 06:13:09 volumio go-librespot[16540]: time="2026-01-11T06:13:09-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 06:13:09 volumio go-librespot[16540]: time="2026-01-11T06:13:09-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 11 06:13:09 volumio go-librespot[16540]: time="2026-01-11T06:13:09-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 11 06:13:09 volumio go-librespot[16540]: time="2026-01-11T06:13:09-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 11 06:13:09 volumio go-librespot[16540]: time="2026-01-11T06:13:09-06:00" level=info msg="zeroconf server listening on port 46077" Jan 11 06:13:09 volumio go-librespot[16540]: time="2026-01-11T06:13:09-06:00" level=debug msg="obtained new client token: AAAzRWGsz3b3UgZCOixq6bky/b8Bw4QeWaIcVZr8KmDmnRUrStV0tdpDYu5HcDOguqnoS3LT4sVUOQfkDmj/f+trvDnYNgWbtNK/JtTTyDglPQj6A7Ofov5Qz3Wnb0CcdpnX/1HK+nEkM7D4iUSy8iesgQnLB01UH8O9vdgNa8QGuk1GYbtZvC0V+R+lDX4zwwqAII+I5orPHxGR2uO/GJxMx5GZQHWU4hCbOgqPOpCo3i/EeaTXjxAQhw==" Jan 11 06:13:09 volumio go-librespot[16540]: time="2026-01-11T06:13:09-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 06:13:09 volumio volumio[15903]: info: Initializing connection to go-librespot Websocket Jan 11 06:13:09 volumio go-librespot[16540]: time="2026-01-11T06:13:09-06:00" level=debug msg="new websocket client" Jan 11 06:13:09 volumio go-librespot[16540]: time="2026-01-11T06:13:09-06:00" level=debug msg="completed keyexchange" Jan 11 06:13:09 volumio go-librespot[16540]: time="2026-01-11T06:13:09-06:00" level=debug msg="completed challenge" Jan 11 06:13:09 volumio volumio[15903]: info: Connection to go-librespot Websocket established Jan 11 06:13:09 volumio go-librespot[16540]: time="2026-01-11T06:13:09-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 11 06:13:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 06:13:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 06:13:09 volumio volumio[15903]: info: Connection to go-librespot Websocket closed Jan 11 06:13:09 volumio volumio[15903]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 11 06:13:09 volumio sudo[16548]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 11 06:13:09 volumio sudo[16548]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:09 volumio sudo[16548]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:09 volumio volumio[15903]: info: Completed starting Core Plugins Jan 11 06:13:09 volumio volumio[15903]: info: ------------------------------------------- Jan 11 06:13:09 volumio volumio[15903]: info: ----- MyVolumio plugins startup ---- Jan 11 06:13:09 volumio volumio[15903]: info: ------------------------------------------- Jan 11 06:13:09 volumio volumio[15903]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 11 06:13:10 volumio sudo[16551]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 11 06:13:10 volumio sudo[16551]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:10 volumio sudo[16554]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 11 06:13:10 volumio sudo[16554]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:10 volumio sudo[16556]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 11 06:13:10 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Jan 11 06:13:10 volumio sudo[16556]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:10 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Jan 11 06:13:10 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Jan 11 06:13:10 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Jan 11 06:13:10 volumio mpd_monitor.sh[16559]: MPD Monitor Service: Starting MPD Monitor Service Jan 11 06:13:10 volumio sudo[16551]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:10 volumio volumio[15903]: info: Successfully started MPD Monitor Jan 11 06:13:10 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Jan 11 06:13:10 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Jan 11 06:13:10 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Jan 11 06:13:10 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Jan 11 06:13:10 volumio sudo[16556]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:10 volumio sudo[16554]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:10 volumio mpd_monitor.sh[16563]: MPD Monitor Service: Starting MPD Monitor Service Jan 11 06:13:10 volumio volumio[15903]: info: Successfully started MPD Monitor Jan 11 06:13:10 volumio volumio[15903]: info: Successfully started MPD Monitor Jan 11 06:13:11 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.167.252 Jan 11 06:13:11 volumio avahi-daemon[664]: Registering new address record for 169.254.167.252 on eth0.IPv4. Jan 11 06:13:11 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 11 06:13:11 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:11 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 06:13:11 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:12 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.167.252 Jan 11 06:13:12 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.167.252 Jan 11 06:13:12 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.167.252 Jan 11 06:13:12 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 11 06:13:12 volumio avahi-daemon[664]: Withdrawing address record for 169.254.167.252 on eth0. Jan 11 06:13:12 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:12 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 06:13:12 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:12 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 11 06:13:12 volumio volumio[15903]: info: Getting Spotify volume Jan 11 06:13:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 11 06:13:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:13:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:13:13 volumio go-librespot[16613]: go-librespot daemon starting... Jan 11 06:13:13 volumio volumio[15903]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 06:13:13 volumio go-librespot[16614]: time="2026-01-11T06:13:13-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 06:13:13 volumio volumio[15903]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 11 06:13:13 volumio volumio[15903]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 11 06:13:13 volumio volumio[15903]: errno: -111, Jan 11 06:13:13 volumio volumio[15903]: code: 'ECONNREFUSED', Jan 11 06:13:13 volumio volumio[15903]: syscall: 'connect', Jan 11 06:13:13 volumio volumio[15903]: address: '127.0.0.1', Jan 11 06:13:13 volumio volumio[15903]: port: 9879, Jan 11 06:13:13 volumio volumio[15903]: response: undefined Jan 11 06:13:13 volumio volumio[15903]: } Jan 11 06:13:13 volumio volumio[15903]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 06:13:13 volumio go-librespot[16614]: time="2026-01-11T06:13:13-06:00" level=debug msg="app state loaded" Jan 11 06:13:13 volumio go-librespot[16614]: time="2026-01-11T06:13:13-06:00" level=debug msg="stored credentials not found" Jan 11 06:13:13 volumio go-librespot[16614]: time="2026-01-11T06:13:13-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 06:13:13 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 11 06:13:13 volumio go-librespot[16614]: time="2026-01-11T06:13:13-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 11 06:13:13 volumio go-librespot[16614]: time="2026-01-11T06:13:13-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 11 06:13:13 volumio go-librespot[16614]: time="2026-01-11T06:13:13-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 11 06:13:13 volumio go-librespot[16614]: time="2026-01-11T06:13:13-06:00" level=info msg="zeroconf server listening on port 38491" Jan 11 06:13:13 volumio go-librespot[16614]: time="2026-01-11T06:13:13-06:00" level=debug msg="obtained new client token: AADQCjCj0CSdtlx0H2z+bth9EEVLrYdEhr6baVWI5nRt2fXg1+eNLXEIksVI22g8d5V+75OZ7iDdj9MsHVTsD78Ng/8PwIGYS+0rO2eMKy/u6FhAFTaLBPhk7Tn7hlHRTpFJHtFab44XSE5+FkrH5oo2FRHgmXRO+LTArUzWlY/hX3hO7MtuLmsJ0beFUFsgjk2NExRBv6Rzja3v8wAulWGB2yuGPRz27UWGvCAFKk2k7+y2OPWZJJsT6w==" Jan 11 06:13:13 volumio go-librespot[16614]: time="2026-01-11T06:13:13-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 06:13:13 volumio go-librespot[16614]: time="2026-01-11T06:13:13-06:00" level=debug msg="completed keyexchange" Jan 11 06:13:13 volumio go-librespot[16614]: time="2026-01-11T06:13:13-06:00" level=debug msg="completed challenge" Jan 11 06:13:13 volumio go-librespot[16614]: time="2026-01-11T06:13:13-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 11 06:13:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 06:13:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 06:13:14 volumio sudo[16637]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-11 06:12' Jan 11 06:13:14 volumio sudo[16637]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:14 volumio sudo[16637]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:15 volumio volumio-remote-updater[14193]: [2026-01-11 06:13:15] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 11 06:13:15 volumio volumio-remote-updater[14193]: [2026-01-11 06:13:15] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 11 06:13:15 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 11 06:13:15 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 11 06:13:15 volumio systemd[1]: volumio.service: Consumed 45.348s CPU time. Jan 11 06:13:15 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 11 06:13:15 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 11 06:13:15 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 19293. Jan 11 06:13:15 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 11 06:13:15 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 11 06:13:15 volumio systemd[1]: volumio.service: Consumed 45.348s CPU time. Jan 11 06:13:15 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 11 06:13:15 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 11 06:13:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 11 06:13:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:13:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:13:17 volumio go-librespot[16664]: go-librespot daemon starting... Jan 11 06:13:17 volumio go-librespot[16665]: time="2026-01-11T06:13:17-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 06:13:17 volumio go-librespot[16665]: time="2026-01-11T06:13:17-06:00" level=debug msg="app state loaded" Jan 11 06:13:17 volumio go-librespot[16665]: time="2026-01-11T06:13:17-06:00" level=debug msg="stored credentials not found" Jan 11 06:13:17 volumio go-librespot[16665]: time="2026-01-11T06:13:17-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 06:13:17 volumio go-librespot[16665]: time="2026-01-11T06:13:17-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 11 06:13:17 volumio go-librespot[16665]: time="2026-01-11T06:13:17-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 11 06:13:17 volumio go-librespot[16665]: time="2026-01-11T06:13:17-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 11 06:13:17 volumio go-librespot[16665]: time="2026-01-11T06:13:17-06:00" level=info msg="zeroconf server listening on port 44841" Jan 11 06:13:17 volumio go-librespot[16665]: time="2026-01-11T06:13:17-06:00" level=debug msg="obtained new client token: AABmxgV4YLt9pArGv1OLXXDMKlxSMh1Kf4GEQObZ4q+/sp7IiPnoNVOgRaaq3qUSY615NBzhkBswJ9gcb/Pw64bZjZ/MLnEShWi3tdMUsEUNDm/1aqtxbFDPNRx7T4yfm7/f8FJ9RxvviYWnlmeQWgvz2NaMrU0WOoH9fgEODlaDct4apXUUA7mZR5dh/MkJlDg/d4moMs2rhegPRU4C3GCnCVAzwBpNDL+rsRa6daDT+0NWQtPr2Ns1MQ==" Jan 11 06:13:17 volumio go-librespot[16665]: time="2026-01-11T06:13:17-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 06:13:17 volumio go-librespot[16665]: time="2026-01-11T06:13:17-06:00" level=debug msg="completed keyexchange" Jan 11 06:13:17 volumio go-librespot[16665]: time="2026-01-11T06:13:17-06:00" level=debug msg="completed challenge" Jan 11 06:13:17 volumio go-librespot[16665]: time="2026-01-11T06:13:17-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 11 06:13:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 06:13:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 06:13:17 volumio volumio[16649]: info: ------------------------------------------- Jan 11 06:13:17 volumio volumio[16649]: info: ----- Volumio3 ---- Jan 11 06:13:17 volumio volumio[16649]: info: ------------------------------------------- Jan 11 06:13:17 volumio volumio[16649]: info: ----- System startup ---- Jan 11 06:13:17 volumio volumio[16649]: info: ------------------------------------------- Jan 11 06:13:18 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.191.42 Jan 11 06:13:18 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 11 06:13:18 volumio avahi-daemon[664]: Registering new address record for 169.254.191.42 on eth0.IPv4. Jan 11 06:13:18 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:18 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 06:13:18 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:18 volumio volumio[16649]: info: MYVOLUMIO Environment detected Jan 11 06:13:18 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.191.42 Jan 11 06:13:18 volumio volumio[16649]: info: Plugin folders cleanup Jan 11 06:13:18 volumio volumio[16649]: info: Scanning into folder /volumio/app/plugins/ Jan 11 06:13:18 volumio volumio[16649]: info: Scanning category audio_interface Jan 11 06:13:18 volumio volumio[16649]: info: Scanning category miscellanea Jan 11 06:13:18 volumio volumio[16649]: info: Scanning category music_service Jan 11 06:13:18 volumio volumio[16649]: info: Scanning category plugins.json Jan 11 06:13:18 volumio volumio[16649]: info: Scanning category system_controller Jan 11 06:13:18 volumio volumio[16649]: info: Scanning category user_interface Jan 11 06:13:18 volumio volumio[16649]: info: Scanning into folder /data/plugins/ Jan 11 06:13:18 volumio volumio[16649]: info: Scanning category audio_interface Jan 11 06:13:18 volumio volumio[16649]: info: Scanning category music_service Jan 11 06:13:18 volumio volumio[16649]: info: Scanning category system_controller Jan 11 06:13:18 volumio volumio[16649]: info: Scanning category system_hardware Jan 11 06:13:18 volumio volumio[16649]: info: Scanning category user_interface Jan 11 06:13:18 volumio volumio[16649]: info: Plugin folders cleanup completed Jan 11 06:13:18 volumio volumio[16649]: info: ------------------------------------------- Jan 11 06:13:18 volumio volumio[16649]: info: ----- Core plugins startup ---- Jan 11 06:13:18 volumio volumio[16649]: info: ------------------------------------------- Jan 11 06:13:18 volumio volumio[16649]: info: Loading plugins from folder /volumio/app/plugins/ Jan 11 06:13:18 volumio volumio[16649]: info: Adding plugin upnp to MyMusic Plugins Jan 11 06:13:18 volumio volumio[16649]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 11 06:13:18 volumio volumio[16649]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 11 06:13:18 volumio volumio[16649]: info: Loading plugins from folder /data/plugins/ Jan 11 06:13:18 volumio volumio[16649]: info: Loading plugin "system"... Jan 11 06:13:18 volumio volumio[16649]: info: Loading plugin "appearance"... Jan 11 06:13:19 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.191.42 Jan 11 06:13:19 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.191.42 Jan 11 06:13:19 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 11 06:13:19 volumio avahi-daemon[664]: Withdrawing address record for 169.254.191.42 on eth0. Jan 11 06:13:19 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 11 06:13:19 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:19 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 06:13:19 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:19 volumio kernel: hwmon hwmon1: Voltage normalised Jan 11 06:13:19 volumio volumio[16649]: info: Loading plugin "network"... Jan 11 06:13:19 volumio volumio[16649]: info: Refreshing Cached IP Addresses Jan 11 06:13:19 volumio sudo[16718]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 11 06:13:19 volumio sudo[16718]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:19 volumio sudo[16718]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:19 volumio sudo[16720]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 11 06:13:19 volumio sudo[16720]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:19 volumio volumio[16649]: info: Loading plugin "services"... Jan 11 06:13:19 volumio volumio[16649]: info: Loading plugin "alsa_controller"... Jan 11 06:13:19 volumio sudo[16720]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:19 volumio sudo[16728]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 11 06:13:19 volumio sudo[16728]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:19 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 06:13:19 volumio volumio[16649]: info: Loading plugin "wizard"... Jan 11 06:13:19 volumio volumio[16649]: info: Loading plugin "networkfs"... Jan 11 06:13:20 volumio volumio[16649]: info: Starting Udev Watcher for removable devices Jan 11 06:13:20 volumio volumio[16649]: info: Ignoring mount for partition: boot Jan 11 06:13:20 volumio volumio[16649]: info: Ignoring mount for partition: volumio Jan 11 06:13:20 volumio volumio[16649]: info: Ignoring mount for partition: volumio_data Jan 11 06:13:20 volumio volumio[16649]: info: Mounting Device Wikipedia Jan 11 06:13:20 volumio volumio-remote-updater[14193]: [2026-01-11 06:13:20] [connect] Successful connection Jan 11 06:13:20 volumio sudo[16757]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime Jan 11 06:13:20 volumio sudo[16757]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:20 volumio sudo[16757]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:20 volumio volumio[16649]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Jan 11 06:13:20 volumio volumio[16649]: dmesg(1) may have more information after failed mount system call. Jan 11 06:13:20 volumio volumio[16649]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime Jan 11 06:13:20 volumio volumio[16649]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Jan 11 06:13:20 volumio volumio[16649]: dmesg(1) may have more information after failed mount system call. Jan 11 06:13:20 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 06:13:20 volumio volumio[16649]: info: Loading plugin "volumio_command_line_client"... Jan 11 06:13:20 volumio volumio[16649]: info: Loading plugin "upnp"... Jan 11 06:13:20 volumio volumio[16649]: info: [1768133600227] Starting Upmpd Daemon Jan 11 06:13:20 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 06:13:20 volumio volumio[16649]: info: Loading plugin "my_music"... Jan 11 06:13:20 volumio volumio[16649]: info: Loading plugin "mpd"... Jan 11 06:13:20 volumio sudo[16728]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 11 06:13:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:13:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:13:20 volumio go-librespot[16759]: go-librespot daemon starting... Jan 11 06:13:20 volumio go-librespot[16760]: time="2026-01-11T06:13:20-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 06:13:20 volumio go-librespot[16760]: time="2026-01-11T06:13:20-06:00" level=debug msg="app state loaded" Jan 11 06:13:20 volumio go-librespot[16760]: time="2026-01-11T06:13:20-06:00" level=debug msg="stored credentials not found" Jan 11 06:13:20 volumio go-librespot[16760]: time="2026-01-11T06:13:20-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 06:13:20 volumio volumio[16649]: info: Loading plugin "upnp_browser"... Jan 11 06:13:21 volumio go-librespot[16760]: time="2026-01-11T06:13:21-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 11 06:13:21 volumio go-librespot[16760]: time="2026-01-11T06:13:21-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 11 06:13:21 volumio go-librespot[16760]: time="2026-01-11T06:13:21-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 11 06:13:21 volumio go-librespot[16760]: time="2026-01-11T06:13:21-06:00" level=info msg="zeroconf server listening on port 35639" Jan 11 06:13:21 volumio go-librespot[16760]: time="2026-01-11T06:13:21-06:00" level=debug msg="obtained new client token: AABDE/lCjg9OclOiF2pJD678e9pzwybodWfy3t3Rw+IBj3dpb87Zwzi9FI3HQyyADdbDjyFlSNYCy5sNcDKh4lv3CTfThgjhd8eQK9CXUNnsNyPKJhuzHs/zUNkqvdJsIYM82mvEABgdXKfH0Z7oKH2GmoEN1ZE+CkezS9KnR0ulmVsseML9PUBAHHPUmYkHwUsTx/36vyDDQBlmbH7B0U9kwO7PFnb++DAhuOLB71YP4TKQOd+SLnm+/w==" Jan 11 06:13:21 volumio go-librespot[16760]: time="2026-01-11T06:13:21-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 06:13:21 volumio go-librespot[16760]: time="2026-01-11T06:13:21-06:00" level=debug msg="completed keyexchange" Jan 11 06:13:21 volumio go-librespot[16760]: time="2026-01-11T06:13:21-06:00" level=debug msg="completed challenge" Jan 11 06:13:21 volumio go-librespot[16760]: time="2026-01-11T06:13:21-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 11 06:13:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 06:13:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 06:13:21 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 11 06:13:23 volumio volumio[16649]: info: Loading plugin "alarm-clock"... Jan 11 06:13:23 volumio volumio[16649]: info: Loading plugin "airplay_emulation"... Jan 11 06:13:23 volumio volumio[16649]: info: Starting Shairport Sync Jan 11 06:13:23 volumio volumio[16649]: info: Loading plugin "last_100"... Jan 11 06:13:23 volumio volumio[16649]: info: Loading plugin "webradio"... Jan 11 06:13:23 volumio volumio[16649]: info: Loading plugin "i2s_dacs"... Jan 11 06:13:23 volumio volumio[16649]: info: I2S DAC not set, start Auto-detection Jan 11 06:13:23 volumio volumio[16649]: info: Loading plugin "volumiodiscovery"... Jan 11 06:13:23 volumio volumio[16649]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 11 06:13:23 volumio volumio[16649]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 06:13:23 volumio volumio[16649]: *** WARNING *** For more information see Jan 11 06:13:23 volumio volumio[16649]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 11 06:13:23 volumio volumio[16649]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 06:13:23 volumio volumio[16649]: *** WARNING *** For more information see Jan 11 06:13:23 volumio node[16649]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 11 06:13:23 volumio node[16649]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 06:13:23 volumio node[16649]: *** WARNING *** For more information see Jan 11 06:13:23 volumio node[16649]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 11 06:13:23 volumio node[16649]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 06:13:23 volumio node[16649]: *** WARNING *** For more information see Jan 11 06:13:23 volumio volumio[16649]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 11 06:13:23 volumio volumio[16649]: info: Discovery: Started advertising with name: Volumio Jan 11 06:13:23 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 06:13:23 volumio volumio[16649]: info: Loading plugin "bandcamp"... Jan 11 06:13:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 11 06:13:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:13:24 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.61.244 Jan 11 06:13:24 volumio avahi-daemon[664]: Registering new address record for 169.254.61.244 on eth0.IPv4. Jan 11 06:13:24 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 11 06:13:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:13:24 volumio go-librespot[16770]: go-librespot daemon starting... Jan 11 06:13:24 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:24 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 06:13:24 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:24 volumio go-librespot[16778]: time="2026-01-11T06:13:24-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 06:13:24 volumio go-librespot[16778]: time="2026-01-11T06:13:24-06:00" level=debug msg="app state loaded" Jan 11 06:13:24 volumio go-librespot[16778]: time="2026-01-11T06:13:24-06:00" level=debug msg="stored credentials not found" Jan 11 06:13:24 volumio go-librespot[16778]: time="2026-01-11T06:13:24-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 06:13:25 volumio go-librespot[16778]: time="2026-01-11T06:13:25-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 11 06:13:25 volumio go-librespot[16778]: time="2026-01-11T06:13:25-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 11 06:13:25 volumio go-librespot[16778]: time="2026-01-11T06:13:25-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 11 06:13:25 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.61.244 Jan 11 06:13:25 volumio go-librespot[16778]: time="2026-01-11T06:13:25-06:00" level=info msg="zeroconf server listening on port 44015" Jan 11 06:13:25 volumio go-librespot[16778]: time="2026-01-11T06:13:25-06:00" level=debug msg="obtained new client token: AAAc290MvDnSuyghMWNA0phFI7FVqzJHLzxHIHbB8Poa1AdMSia/4bbeQND4isDjOZLwGLf9iy34yiv/Wk52nCAmNKYSFU/rHaFTtHI+sd9/U8QfRU2dkhSZDt2SFcf3wBH2bLeWNxSTMVJBH+GMW8Wxv4MpfU0IOAuG+HpJYNIh+E60y4DYAXcp1p8c6lagXAe++kBDQUMcrhWvFjfeI/B1YtaGPay+fBTZH11PdgNf0P53+jIajcQ=" Jan 11 06:13:25 volumio go-librespot[16778]: time="2026-01-11T06:13:25-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 06:13:25 volumio volumio[16649]: info: Plugin calmradio is not enabled Jan 11 06:13:25 volumio volumio[16649]: info: Loading plugin "soundcloud"... Jan 11 06:13:25 volumio go-librespot[16778]: time="2026-01-11T06:13:25-06:00" level=debug msg="completed keyexchange" Jan 11 06:13:25 volumio go-librespot[16778]: time="2026-01-11T06:13:25-06:00" level=debug msg="completed challenge" Jan 11 06:13:25 volumio go-librespot[16778]: time="2026-01-11T06:13:25-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 11 06:13:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 06:13:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 06:13:25 volumio volumio[16649]: info: Loading plugin "spop"... Jan 11 06:13:25 volumio kernel: hwmon hwmon1: Voltage normalised Jan 11 06:13:25 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.61.244 Jan 11 06:13:25 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.61.244 Jan 11 06:13:25 volumio avahi-daemon[664]: Withdrawing address record for 169.254.61.244 on eth0. Jan 11 06:13:25 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 11 06:13:25 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 11 06:13:25 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:25 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 06:13:25 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:26 volumio volumio[16649]: info: Loading plugin "squeezelite_mc"... Jan 11 06:13:27 volumio volumio[16649]: info: Loading plugin "youtube2"... Jan 11 06:13:27 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 11 06:13:28 volumio volumio[16649]: info: Loading plugin "ytcr"... Jan 11 06:13:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 11 06:13:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:13:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:13:28 volumio go-librespot[16811]: go-librespot daemon starting... Jan 11 06:13:28 volumio go-librespot[16812]: time="2026-01-11T06:13:28-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 06:13:28 volumio go-librespot[16812]: time="2026-01-11T06:13:28-06:00" level=debug msg="app state loaded" Jan 11 06:13:28 volumio go-librespot[16812]: time="2026-01-11T06:13:28-06:00" level=debug msg="stored credentials not found" Jan 11 06:13:28 volumio go-librespot[16812]: time="2026-01-11T06:13:28-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 06:13:28 volumio go-librespot[16812]: time="2026-01-11T06:13:28-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 11 06:13:28 volumio go-librespot[16812]: time="2026-01-11T06:13:28-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 11 06:13:28 volumio go-librespot[16812]: time="2026-01-11T06:13:28-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 11 06:13:29 volumio go-librespot[16812]: time="2026-01-11T06:13:29-06:00" level=info msg="zeroconf server listening on port 43195" Jan 11 06:13:29 volumio go-librespot[16812]: time="2026-01-11T06:13:29-06:00" level=debug msg="obtained new client token: AABlvOPpJtNn8yrzKJQ4pUPVXDlvdb1H9r2nzZ9zsUu4QAvKY9Q8zTUHz1DjxEr5ICId17IgvjS7n5kxNb1sHZH7Gnq6d2HusAg91dWmSFw1Ii9fDEPfbt6IHBPf/mfpBVN3YgH6y7CzTVdbu+ellb59LeGvtotuK8vpI3KGyYSjdUi9euZDt4CS1J1KIBxMHhBMbu545coG6rHxwWYoNCjojuKdafHaHAMXn6euUSZKLDV1kZPJ9ZY=" Jan 11 06:13:29 volumio go-librespot[16812]: time="2026-01-11T06:13:29-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 06:13:29 volumio go-librespot[16812]: time="2026-01-11T06:13:29-06:00" level=debug msg="completed keyexchange" Jan 11 06:13:29 volumio go-librespot[16812]: time="2026-01-11T06:13:29-06:00" level=debug msg="completed challenge" Jan 11 06:13:29 volumio go-librespot[16812]: time="2026-01-11T06:13:29-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 11 06:13:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 06:13:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 06:13:30 volumio volumio[16649]: info: Loading plugin "ytmusic"... Jan 11 06:13:30 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.120.60 Jan 11 06:13:30 volumio avahi-daemon[664]: Registering new address record for 169.254.120.60 on eth0.IPv4. Jan 11 06:13:30 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 11 06:13:31 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:31 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 06:13:31 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:31 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.120.60 Jan 11 06:13:31 volumio volumio[16649]: info: Plugin now_playing is not enabled Jan 11 06:13:31 volumio volumio[16649]: info: Loading plugin "outputs"... Jan 11 06:13:31 volumio volumio[16649]: info: Loading plugin "albumart"... Jan 11 06:13:31 volumio volumio[16649]: info: Plugin example_plugin is not enabled Jan 11 06:13:31 volumio volumio[16649]: info: Loading plugin "inputs"... Jan 11 06:13:31 volumio volumio[16649]: info: Loading plugin "updater_comm"... Jan 11 06:13:31 volumio volumio[16649]: info: Plugin mpdemulation is not enabled Jan 11 06:13:31 volumio volumio[16649]: info: Loading plugin "rest_api"... Jan 11 06:13:31 volumio volumio[16649]: info: Loading plugin "websocket"... Jan 11 06:13:31 volumio volumio[16649]: info: Starting Socket.io Server version 1.7.4 Jan 11 06:13:31 volumio volumio[16649]: info: Plugin fusiondsp is not enabled Jan 11 06:13:31 volumio volumio[16649]: info: Plugin mpdoutput is not enabled Jan 11 06:13:31 volumio volumio[16649]: info: Plugin RoonBridge is not enabled Jan 11 06:13:31 volumio volumio[16649]: info: Loading plugin "podcast"... Jan 11 06:13:31 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.120.60 Jan 11 06:13:31 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.120.60 Jan 11 06:13:31 volumio avahi-daemon[664]: Withdrawing address record for 169.254.120.60 on eth0. Jan 11 06:13:31 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 11 06:13:31 volumio volumio[16649]: info: ControllerPodcast::constructor Jan 11 06:13:31 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:31 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 06:13:31 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:31 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 11 06:13:31 volumio volumio[16649]: info: Loading plugin "volusonic"... Jan 11 06:13:31 volumio volumio[16852]: Forking 3 albumart workers Jan 11 06:13:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 11 06:13:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:13:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:13:32 volumio go-librespot[16908]: go-librespot daemon starting... Jan 11 06:13:32 volumio volumio-remote-updater[14193]: [2026-01-11 06:13:32] [connect] Successful connection Jan 11 06:13:32 volumio go-librespot[16909]: time="2026-01-11T06:13:32-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 06:13:32 volumio go-librespot[16909]: time="2026-01-11T06:13:32-06:00" level=debug msg="app state loaded" Jan 11 06:13:32 volumio go-librespot[16909]: time="2026-01-11T06:13:32-06:00" level=debug msg="stored credentials not found" Jan 11 06:13:32 volumio go-librespot[16909]: time="2026-01-11T06:13:32-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 06:13:33 volumio go-librespot[16909]: time="2026-01-11T06:13:33-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 11 06:13:33 volumio go-librespot[16909]: time="2026-01-11T06:13:33-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 11 06:13:33 volumio go-librespot[16909]: time="2026-01-11T06:13:33-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 11 06:13:33 volumio go-librespot[16909]: time="2026-01-11T06:13:33-06:00" level=info msg="zeroconf server listening on port 35881" Jan 11 06:13:33 volumio go-librespot[16909]: time="2026-01-11T06:13:33-06:00" level=debug msg="obtained new client token: AACaGieb9ztaKgP6HIohtNFSJ04ZzRRq3FReoJJP+GC/kZ8Ii5bwE8xkbT6F5DSAoQp2boEe3PgA9mYehnwp8/JSKw7Y5UXHeJb0DAlcnuM/nh0G01cAR1J95RTM0iwOBn0b9Z8oq2URJCMiqeNaS5gPaQutYyfXbcQU3OVmOtQxpMH3RObbxqAlYKHwmGkLLHj7aR6ySyXWG+1r2TVhJQABaeKOZ5Zs8oykwfOVfLIK9zo6o5lQugAWQg==" Jan 11 06:13:33 volumio go-librespot[16909]: time="2026-01-11T06:13:33-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 06:13:33 volumio go-librespot[16909]: time="2026-01-11T06:13:33-06:00" level=debug msg="completed keyexchange" Jan 11 06:13:33 volumio go-librespot[16909]: time="2026-01-11T06:13:33-06:00" level=debug msg="completed challenge" Jan 11 06:13:33 volumio go-librespot[16909]: time="2026-01-11T06:13:33-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 11 06:13:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 06:13:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 06:13:34 volumio volumio[16649]: info: Applying required configuration parameters for plugin volusonic Jan 11 06:13:34 volumio volumio[16649]: info: Loading plugin "backup_restore"... Jan 11 06:13:34 volumio volumio[16878]: Starting albumart workers Jan 11 06:13:34 volumio volumio[16880]: Starting albumart workers Jan 11 06:13:34 volumio volumio[16879]: Starting albumart workers Jan 11 06:13:34 volumio volumio[16649]: info: Applying required configuration parameters for plugin backup_restore Jan 11 06:13:35 volumio volumio[16649]: info: Plugin rpi_eeprom_config is not enabled Jan 11 06:13:35 volumio volumio[16649]: info: Plugin rpi_eeprom_updater is not enabled Jan 11 06:13:35 volumio volumio[16649]: info: Loading plugin "scheduledrestart"... Jan 11 06:13:35 volumio volumio[16649]: info: Applying required configuration parameters for plugin scheduledrestart Jan 11 06:13:35 volumio volumio[16649]: info: Plugin Bluetoothremote is not enabled Jan 11 06:13:35 volumio volumio[16649]: info: Plugin music_services_shield is not enabled Jan 11 06:13:35 volumio volumio[16649]: info: Loading plugin "Systeminfo"... Jan 11 06:13:35 volumio volumio[16649]: info: Plugin peppymeterbasic is not enabled Jan 11 06:13:35 volumio volumio[16649]: info: Loading plugin "peppyspectrum"... Jan 11 06:13:36 volumio volumio[16649]: info: Loading i18n strings for locale en Jan 11 06:13:36 volumio volumio[16649]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Jan 11 06:13:36 volumio volumio[16649]: Updating browse sources language Jan 11 06:13:36 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:13:36 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 06:13:36 volumio volumio[16649]: info: CoreCommandRouter::initPlayerControls Jan 11 06:13:36 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:36 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:36 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:36 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:36 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:36 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:36 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:36 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:36 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 06:13:36 volumio volumio[16649]: Express server listening on port 3000 Jan 11 06:13:36 volumio volumio[16649]: [Metrics] WebUI: 19s 205.63ms Jan 11 06:13:36 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.156.219 Jan 11 06:13:36 volumio avahi-daemon[664]: Registering new address record for 169.254.156.219 on eth0.IPv4. Jan 11 06:13:36 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 11 06:13:36 volumio volumio[16649]: info: CoreStateMachine::resetVolumioState Jan 11 06:13:36 volumio volumio[16649]: info: CoreStateMachine::getcurrentVolume Jan 11 06:13:36 volumio volumio[16649]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 06:13:36 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:36 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 06:13:36 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:36 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 06:13:36 volumio sudo[16956]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 11 06:13:36 volumio sudo[16956]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:36 volumio sudo[16958]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 11 06:13:36 volumio sudo[16958]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:36 volumio sudo[16956]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:36 volumio sudo[16958]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:36 volumio volumio[16649]: info: Volumio Network Manager: Network status updated: 1 Jan 11 06:13:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 11 06:13:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:13:36 volumio volumio[16649]: info: VolumeController:: Volume=100 Mute =false Jan 11 06:13:36 volumio volumio[16649]: info: CoreStateMachine::pushState Jan 11 06:13:36 volumio volumio[16649]: info: CorePlayQueue::getTrack 0 Jan 11 06:13:36 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 06:13:36 volumio volumio[16649]: info: CoreCommandRouter::volumioPushState Jan 11 06:13:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:13:36 volumio volumio[16649]: info: CoreStateMachine::updateTrackBlock Jan 11 06:13:36 volumio volumio[16649]: info: CorePlayQueue::getTrackBlock Jan 11 06:13:36 volumio volumio[16649]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 06:13:36 volumio go-librespot[16963]: go-librespot daemon starting... Jan 11 06:13:36 volumio volumio-remote-updater[14193]: [2026-01-11 06:13:36] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1768133612 101 Jan 11 06:13:36 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.156.219 Jan 11 06:13:36 volumio go-librespot[16964]: time="2026-01-11T06:13:36-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 06:13:36 volumio go-librespot[16964]: time="2026-01-11T06:13:36-06:00" level=debug msg="app state loaded" Jan 11 06:13:36 volumio go-librespot[16964]: time="2026-01-11T06:13:36-06:00" level=debug msg="stored credentials not found" Jan 11 06:13:36 volumio go-librespot[16964]: time="2026-01-11T06:13:36-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 06:13:36 volumio volumio[16649]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Jan 11 06:13:36 volumio volumio[16649]: info: Reloading queue from file Jan 11 06:13:36 volumio volumio[16649]: info: CoreStateMachine::setRepeat null single undefined Jan 11 06:13:36 volumio volumio[16649]: info: CoreStateMachine::pushState Jan 11 06:13:36 volumio volumio[16649]: info: CorePlayQueue::getTrack 0 Jan 11 06:13:36 volumio volumio[16649]: info: CoreCommandRouter::volumioPushState Jan 11 06:13:36 volumio volumio[16649]: info: CoreStateMachine::setRandom null Jan 11 06:13:36 volumio volumio[16649]: info: CoreStateMachine::pushState Jan 11 06:13:36 volumio volumio[16649]: info: CorePlayQueue::getTrack 0 Jan 11 06:13:36 volumio volumio[16649]: info: CoreCommandRouter::volumioPushState Jan 11 06:13:36 volumio volumio[16649]: info: Setting Device type: Raspberry PI Jan 11 06:13:36 volumio volumio[16649]: info: VolumeController:: Volume=100 Mute =false Jan 11 06:13:36 volumio volumio[16649]: info: CoreStateMachine::pushState Jan 11 06:13:36 volumio volumio[16649]: info: CorePlayQueue::getTrack 0 Jan 11 06:13:36 volumio volumio[16649]: info: CoreCommandRouter::volumioPushState Jan 11 06:13:36 volumio volumio[16649]: info: Completed loading Core Plugins Jan 11 06:13:36 volumio volumio[16649]: info: Preparing to generate the ALSA configuration file Jan 11 06:13:36 volumio sudo[16980]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 11 06:13:36 volumio sudo[16980]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:36 volumio volumio[16649]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Jan 11 06:13:36 volumio volumio[16649]: info: Discovery: Found device Volumio Jan 11 06:13:36 volumio volumio[16649]: info: CoreCommandRouter::volumioGetState Jan 11 06:13:36 volumio volumio[16649]: info: CorePlayQueue::getTrack 0 Jan 11 06:13:36 volumio volumio[16649]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 11 06:13:36 volumio volumio[16649]: info: Reading ALSA contributions from plugins. Jan 11 06:13:36 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.156.219 Jan 11 06:13:36 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.156.219 Jan 11 06:13:36 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 11 06:13:36 volumio avahi-daemon[664]: Withdrawing address record for 169.254.156.219 on eth0. Jan 11 06:13:37 volumio volumio[16649]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Jan 11 06:13:37 volumio volumio[16649]: info: Discovery: Found device Volumio Jan 11 06:13:37 volumio volumio[16649]: info: CoreCommandRouter::volumioGetState Jan 11 06:13:37 volumio volumio[16649]: info: CorePlayQueue::getTrack 0 Jan 11 06:13:37 volumio sudo[16980]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:37 volumio volumio[16649]: info: Upmpdcli Daemon Started Jan 11 06:13:37 volumio volumio[16649]: info: Asound.conf file unchanged, so no further update is needed Jan 11 06:13:37 volumio volumio[16649]: info: Output device has changed, restarting MPD Jan 11 06:13:37 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:37 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 06:13:37 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:37 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 11 06:13:37 volumio go-librespot[16964]: time="2026-01-11T06:13:37-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 11 06:13:37 volumio go-librespot[16964]: time="2026-01-11T06:13:37-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 11 06:13:37 volumio go-librespot[16964]: time="2026-01-11T06:13:37-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 11 06:13:37 volumio volumio[16649]: info: Output device has changed, restarting Shairport Sync Jan 11 06:13:37 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:37 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 06:13:37 volumio sudo[16999]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 06:13:37 volumio sudo[16999]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:37 volumio go-librespot[16964]: time="2026-01-11T06:13:37-06:00" level=info msg="zeroconf server listening on port 38537" Jan 11 06:13:37 volumio sudo[16999]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:37 volumio sudo[17002]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 06:13:37 volumio sudo[17002]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:37 volumio volumio[16649]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 06:13:37 volumio volumio[16649]: info: ___________ START PLUGINS ___________ Jan 11 06:13:37 volumio volumio[16649]: info: ControllerMpd::onStart: Initializing MPD Jan 11 06:13:37 volumio volumio[16649]: info: Creating MPD Configuration file Jan 11 06:13:37 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 06:13:37 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 11 06:13:37 volumio volumio[16649]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 06:13:37 volumio volumio[16649]: info: [1768133617190] CoreMusicLibrary::Adding element Media Servers Jan 11 06:13:37 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:13:37 volumio sudo[17010]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 06:13:37 volumio sudo[17012]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 06:13:37 volumio go-librespot[16964]: time="2026-01-11T06:13:37-06:00" level=debug msg="obtained new client token: AACk66swxQAz4Vnga653XvdFZnFXhzgwnwHgMq4lYqz18tXuvOWJDIek6xK71FiC8g61x6dYI+dtyDRO4zGWsve/ID1hzPBvTrCxn9lKtO8+IOBptK0gEEFp2uvHFt1O24IxtzwD9pi8IEea/TK4Twkiow/KW7eKHmzBJq9xLFkNFUWVVRH5nDvFaKVQrgVQeE4xAKGcfZ+Mq2rrrtxA2CkUaucDYf/79YUm2Km5nEZIaEyZtIwcOv0=" Jan 11 06:13:37 volumio sudo[17012]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:37 volumio sudo[17010]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:37 volumio sudo[17010]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:37 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:37 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 06:13:37 volumio go-librespot[16964]: time="2026-01-11T06:13:37-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Jan 11 06:13:37 volumio volumio[16649]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 06:13:37 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:37 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 06:13:37 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 11 06:13:37 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 11 06:13:37 volumio systemd[1]: mpd.service: Consumed 5.631s CPU time. Jan 11 06:13:37 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 11 06:13:37 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 11 06:13:37 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 11 06:13:37 volumio volumio[16649]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 06:13:37 volumio volumio[16649]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 06:13:37 volumio volumio[16649]: info: [1768133617316] CoreMusicLibrary::Adding element Last_100 Jan 11 06:13:37 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:13:37 volumio go-librespot[16964]: time="2026-01-11T06:13:37-06:00" level=debug msg="connected to ap-guc3.spotify.com:443" Jan 11 06:13:37 volumio volumio[16649]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 06:13:37 volumio volumio[16649]: info: [1768133617321] CoreMusicLibrary::Adding element Webradio Jan 11 06:13:37 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:13:37 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 06:13:37 volumio volumio[16649]: info: Initializing BBC Radios Jan 11 06:13:37 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 11 06:13:37 volumio go-librespot[16964]: time="2026-01-11T06:13:37-06:00" level=debug msg="completed keyexchange" Jan 11 06:13:37 volumio go-librespot[16964]: time="2026-01-11T06:13:37-06:00" level=debug msg="completed challenge" Jan 11 06:13:37 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 11 06:13:37 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 06:13:37 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 06:13:37 volumio go-librespot[16964]: time="2026-01-11T06:13:37-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 11 06:13:37 volumio volumio[16649]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 06:13:37 volumio volumio[16649]: info: [1768133617419] CoreMusicLibrary::Adding element Bandcamp Discover Jan 11 06:13:37 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:13:37 volumio volumio[16649]: Cannot find translation for source Bandcamp Discover Jan 11 06:13:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 06:13:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 06:13:37 volumio volumio[16649]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 06:13:37 volumio volumio[16649]: info: [1768133617437] CoreMusicLibrary::Adding element SoundCloud Jan 11 06:13:37 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:13:37 volumio volumio[16649]: Cannot find translation for source Bandcamp Discover Jan 11 06:13:37 volumio volumio[16649]: Cannot find translation for source SoundCloud Jan 11 06:13:37 volumio volumio[16649]: info: Creating Spotify config file Jan 11 06:13:37 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:37 volumio sudo[17029]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 11 06:13:37 volumio sudo[17029]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 11 06:13:37 volumio sudo[17029]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:37 volumio volumio[16649]: info: [squeezelite_mc] Starting proxy server... Jan 11 06:13:37 volumio volumio[16649]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 06:13:37 volumio volumio[16649]: info: [1768133617801] CoreMusicLibrary::Adding element YouTube2 Jan 11 06:13:37 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:13:37 volumio volumio[16649]: Cannot find translation for source Bandcamp Discover Jan 11 06:13:37 volumio volumio[16649]: Cannot find translation for source SoundCloud Jan 11 06:13:37 volumio volumio[16649]: Cannot find translation for source YouTube2 Jan 11 06:13:37 volumio volumio[16649]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 06:13:37 volumio volumio[16649]: info: [1768133617819] CoreMusicLibrary::Adding element YouTube Music Jan 11 06:13:37 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:13:37 volumio volumio[16649]: Cannot find translation for source Bandcamp Discover Jan 11 06:13:37 volumio volumio[16649]: Cannot find translation for source SoundCloud Jan 11 06:13:37 volumio volumio[16649]: Cannot find translation for source YouTube2 Jan 11 06:13:37 volumio volumio[16649]: Cannot find translation for source YouTube Music Jan 11 06:13:37 volumio volumio[16649]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 06:13:37 volumio volumio[16649]: info: [1768133617831] CoreMusicLibrary::Adding element Podcast Jan 11 06:13:37 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:13:37 volumio volumio[16649]: Cannot find translation for source Bandcamp Discover Jan 11 06:13:37 volumio volumio[16649]: Cannot find translation for source SoundCloud Jan 11 06:13:37 volumio volumio[16649]: Cannot find translation for source YouTube2 Jan 11 06:13:37 volumio volumio[16649]: Cannot find translation for source YouTube Music Jan 11 06:13:37 volumio volumio[16649]: Cannot find translation for source Podcast Jan 11 06:13:37 volumio volumio[16649]: info: Loading i18n strings for locale en Jan 11 06:13:37 volumio volumio[16649]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Jan 11 06:13:37 volumio volumio[16649]: Updating browse sources language Jan 11 06:13:37 volumio volumio[16649]: Cannot find translation for source Bandcamp Discover Jan 11 06:13:37 volumio volumio[16649]: Cannot find translation for source SoundCloud Jan 11 06:13:37 volumio volumio[16649]: Cannot find translation for source YouTube2 Jan 11 06:13:37 volumio volumio[16649]: Cannot find translation for source YouTube Music Jan 11 06:13:37 volumio volumio[16649]: Cannot find translation for source Podcast Jan 11 06:13:37 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:13:37 volumio volumio[16649]: Cannot find translation for source Bandcamp Discover Jan 11 06:13:37 volumio volumio[16649]: Cannot find translation for source SoundCloud Jan 11 06:13:37 volumio volumio[16649]: Cannot find translation for source YouTube2 Jan 11 06:13:37 volumio volumio[16649]: Cannot find translation for source YouTube Music Jan 11 06:13:37 volumio volumio[16649]: Cannot find translation for source Podcast Jan 11 06:13:37 volumio volumio[16649]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 06:13:37 volumio volumio[16649]: info: [1768133617877] CoreMusicLibrary::Adding element Volusonic Jan 11 06:13:37 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:13:37 volumio volumio[16649]: Cannot find translation for source Bandcamp Discover Jan 11 06:13:37 volumio volumio[16649]: Cannot find translation for source SoundCloud Jan 11 06:13:37 volumio volumio[16649]: Cannot find translation for source YouTube2 Jan 11 06:13:37 volumio volumio[16649]: Cannot find translation for source YouTube Music Jan 11 06:13:37 volumio volumio[16649]: Cannot find translation for source Podcast Jan 11 06:13:37 volumio volumio[16649]: Cannot find translation for source Volusonic Jan 11 06:13:37 volumio volumio[16649]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Jan 11 06:13:37 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jan 11 06:13:37 volumio volumio[16649]: info: Volumio Calling Home Jan 11 06:13:38 volumio volumio[16649]: info: [squeezelite_mc] Proxy server started on port 34723 Jan 11 06:13:38 volumio volumio[16649]: info: Preparing to generate the ALSA configuration file Jan 11 06:13:38 volumio volumio[16649]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 06:13:38 volumio volumio[16649]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 11 06:13:38 volumio volumio[16649]: info: Reading ALSA contributions from plugins. Jan 11 06:13:38 volumio volumio[16649]: info: MPD Permissions set Jan 11 06:13:38 volumio volumio[16649]: info: MPD Permissions set Jan 11 06:13:38 volumio volumio[16649]: info: Spotify config file written Jan 11 06:13:38 volumio kernel: hwmon hwmon1: Voltage normalised Jan 11 06:13:38 volumio sudo[17046]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 11 06:13:38 volumio sudo[17046]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:38 volumio volumio[16649]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 11 06:13:38 volumio volumio[16649]: info: VolumeController:: Volume=100 Mute =false Jan 11 06:13:38 volumio volumio[16649]: info: CoreStateMachine::pushState Jan 11 06:13:38 volumio volumio[16649]: info: CorePlayQueue::getTrack 0 Jan 11 06:13:38 volumio volumio[16649]: info: CoreCommandRouter::volumioPushState Jan 11 06:13:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:13:38 volumio volumio[16649]: info: [squeezelite_mc] Server discovery started Jan 11 06:13:38 volumio volumio[16649]: info: [squeezelite_mc] Player finder started Jan 11 06:13:38 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:38 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:38 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:38 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 06:13:38 volumio volumio[16649]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Jan 11 06:13:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:13:38 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:38 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:38 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:38 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:38 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:38 volumio go-librespot[17049]: go-librespot daemon starting... Jan 11 06:13:38 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:38 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:38 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:38 volumio sudo[17046]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:38 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 06:13:38 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:38 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:38 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:38 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:38 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:38 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:38 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:38 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:38 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:38 volumio go-librespot[17052]: time="2026-01-11T06:13:38-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 06:13:38 volumio go-librespot[17052]: time="2026-01-11T06:13:38-06:00" level=debug msg="app state loaded" Jan 11 06:13:38 volumio go-librespot[17052]: time="2026-01-11T06:13:38-06:00" level=debug msg="stored credentials not found" Jan 11 06:13:38 volumio go-librespot[17052]: time="2026-01-11T06:13:38-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 06:13:38 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 06:13:38 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:38 volumio volumio[16649]: info: No need to fix Spotify hosts Jan 11 06:13:38 volumio volumio[16649]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 11 06:13:38 volumio volumio[16649]: info: Volumio called home Jan 11 06:13:38 volumio go-librespot[17052]: time="2026-01-11T06:13:38-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 11 06:13:38 volumio go-librespot[17052]: time="2026-01-11T06:13:38-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 11 06:13:38 volumio go-librespot[17052]: time="2026-01-11T06:13:38-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 11 06:13:38 volumio go-librespot[17052]: time="2026-01-11T06:13:38-06:00" level=info msg="zeroconf server listening on port 46597" Jan 11 06:13:38 volumio volumio[16649]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Jan 11 06:13:38 volumio volumio[16649]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Jan 11 06:13:39 volumio volumio[16649]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf Jan 11 06:13:39 volumio volumio[16649]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 11 06:13:39 volumio volumio[16649]: SPOTIFY: BQDpuJoSOzQPBBKom9k8A0Sk8OgCMQ3CesffdxcuU63yvSCF3oV3P3ATDwJI2PFf2zXhVuydsjhihNRd_aC4SZEVAa3y35RNko_erAarksp-mOfnuiZ74690kYjA8Kz13dRnoGo80iyWMy_ybh8G4dsYYeTzd_DZuNaxqWXKYr5dLBDaHVuaX1Rd0QaOLvtyR0cdFIF46RHovBIBNGTVRbjV4KiTY_MPrJ8PNkw Jan 11 06:13:39 volumio volumio[16649]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 11 06:13:39 volumio volumio[16649]: info: New Spotify access token = BQDpuJoSOzQPBBKom9k8A0Sk8OgCMQ3CesffdxcuU63yvSCF3oV3P3ATDwJI2PFf2zXhVuydsjhihNRd_aC4SZEVAa3y35RNko_erAarksp-mOfnuiZ74690kYjA8Kz13dRnoGo80iyWMy_ybh8G4dsYYeTzd_DZuNaxqWXKYr5dLBDaHVuaX1Rd0QaOLvtyR0cdFIF46RHovBIBNGTVRbjV4KiTY_MPrJ8PNkw Jan 11 06:13:39 volumio volumio[16649]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 11 06:13:39 volumio volumio[16649]: info: Starting Shairport Sync Jan 11 06:13:39 volumio go-librespot[17052]: time="2026-01-11T06:13:39-06:00" level=debug msg="obtained new client token: AAAa9SPj+8xTqCGRGMD731/WlAtmd5TVC2E62/5ohuWO32bH2KOhztcDu+9yP8kBixjvy7v1ru2mVMnAM59mqYiwJC6br3mxc+yHLTXKFqO0UP0TxgXJ/lyCJqM90RzxMGpste0tDdBkGNwo2glAhmsd4sm55vmE2ntnTtKjgZKTu2jRHiucZBOtw9JEDyrg7XksOfNxwOsypsyBZ1lTixeMc6FYnPSAyWka8PM0+QSpLjFkLJfDS6c=" Jan 11 06:13:39 volumio volumio[16649]: info: Starting Shairport Sync Jan 11 06:13:39 volumio volumio[16649]: info: Starting Shairport Sync Jan 11 06:13:39 volumio go-librespot[17052]: time="2026-01-11T06:13:39-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 06:13:39 volumio sudo[17074]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 06:13:39 volumio sudo[17074]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:39 volumio sudo[17076]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 06:13:39 volumio sudo[17076]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:39 volumio sudo[17078]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 06:13:39 volumio sudo[17078]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:39 volumio go-librespot[17052]: time="2026-01-11T06:13:39-06:00" level=debug msg="completed keyexchange" Jan 11 06:13:39 volumio go-librespot[17052]: time="2026-01-11T06:13:39-06:00" level=debug msg="completed challenge" Jan 11 06:13:39 volumio sudo[17072]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf Jan 11 06:13:39 volumio sudo[17072]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:39 volumio go-librespot[17052]: time="2026-01-11T06:13:39-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 11 06:13:39 volumio sudo[17072]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 06:13:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 06:13:39 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 11 06:13:39 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 11 06:13:39 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 11 06:13:39 volumio volumio[16649]: info: Asound.conf file unchanged, so no further update is needed Jan 11 06:13:39 volumio systemd[1]: shairport-sync.service: Consumed 2.058s CPU time. Jan 11 06:13:39 volumio volumio[16649]: info: Output device has changed, restarting MPD Jan 11 06:13:39 volumio volumio[16649]: info: Output device has changed, restarting Shairport Sync Jan 11 06:13:39 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:39 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 06:13:39 volumio sudo[17086]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 06:13:39 volumio sudo[17086]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:39 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 11 06:13:39 volumio sudo[17076]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:39 volumio sudo[17086]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:39 volumio sudo[17074]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:39 volumio sudo[17078]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:39 volumio sudo[17088]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 06:13:39 volumio sudo[17088]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:39 volumio volumio[16649]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 06:13:39 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 11 06:13:39 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 11 06:13:39 volumio systemd[1]: mpd.service: Consumed 2.188s CPU time. Jan 11 06:13:39 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 11 06:13:39 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 11 06:13:39 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 11 06:13:39 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 11 06:13:39 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 11 06:13:39 volumio volumio[16649]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Jan 11 06:13:40 volumio sudo[17116]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Jan 11 06:13:40 volumio sudo[17116]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:40 volumio volumio[16649]: info: MPD Permissions set Jan 11 06:13:40 volumio volumio[16649]: info: Shairport-Sync Started Jan 11 06:13:40 volumio volumio[16649]: Error adding Membership: Error: addMembership EINVAL Jan 11 06:13:40 volumio volumio[16649]: info: Shairport-Sync Started Jan 11 06:13:40 volumio sudo[17116]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:40 volumio volumio[16649]: info: Shairport-Sync Started Jan 11 06:13:40 volumio volumio[16649]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Jan 11 06:13:40 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 11 06:13:40 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:40 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:40 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:40 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:40 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:40 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:40 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:40 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:40 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 06:13:40 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:40 volumio sudo[17113]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 11 06:13:40 volumio sudo[17113]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 11 06:13:40 volumio sudo[17134]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Jan 11 06:13:40 volumio sudo[17134]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:40 volumio sudo[17113]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:40 volumio volumio[16649]: info: CoreCommandRouter::volumioGetState Jan 11 06:13:40 volumio volumio[16649]: info: CorePlayQueue::getTrack 0 Jan 11 06:13:40 volumio sudo[17134]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:40 volumio volumio[16649]: SPOTIFY: User informations: {"display_name":"Clint Smith","external_urls":{"spotify":"https://open.spotify.com/user/clintsmith1"},"followers":{"href":null,"total":7},"href":"https://api.spotify.com/v1/users/clintsmith1","id":"clintsmith1","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee856520409d25d9cc210472a0fd","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b826520409d25d9cc210472a0fd","width":64}],"type":"user","uri":"spotify:user:clintsmith1"} Jan 11 06:13:40 volumio volumio[16649]: info: Spotify Successfully logged in Jan 11 06:13:40 volumio volumio[16649]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 06:13:40 volumio volumio[16649]: info: [1768133620561] CoreMusicLibrary::Adding element Spotify Jan 11 06:13:40 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:13:40 volumio volumio[16649]: Cannot find translation for source Bandcamp Discover Jan 11 06:13:40 volumio volumio[16649]: Cannot find translation for source SoundCloud Jan 11 06:13:40 volumio volumio[16649]: Cannot find translation for source YouTube2 Jan 11 06:13:40 volumio volumio[16649]: Cannot find translation for source YouTube Music Jan 11 06:13:40 volumio volumio[16649]: Cannot find translation for source Podcast Jan 11 06:13:40 volumio volumio[16649]: Cannot find translation for source Volusonic Jan 11 06:13:40 volumio volumio[16649]: Cannot find translation for source Spotify Jan 11 06:13:40 volumio volumio[16649]: info: Starting Shairport Sync Jan 11 06:13:40 volumio volumio[16649]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Jan 11 06:13:40 volumio sudo[17144]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 06:13:40 volumio sudo[17144]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:40 volumio sudo[17146]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Jan 11 06:13:40 volumio sudo[17146]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:40 volumio systemd[1]: Reloading. Jan 11 06:13:41 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:41 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:41 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:13:41 volumio volumio[16649]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 06:13:41 volumio volumio[16649]: info: go-librespot daemon successfully initialized Jan 11 06:13:42 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 11 06:13:42 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 11 06:13:42 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.160.222 Jan 11 06:13:42 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 11 06:13:42 volumio avahi-daemon[664]: Registering new address record for 169.254.160.222 on eth0.IPv4. Jan 11 06:13:42 volumio sudo[17146]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:42 volumio volumio[16649]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 11 06:13:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 11 06:13:42 volumio sudo[17183]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 11 06:13:42 volumio sudo[17183]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:43 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:43 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 06:13:43 volumio sudo[17183]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:43 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:43 volumio volumio[16649]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Jan 11 06:13:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:13:43 volumio sudo[17187]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Jan 11 06:13:43 volumio sudo[17187]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:43 volumio go-librespot[17186]: go-librespot daemon starting... Jan 11 06:13:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:13:43 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 11 06:13:43 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 11 06:13:43 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 11 06:13:43 volumio systemd[1]: shairport-sync.service: Consumed 1.574s CPU time. Jan 11 06:13:43 volumio go-librespot[17189]: time="2026-01-11T06:13:43-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 06:13:43 volumio go-librespot[17189]: time="2026-01-11T06:13:43-06:00" level=debug msg="app state loaded" Jan 11 06:13:43 volumio go-librespot[17189]: time="2026-01-11T06:13:43-06:00" level=debug msg="stored credentials not found" Jan 11 06:13:43 volumio go-librespot[17189]: time="2026-01-11T06:13:43-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 06:13:43 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 11 06:13:43 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Jan 11 06:13:43 volumio sudo[17144]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:43 volumio volumio[16649]: info: Shairport-Sync Started Jan 11 06:13:43 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.160.222 Jan 11 06:13:43 volumio systemd[1]: squeezelite.service: Deactivated successfully. Jan 11 06:13:43 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Jan 11 06:13:43 volumio sudo[17187]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:43 volumio go-librespot[17189]: time="2026-01-11T06:13:43-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 11 06:13:43 volumio go-librespot[17189]: time="2026-01-11T06:13:43-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 11 06:13:43 volumio go-librespot[17189]: time="2026-01-11T06:13:43-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 11 06:13:43 volumio go-librespot[17189]: time="2026-01-11T06:13:43-06:00" level=info msg="zeroconf server listening on port 37493" Jan 11 06:13:43 volumio go-librespot[17189]: time="2026-01-11T06:13:43-06:00" level=debug msg="obtained new client token: AAASEUbhp1d2Pn/ZrlDQ2pxkrLJWUZBjtzfW9fxm5MExrGz4O999dSFWFcUWLs1wxxadkTHfyFCBgPswzAhxwS7qAgsx3HjKrIK7SFEXyi897GWaGpQXSJu+VME2TxrYz3gQi1SMsyG/O24+Q27ki7wqbzM6jEhqJCng2oG4TCmhWRCaqfYRsP6u1Qgu1UeyNngd6x+All88MKNkj5TXBYznpgq1ZFYtV00dSa8EDmY61w/xFR5Lzih2dw==" Jan 11 06:13:43 volumio go-librespot[17189]: time="2026-01-11T06:13:43-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 06:13:43 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.160.222 Jan 11 06:13:43 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.160.222 Jan 11 06:13:43 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 11 06:13:43 volumio avahi-daemon[664]: Withdrawing address record for 169.254.160.222 on eth0. Jan 11 06:13:43 volumio go-librespot[17189]: time="2026-01-11T06:13:43-06:00" level=debug msg="completed keyexchange" Jan 11 06:13:43 volumio go-librespot[17189]: time="2026-01-11T06:13:43-06:00" level=debug msg="completed challenge" Jan 11 06:13:43 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 11 06:13:43 volumio go-librespot[17189]: time="2026-01-11T06:13:43-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 11 06:13:43 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:43 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 06:13:43 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 06:13:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 06:13:43 volumio volumio[16649]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 11 06:13:43 volumio sudo[17228]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 11 06:13:43 volumio sudo[17228]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:43 volumio sudo[17228]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:43 volumio volumio[16649]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Jan 11 06:13:44 volumio sudo[17232]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Jan 11 06:13:44 volumio sudo[17232]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:44 volumio sudo[17232]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:44 volumio volumio[16649]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Jan 11 06:13:44 volumio sudo[17235]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Jan 11 06:13:44 volumio sudo[17235]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:44 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Jan 11 06:13:44 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Jan 11 06:13:44 volumio sudo[17235]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:44 volumio kernel: hwmon hwmon1: Voltage normalised Jan 11 06:13:44 volumio mpd[17142]: 2026-01-11T06:13:44 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 11 06:13:44 volumio volumio[16649]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 11 06:13:44 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 11 06:13:44 volumio sudo[17012]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:44 volumio sudo[17002]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:44 volumio sudo[17088]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:44 volumio sudo[17245]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 11 06:13:44 volumio sudo[17245]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:44 volumio sudo[17245]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:44 volumio volumio[16649]: error: MPD error: The expression evaluated to a falsy value: Jan 11 06:13:44 volumio volumio[16649]: assert.ok(self.idling) Jan 11 06:13:44 volumio volumio[16649]: error: The expression evaluated to a falsy value: Jan 11 06:13:44 volumio volumio[16649]: assert.ok(self.idling) Jan 11 06:13:44 volumio volumio[16649]: error: MPD error: The expression evaluated to a falsy value: Jan 11 06:13:44 volumio volumio[16649]: assert.ok(self.idling) Jan 11 06:13:44 volumio volumio[16649]: error: The expression evaluated to a falsy value: Jan 11 06:13:44 volumio volumio[16649]: assert.ok(self.idling) Jan 11 06:13:44 volumio volumio[16649]: info: MPD running with PID17142 Jan 11 06:13:44 volumio volumio[16649]: ,establishing connection Jan 11 06:13:44 volumio volumio[16649]: error: updateQueue error: null Jan 11 06:13:44 volumio volumio[16649]: error: updateQueue error: null Jan 11 06:13:44 volumio volumio[16649]: info: Initializing connection to go-librespot Websocket Jan 11 06:13:45 volumio volumio[16649]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 11 06:13:45 volumio volumio[16649]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 11 06:13:45 volumio sudo[17250]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 11 06:13:45 volumio sudo[17250]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:45 volumio sudo[17250]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:45 volumio volumio[16649]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 11 06:13:46 volumio sudo[17253]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 11 06:13:46 volumio sudo[17253]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:46 volumio sudo[17253]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:46 volumio volumio[16649]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 11 06:13:46 volumio sudo[17256]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 11 06:13:46 volumio sudo[17256]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:46 volumio sudo[17256]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Jan 11 06:13:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:13:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:13:46 volumio go-librespot[17258]: go-librespot daemon starting... Jan 11 06:13:47 volumio go-librespot[17259]: time="2026-01-11T06:13:47-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 06:13:47 volumio go-librespot[17259]: time="2026-01-11T06:13:47-06:00" level=debug msg="app state loaded" Jan 11 06:13:47 volumio go-librespot[17259]: time="2026-01-11T06:13:47-06:00" level=debug msg="stored credentials not found" Jan 11 06:13:47 volumio go-librespot[17259]: time="2026-01-11T06:13:47-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 06:13:47 volumio volumio[16649]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 11 06:13:47 volumio sudo[17267]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 11 06:13:47 volumio sudo[17267]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:47 volumio sudo[17267]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:47 volumio go-librespot[17259]: time="2026-01-11T06:13:47-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 11 06:13:47 volumio go-librespot[17259]: time="2026-01-11T06:13:47-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 11 06:13:47 volumio go-librespot[17259]: time="2026-01-11T06:13:47-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 11 06:13:47 volumio volumio[16649]: info: Completed starting Core Plugins Jan 11 06:13:47 volumio volumio[16649]: info: ------------------------------------------- Jan 11 06:13:47 volumio volumio[16649]: info: ----- MyVolumio plugins startup ---- Jan 11 06:13:47 volumio volumio[16649]: info: ------------------------------------------- Jan 11 06:13:47 volumio volumio[16649]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 11 06:13:47 volumio go-librespot[17259]: time="2026-01-11T06:13:47-06:00" level=info msg="zeroconf server listening on port 34587" Jan 11 06:13:47 volumio go-librespot[17259]: time="2026-01-11T06:13:47-06:00" level=debug msg="obtained new client token: AAASJ6gZri/fq1wOKgdQPKKTGZr3TidpqP6t6HUlPCz3ly98Z8mKqe3dTXD99UBO5gHDAI1euKcQNigsXH7KsP6eEkuvzVgQzNMzDCIMS3Op2pZJPtrX7PZYokPffM5hStCOYz6V6Fnpwm0gvDDBwN89eBvyMzSMyWvECuW+ZlqrJh0u3uqxLluEfO3WZpSZ6ddqaKZG8qMgIiRhRdew3oLJZsXJbzBwgQIy1KgOQ9TYJH0SRITYLnqGlQ==" Jan 11 06:13:47 volumio go-librespot[17259]: time="2026-01-11T06:13:47-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 06:13:47 volumio go-librespot[17259]: time="2026-01-11T06:13:47-06:00" level=debug msg="completed keyexchange" Jan 11 06:13:47 volumio go-librespot[17259]: time="2026-01-11T06:13:47-06:00" level=debug msg="completed challenge" Jan 11 06:13:47 volumio go-librespot[17259]: time="2026-01-11T06:13:47-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 11 06:13:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 06:13:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 06:13:47 volumio sudo[17270]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 11 06:13:47 volumio sudo[17270]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:47 volumio sudo[17272]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 11 06:13:47 volumio sudo[17272]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:47 volumio sudo[17275]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 11 06:13:47 volumio sudo[17275]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:47 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Jan 11 06:13:47 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Jan 11 06:13:47 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Jan 11 06:13:47 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Jan 11 06:13:47 volumio sudo[17272]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:47 volumio sudo[17275]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:47 volumio sudo[17270]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:47 volumio mpd_monitor.sh[17278]: MPD Monitor Service: Starting MPD Monitor Service Jan 11 06:13:47 volumio volumio[16649]: info: Successfully started MPD Monitor Jan 11 06:13:47 volumio volumio[16649]: info: Successfully started MPD Monitor Jan 11 06:13:47 volumio volumio[16649]: info: Successfully started MPD Monitor Jan 11 06:13:48 volumio volumio[16649]: info: Initializing connection to go-librespot Websocket Jan 11 06:13:48 volumio volumio[16649]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 11 06:13:49 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.146.141 Jan 11 06:13:49 volumio avahi-daemon[664]: Registering new address record for 169.254.146.141 on eth0.IPv4. Jan 11 06:13:49 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 11 06:13:49 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:49 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 06:13:49 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:49 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.146.141 Jan 11 06:13:49 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.146.141 Jan 11 06:13:49 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.146.141 Jan 11 06:13:49 volumio avahi-daemon[664]: Withdrawing address record for 169.254.146.141 on eth0. Jan 11 06:13:49 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 11 06:13:49 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 11 06:13:49 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:49 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 06:13:49 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Jan 11 06:13:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:13:50 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 11 06:13:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:13:50 volumio go-librespot[17328]: go-librespot daemon starting... Jan 11 06:13:50 volumio go-librespot[17330]: time="2026-01-11T06:13:50-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 06:13:50 volumio go-librespot[17330]: time="2026-01-11T06:13:50-06:00" level=debug msg="app state loaded" Jan 11 06:13:50 volumio go-librespot[17330]: time="2026-01-11T06:13:50-06:00" level=debug msg="stored credentials not found" Jan 11 06:13:50 volumio go-librespot[17330]: time="2026-01-11T06:13:50-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 06:13:51 volumio volumio[16649]: info: Initializing connection to go-librespot Websocket Jan 11 06:13:51 volumio go-librespot[17330]: time="2026-01-11T06:13:51-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 11 06:13:51 volumio go-librespot[17330]: time="2026-01-11T06:13:51-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 11 06:13:51 volumio go-librespot[17330]: time="2026-01-11T06:13:51-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 11 06:13:51 volumio go-librespot[17330]: time="2026-01-11T06:13:51-06:00" level=info msg="zeroconf server listening on port 39343" Jan 11 06:13:51 volumio go-librespot[17330]: time="2026-01-11T06:13:51-06:00" level=debug msg="obtained new client token: AADMQj1FcTqULQygCTc3/rTAYM+y35hUB7vKM6E2UsXY5PNJzybfZPOOOnZz9vkGbrXXkOiMbMmetSytut9tfgRLUzwU/in5UK9BVrNuFQZ5gWZjwpQpsseDSTvm2I/rLpCq5Lw09xPbAjqW+DR1QCj+FVIL/kFoWu47Hw5NstK9zNfoBZRcLDPuL0IJ9+UXUuYS0Pnlm7G3+wSCgdaJC2uk4dsaAOj8UfYA2mZXdXJB+qmKXqqPnH4e2Q==" Jan 11 06:13:51 volumio go-librespot[17330]: time="2026-01-11T06:13:51-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 06:13:51 volumio go-librespot[17330]: time="2026-01-11T06:13:51-06:00" level=debug msg="completed keyexchange" Jan 11 06:13:51 volumio go-librespot[17330]: time="2026-01-11T06:13:51-06:00" level=debug msg="completed challenge" Jan 11 06:13:51 volumio go-librespot[17330]: time="2026-01-11T06:13:51-06:00" level=debug msg="new websocket client" Jan 11 06:13:51 volumio go-librespot[17330]: time="2026-01-11T06:13:51-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 11 06:13:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 06:13:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 06:13:51 volumio volumio[16649]: info: Connection to go-librespot Websocket established Jan 11 06:13:51 volumio volumio[16649]: info: Connection to go-librespot Websocket closed Jan 11 06:13:54 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.171.148 Jan 11 06:13:54 volumio avahi-daemon[664]: Registering new address record for 169.254.171.148 on eth0.IPv4. Jan 11 06:13:54 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 11 06:13:54 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:54 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 06:13:54 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:54 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.171.148 Jan 11 06:13:54 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.171.148 Jan 11 06:13:54 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.171.148 Jan 11 06:13:54 volumio avahi-daemon[664]: Withdrawing address record for 169.254.171.148 on eth0. Jan 11 06:13:54 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 11 06:13:54 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 11 06:13:54 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:54 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 06:13:54 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:54 volumio volumio[16649]: info: Getting Spotify volume Jan 11 06:13:54 volumio volumio[16649]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 06:13:54 volumio volumio[16649]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 11 06:13:54 volumio volumio[16649]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 11 06:13:54 volumio volumio[16649]: errno: -111, Jan 11 06:13:54 volumio volumio[16649]: code: 'ECONNREFUSED', Jan 11 06:13:54 volumio volumio[16649]: syscall: 'connect', Jan 11 06:13:54 volumio volumio[16649]: address: '127.0.0.1', Jan 11 06:13:54 volumio volumio[16649]: port: 9879, Jan 11 06:13:54 volumio volumio[16649]: response: undefined Jan 11 06:13:54 volumio volumio[16649]: } Jan 11 06:13:54 volumio volumio[16649]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 06:13:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Jan 11 06:13:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:13:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:13:54 volumio go-librespot[17381]: go-librespot daemon starting... Jan 11 06:13:55 volumio go-librespot[17383]: time="2026-01-11T06:13:55-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 06:13:55 volumio go-librespot[17383]: time="2026-01-11T06:13:55-06:00" level=debug msg="app state loaded" Jan 11 06:13:55 volumio go-librespot[17383]: time="2026-01-11T06:13:55-06:00" level=debug msg="stored credentials not found" Jan 11 06:13:55 volumio go-librespot[17383]: time="2026-01-11T06:13:55-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 06:13:55 volumio go-librespot[17383]: time="2026-01-11T06:13:55-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 11 06:13:55 volumio go-librespot[17383]: time="2026-01-11T06:13:55-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 11 06:13:55 volumio go-librespot[17383]: time="2026-01-11T06:13:55-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 11 06:13:55 volumio go-librespot[17383]: time="2026-01-11T06:13:55-06:00" level=info msg="zeroconf server listening on port 46709" Jan 11 06:13:55 volumio go-librespot[17383]: time="2026-01-11T06:13:55-06:00" level=debug msg="obtained new client token: AACXJzLTwBm5myLK9C+aXvDcSn1St4hx1boKjtVWZVAoMEkrNdgT2lIETPwI06oo+nA0yK1KTi4j0f3E9zc+X08nKIphzUUhWBFii1B8MR9+QDAh2cLf8dTNm3BT8Cqk6416yba2ZoACkD3yfXtP0wJ4rbf3TPJ32dZv+ZtbxBqn2TrK7Pcoi/DWzNoBwB4YY6MnDi99mPlwakCpKK4HNm/tyBYH6yIvxufVsPlh/nqa5tcdQqAPn6CaYQ==" Jan 11 06:13:55 volumio go-librespot[17383]: time="2026-01-11T06:13:55-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 06:13:55 volumio go-librespot[17383]: time="2026-01-11T06:13:55-06:00" level=debug msg="completed keyexchange" Jan 11 06:13:55 volumio go-librespot[17383]: time="2026-01-11T06:13:55-06:00" level=debug msg="completed challenge" Jan 11 06:13:55 volumio go-librespot[17383]: time="2026-01-11T06:13:55-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 11 06:13:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 06:13:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 06:13:55 volumio sudo[17393]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-11 06:12' Jan 11 06:13:55 volumio sudo[17393]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:13:55 volumio sudo[17393]: pam_unix(sudo:session): session closed for user root Jan 11 06:13:56 volumio volumio-remote-updater[14193]: [2026-01-11 06:13:56] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 11 06:13:56 volumio volumio-remote-updater[14193]: [2026-01-11 06:13:56] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 11 06:13:56 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 11 06:13:56 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 11 06:13:56 volumio systemd[1]: volumio.service: Consumed 55.280s CPU time. Jan 11 06:13:56 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 11 06:13:56 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 11 06:13:56 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 19294. Jan 11 06:13:56 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 11 06:13:56 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 11 06:13:56 volumio systemd[1]: volumio.service: Consumed 55.280s CPU time. Jan 11 06:13:56 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 11 06:13:56 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 11 06:13:56 volumio kernel: hwmon hwmon1: Voltage normalised Jan 11 06:13:58 volumio volumio[17406]: info: ------------------------------------------- Jan 11 06:13:58 volumio volumio[17406]: info: ----- Volumio3 ---- Jan 11 06:13:58 volumio volumio[17406]: info: ------------------------------------------- Jan 11 06:13:58 volumio volumio[17406]: info: ----- System startup ---- Jan 11 06:13:58 volumio volumio[17406]: info: ------------------------------------------- Jan 11 06:13:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Jan 11 06:13:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:13:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:13:58 volumio go-librespot[17428]: go-librespot daemon starting... Jan 11 06:13:58 volumio go-librespot[17429]: time="2026-01-11T06:13:58-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 06:13:58 volumio go-librespot[17429]: time="2026-01-11T06:13:58-06:00" level=debug msg="app state loaded" Jan 11 06:13:58 volumio go-librespot[17429]: time="2026-01-11T06:13:58-06:00" level=debug msg="stored credentials not found" Jan 11 06:13:58 volumio go-librespot[17429]: time="2026-01-11T06:13:58-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 06:13:58 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.91.138 Jan 11 06:13:58 volumio avahi-daemon[664]: Registering new address record for 169.254.91.138 on eth0.IPv4. Jan 11 06:13:58 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 11 06:13:58 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:58 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 06:13:58 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:58 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.91.138 Jan 11 06:13:59 volumio go-librespot[17429]: time="2026-01-11T06:13:59-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 11 06:13:59 volumio go-librespot[17429]: time="2026-01-11T06:13:59-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 11 06:13:59 volumio go-librespot[17429]: time="2026-01-11T06:13:59-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 11 06:13:59 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.91.138 Jan 11 06:13:59 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.91.138 Jan 11 06:13:59 volumio avahi-daemon[664]: Withdrawing address record for 169.254.91.138 on eth0. Jan 11 06:13:59 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 11 06:13:59 volumio go-librespot[17429]: time="2026-01-11T06:13:59-06:00" level=info msg="zeroconf server listening on port 40609" Jan 11 06:13:59 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:59 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 06:13:59 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:13:59 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 11 06:13:59 volumio go-librespot[17429]: time="2026-01-11T06:13:59-06:00" level=debug msg="obtained new client token: AABkdG/wZqNSS+JOkMF+5x3ZdU8gUoVS5JwbS1Y7aNnfX0aIqUCD1QEMCOdx6a5fu3NSY174sOBwmSfMq1A3F+Ap7/BNm1UvQQ+U53Fuo+TKdZy2lGlye6bWNN+lQuMNgK9pS6kg4165fQl3Sd6wEN9riTMqLW9qVedkBtw432ZTOyCSoRh7YLLk3WxveSES9vvQoF3sgaMxgOK00Faw5/JWdWDZ8G7WIhB4xz7Q9xhCKm9KRwOusB8=" Jan 11 06:13:59 volumio go-librespot[17429]: time="2026-01-11T06:13:59-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 06:13:59 volumio go-librespot[17429]: time="2026-01-11T06:13:59-06:00" level=debug msg="completed keyexchange" Jan 11 06:13:59 volumio go-librespot[17429]: time="2026-01-11T06:13:59-06:00" level=debug msg="completed challenge" Jan 11 06:13:59 volumio go-librespot[17429]: time="2026-01-11T06:13:59-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 11 06:13:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 06:13:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 06:13:59 volumio volumio[17406]: info: MYVOLUMIO Environment detected Jan 11 06:13:59 volumio volumio[17406]: info: Plugin folders cleanup Jan 11 06:13:59 volumio volumio[17406]: info: Scanning into folder /volumio/app/plugins/ Jan 11 06:13:59 volumio volumio[17406]: info: Scanning category audio_interface Jan 11 06:13:59 volumio volumio[17406]: info: Scanning category miscellanea Jan 11 06:13:59 volumio volumio[17406]: info: Scanning category music_service Jan 11 06:13:59 volumio volumio[17406]: info: Scanning category plugins.json Jan 11 06:13:59 volumio volumio[17406]: info: Scanning category system_controller Jan 11 06:13:59 volumio volumio[17406]: info: Scanning category user_interface Jan 11 06:13:59 volumio volumio[17406]: info: Scanning into folder /data/plugins/ Jan 11 06:13:59 volumio volumio[17406]: info: Scanning category audio_interface Jan 11 06:13:59 volumio volumio[17406]: info: Scanning category music_service Jan 11 06:13:59 volumio volumio[17406]: info: Scanning category system_controller Jan 11 06:13:59 volumio volumio[17406]: info: Scanning category system_hardware Jan 11 06:13:59 volumio volumio[17406]: info: Scanning category user_interface Jan 11 06:13:59 volumio volumio[17406]: info: Plugin folders cleanup completed Jan 11 06:13:59 volumio volumio[17406]: info: ------------------------------------------- Jan 11 06:13:59 volumio volumio[17406]: info: ----- Core plugins startup ---- Jan 11 06:13:59 volumio volumio[17406]: info: ------------------------------------------- Jan 11 06:13:59 volumio volumio[17406]: info: Loading plugins from folder /volumio/app/plugins/ Jan 11 06:13:59 volumio volumio[17406]: info: Adding plugin upnp to MyMusic Plugins Jan 11 06:13:59 volumio volumio[17406]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 11 06:13:59 volumio volumio[17406]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 11 06:13:59 volumio volumio[17406]: info: Loading plugins from folder /data/plugins/ Jan 11 06:13:59 volumio volumio[17406]: info: Loading plugin "system"... Jan 11 06:13:59 volumio volumio[17406]: info: Loading plugin "appearance"... Jan 11 06:14:00 volumio volumio[17406]: info: Loading plugin "network"... Jan 11 06:14:00 volumio volumio[17406]: info: Refreshing Cached IP Addresses Jan 11 06:14:00 volumio sudo[17476]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 11 06:14:00 volumio sudo[17476]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:14:00 volumio volumio[17406]: info: Loading plugin "services"... Jan 11 06:14:00 volumio sudo[17478]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 11 06:14:00 volumio sudo[17476]: pam_unix(sudo:session): session closed for user root Jan 11 06:14:00 volumio sudo[17478]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:14:00 volumio volumio[17406]: info: Loading plugin "alsa_controller"... Jan 11 06:14:00 volumio sudo[17478]: pam_unix(sudo:session): session closed for user root Jan 11 06:14:00 volumio sudo[17488]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 11 06:14:00 volumio sudo[17488]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:14:00 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 06:14:00 volumio volumio[17406]: info: Loading plugin "wizard"... Jan 11 06:14:00 volumio volumio[17406]: info: Loading plugin "networkfs"... Jan 11 06:14:00 volumio volumio[17406]: info: Starting Udev Watcher for removable devices Jan 11 06:14:00 volumio volumio[17406]: info: Ignoring mount for partition: boot Jan 11 06:14:00 volumio volumio[17406]: info: Ignoring mount for partition: volumio Jan 11 06:14:00 volumio volumio[17406]: info: Ignoring mount for partition: volumio_data Jan 11 06:14:00 volumio volumio[17406]: info: Mounting Device Wikipedia Jan 11 06:14:00 volumio sudo[17515]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime Jan 11 06:14:00 volumio sudo[17515]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:14:00 volumio sudo[17515]: pam_unix(sudo:session): session closed for user root Jan 11 06:14:00 volumio volumio[17406]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Jan 11 06:14:00 volumio volumio[17406]: dmesg(1) may have more information after failed mount system call. Jan 11 06:14:00 volumio volumio[17406]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime Jan 11 06:14:00 volumio volumio[17406]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Jan 11 06:14:00 volumio volumio[17406]: dmesg(1) may have more information after failed mount system call. Jan 11 06:14:00 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 06:14:00 volumio volumio[17406]: info: Loading plugin "volumio_command_line_client"... Jan 11 06:14:01 volumio volumio[17406]: info: Loading plugin "upnp"... Jan 11 06:14:01 volumio volumio[17406]: info: [1768133641011] Starting Upmpd Daemon Jan 11 06:14:01 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 06:14:01 volumio volumio[17406]: info: Loading plugin "my_music"... Jan 11 06:14:01 volumio volumio[17406]: info: Loading plugin "mpd"... Jan 11 06:14:01 volumio volumio-remote-updater[14193]: [2026-01-11 06:14:01] [connect] Successful connection Jan 11 06:14:01 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 11 06:14:01 volumio sudo[17488]: pam_unix(sudo:session): session closed for user root Jan 11 06:14:01 volumio volumio[17406]: info: Loading plugin "upnp_browser"... Jan 11 06:14:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Jan 11 06:14:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:14:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:14:02 volumio go-librespot[17518]: go-librespot daemon starting... Jan 11 06:14:02 volumio go-librespot[17519]: time="2026-01-11T06:14:02-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 06:14:02 volumio go-librespot[17519]: time="2026-01-11T06:14:02-06:00" level=debug msg="app state loaded" Jan 11 06:14:02 volumio go-librespot[17519]: time="2026-01-11T06:14:02-06:00" level=debug msg="stored credentials not found" Jan 11 06:14:02 volumio go-librespot[17519]: time="2026-01-11T06:14:02-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 06:14:02 volumio go-librespot[17519]: time="2026-01-11T06:14:02-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 11 06:14:02 volumio go-librespot[17519]: time="2026-01-11T06:14:02-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 11 06:14:02 volumio go-librespot[17519]: time="2026-01-11T06:14:02-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 11 06:14:03 volumio go-librespot[17519]: time="2026-01-11T06:14:03-06:00" level=info msg="zeroconf server listening on port 40073" Jan 11 06:14:03 volumio go-librespot[17519]: time="2026-01-11T06:14:03-06:00" level=debug msg="obtained new client token: AAAFsPOFtrfghsz5GdsJgX2U7Cv1/yDCuYcrgR8zb7ocgJZi5Ybi68917+d6nf8LUgl8+I/lIl8a5wqqiYrWB0nWLU+nobEMWJyVfjJ/k8k1iNs/mFjeiiNqa/7aZFoUvGOrQrX1eBtqrikw7C1YWYyM4dT5xJ+8aFOCJzoSz+G6Vaocm/3c41BcvQm+fmWVCyMC/FBjtVzzSwLeoo3IRvwNGQegIyXOkMfDJBCojuPlK1Yl5bmyIF0=" Jan 11 06:14:03 volumio go-librespot[17519]: time="2026-01-11T06:14:03-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 06:14:03 volumio go-librespot[17519]: time="2026-01-11T06:14:03-06:00" level=debug msg="completed keyexchange" Jan 11 06:14:03 volumio go-librespot[17519]: time="2026-01-11T06:14:03-06:00" level=debug msg="completed challenge" Jan 11 06:14:03 volumio go-librespot[17519]: time="2026-01-11T06:14:03-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 11 06:14:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 06:14:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 06:14:04 volumio volumio[17406]: info: Loading plugin "alarm-clock"... Jan 11 06:14:04 volumio volumio[17406]: info: Loading plugin "airplay_emulation"... Jan 11 06:14:04 volumio volumio[17406]: info: Starting Shairport Sync Jan 11 06:14:04 volumio volumio[17406]: info: Loading plugin "last_100"... Jan 11 06:14:04 volumio volumio[17406]: info: Loading plugin "webradio"... Jan 11 06:14:04 volumio volumio[17406]: info: Loading plugin "i2s_dacs"... Jan 11 06:14:04 volumio volumio[17406]: info: I2S DAC not set, start Auto-detection Jan 11 06:14:04 volumio volumio[17406]: info: Loading plugin "volumiodiscovery"... Jan 11 06:14:04 volumio volumio[17406]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 11 06:14:04 volumio node[17406]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 11 06:14:04 volumio volumio[17406]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 06:14:04 volumio node[17406]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 06:14:04 volumio volumio[17406]: *** WARNING *** For more information see Jan 11 06:14:04 volumio node[17406]: *** WARNING *** For more information see Jan 11 06:14:04 volumio volumio[17406]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 11 06:14:04 volumio node[17406]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 11 06:14:04 volumio volumio[17406]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 06:14:04 volumio node[17406]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 06:14:04 volumio volumio[17406]: *** WARNING *** For more information see Jan 11 06:14:04 volumio node[17406]: *** WARNING *** For more information see Jan 11 06:14:04 volumio volumio[17406]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 11 06:14:04 volumio volumio[17406]: info: Discovery: Started advertising with name: Volumio Jan 11 06:14:04 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 06:14:04 volumio volumio[17406]: info: Loading plugin "bandcamp"... Jan 11 06:14:04 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.112.135 Jan 11 06:14:04 volumio avahi-daemon[664]: Registering new address record for 169.254.112.135 on eth0.IPv4. Jan 11 06:14:04 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 11 06:14:04 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:14:04 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 06:14:04 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:14:05 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.112.135 Jan 11 06:14:06 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.112.135 Jan 11 06:14:06 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.112.135 Jan 11 06:14:06 volumio avahi-daemon[664]: Withdrawing address record for 169.254.112.135 on eth0. Jan 11 06:14:06 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 11 06:14:06 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:14:06 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 06:14:06 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 11 06:14:06 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:14:06 volumio volumio[17406]: info: Plugin calmradio is not enabled Jan 11 06:14:06 volumio volumio[17406]: info: Loading plugin "soundcloud"... Jan 11 06:14:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Jan 11 06:14:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:14:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:14:06 volumio go-librespot[17561]: go-librespot daemon starting... Jan 11 06:14:06 volumio go-librespot[17562]: time="2026-01-11T06:14:06-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 06:14:06 volumio go-librespot[17562]: time="2026-01-11T06:14:06-06:00" level=debug msg="app state loaded" Jan 11 06:14:06 volumio go-librespot[17562]: time="2026-01-11T06:14:06-06:00" level=debug msg="stored credentials not found" Jan 11 06:14:06 volumio go-librespot[17562]: time="2026-01-11T06:14:06-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 06:14:06 volumio volumio[17406]: info: Loading plugin "spop"... Jan 11 06:14:06 volumio go-librespot[17562]: time="2026-01-11T06:14:06-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 11 06:14:06 volumio go-librespot[17562]: time="2026-01-11T06:14:06-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 11 06:14:06 volumio go-librespot[17562]: time="2026-01-11T06:14:06-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 11 06:14:07 volumio go-librespot[17562]: time="2026-01-11T06:14:07-06:00" level=info msg="zeroconf server listening on port 37789" Jan 11 06:14:07 volumio go-librespot[17562]: time="2026-01-11T06:14:07-06:00" level=debug msg="obtained new client token: AACTZeXQl5M4zsoSWKqckFGtyk3FhPG1SvnN+t0PIqimORCEqyNFyrW91lbOHjs5CMty2q3qiMlG6FKq/JfqYG8xmBBmb6tMwZdWK3Pq74CKGMK1F2LaXalG9mM1Hl2quJ2ggJKIoTHswDyK9EakDdgO/GI18tMbcp6NlvUNKbYmj1p4FTF0hEogqNM5865QKKs5BraCy6i284BuFhW5vEOC1qWCzhDuWrEAro33kL2dbn+OqKybMHo=" Jan 11 06:14:07 volumio go-librespot[17562]: time="2026-01-11T06:14:07-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 06:14:07 volumio go-librespot[17562]: time="2026-01-11T06:14:07-06:00" level=debug msg="completed keyexchange" Jan 11 06:14:07 volumio go-librespot[17562]: time="2026-01-11T06:14:07-06:00" level=debug msg="completed challenge" Jan 11 06:14:07 volumio go-librespot[17562]: time="2026-01-11T06:14:07-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 11 06:14:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 06:14:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 06:14:08 volumio volumio[17406]: info: Loading plugin "squeezelite_mc"... Jan 11 06:14:09 volumio volumio[17406]: info: Loading plugin "youtube2"... Jan 11 06:14:10 volumio volumio[17406]: info: Loading plugin "ytcr"... Jan 11 06:14:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Jan 11 06:14:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:14:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:14:10 volumio go-librespot[17573]: go-librespot daemon starting... Jan 11 06:14:10 volumio go-librespot[17574]: time="2026-01-11T06:14:10-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 06:14:10 volumio go-librespot[17574]: time="2026-01-11T06:14:10-06:00" level=debug msg="app state loaded" Jan 11 06:14:10 volumio go-librespot[17574]: time="2026-01-11T06:14:10-06:00" level=debug msg="stored credentials not found" Jan 11 06:14:10 volumio go-librespot[17574]: time="2026-01-11T06:14:10-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 06:14:10 volumio go-librespot[17574]: time="2026-01-11T06:14:10-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 11 06:14:10 volumio go-librespot[17574]: time="2026-01-11T06:14:10-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 11 06:14:10 volumio go-librespot[17574]: time="2026-01-11T06:14:10-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 11 06:14:10 volumio go-librespot[17574]: time="2026-01-11T06:14:10-06:00" level=info msg="zeroconf server listening on port 43371" Jan 11 06:14:10 volumio go-librespot[17574]: time="2026-01-11T06:14:10-06:00" level=debug msg="obtained new client token: AAB7H1voJasz0rn7NKLfnMmWRdOLleDETMC6i/qvetm0vrgIqeSftWIibUYN5sxdDc2kTnF8p9dC/hdNrWx2vQB0gZ5leMVlOa+HAa4oJdtK7ch6U/oLkVBLRSI9ODUycEAnDvsDbiXw4MYUr7z0B62ItGBLZjFRAu++YufeNjFArguqa8ax9+J7YOxGxDo0Y4Ceg8ay04Lu3/2BJ+XvivlssgGRbc7ZtOKeAhgNCzGzouwYzgaU9hQVwg==" Jan 11 06:14:10 volumio go-librespot[17574]: time="2026-01-11T06:14:10-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 06:14:10 volumio go-librespot[17574]: time="2026-01-11T06:14:10-06:00" level=debug msg="completed keyexchange" Jan 11 06:14:10 volumio go-librespot[17574]: time="2026-01-11T06:14:10-06:00" level=debug msg="completed challenge" Jan 11 06:14:11 volumio go-librespot[17574]: time="2026-01-11T06:14:11-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 11 06:14:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 06:14:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 06:14:11 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.252.183 Jan 11 06:14:11 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 11 06:14:11 volumio avahi-daemon[664]: Registering new address record for 169.254.252.183 on eth0.IPv4. Jan 11 06:14:11 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:14:11 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 06:14:11 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:14:11 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.252.183 Jan 11 06:14:11 volumio kernel: hwmon hwmon1: Voltage normalised Jan 11 06:14:11 volumio volumio[17406]: info: Loading plugin "ytmusic"... Jan 11 06:14:11 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.252.183 Jan 11 06:14:11 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.252.183 Jan 11 06:14:11 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 11 06:14:11 volumio avahi-daemon[664]: Withdrawing address record for 169.254.252.183 on eth0. Jan 11 06:14:11 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 11 06:14:11 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:14:11 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 06:14:11 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:14:12 volumio volumio[17406]: info: Plugin now_playing is not enabled Jan 11 06:14:12 volumio volumio[17406]: info: Loading plugin "outputs"... Jan 11 06:14:12 volumio volumio[17406]: info: Loading plugin "albumart"... Jan 11 06:14:12 volumio volumio[17406]: info: Plugin example_plugin is not enabled Jan 11 06:14:12 volumio volumio[17406]: info: Loading plugin "inputs"... Jan 11 06:14:12 volumio volumio[17406]: info: Loading plugin "updater_comm"... Jan 11 06:14:12 volumio volumio[17406]: info: Plugin mpdemulation is not enabled Jan 11 06:14:12 volumio volumio[17406]: info: Loading plugin "rest_api"... Jan 11 06:14:12 volumio volumio[17406]: info: Loading plugin "websocket"... Jan 11 06:14:12 volumio volumio[17406]: info: Starting Socket.io Server version 1.7.4 Jan 11 06:14:12 volumio volumio[17406]: info: Plugin fusiondsp is not enabled Jan 11 06:14:12 volumio volumio[17406]: info: Plugin mpdoutput is not enabled Jan 11 06:14:12 volumio volumio[17406]: info: Plugin RoonBridge is not enabled Jan 11 06:14:12 volumio volumio[17406]: info: Loading plugin "podcast"... Jan 11 06:14:12 volumio volumio[17406]: info: ControllerPodcast::constructor Jan 11 06:14:12 volumio volumio[17406]: info: Loading plugin "volusonic"... Jan 11 06:14:12 volumio volumio[17628]: Forking 3 albumart workers Jan 11 06:14:13 volumio volumio-remote-updater[14193]: [2026-01-11 06:14:13] [connect] Successful connection Jan 11 06:14:13 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 11 06:14:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Jan 11 06:14:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:14:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:14:14 volumio go-librespot[17669]: go-librespot daemon starting... Jan 11 06:14:14 volumio go-librespot[17670]: time="2026-01-11T06:14:14-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 06:14:14 volumio go-librespot[17670]: time="2026-01-11T06:14:14-06:00" level=debug msg="app state loaded" Jan 11 06:14:14 volumio go-librespot[17670]: time="2026-01-11T06:14:14-06:00" level=debug msg="stored credentials not found" Jan 11 06:14:14 volumio go-librespot[17670]: time="2026-01-11T06:14:14-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 06:14:14 volumio go-librespot[17670]: time="2026-01-11T06:14:14-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 11 06:14:14 volumio go-librespot[17670]: time="2026-01-11T06:14:14-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 11 06:14:14 volumio go-librespot[17670]: time="2026-01-11T06:14:14-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 11 06:14:14 volumio go-librespot[17670]: time="2026-01-11T06:14:14-06:00" level=info msg="zeroconf server listening on port 45413" Jan 11 06:14:14 volumio volumio[17406]: info: Applying required configuration parameters for plugin volusonic Jan 11 06:14:14 volumio volumio[17406]: info: Loading plugin "backup_restore"... Jan 11 06:14:15 volumio volumio[17638]: Starting albumart workers Jan 11 06:14:15 volumio volumio[17640]: Starting albumart workers Jan 11 06:14:15 volumio go-librespot[17670]: time="2026-01-11T06:14:15-06:00" level=debug msg="obtained new client token: AAD+a4RShpCpTouw1euH38eKJBrujRVyho/OU6Za34jB3lxNftihJtR7GC8JTCIl+ylgIDj2MKTckr9EWSNH5IHTMomVk7iJ74gHRxMPL3ZXR9rXBHNqTj75I9sANJ6T3NXtAESjLMk0vWE5th9Tuk6uQjU/sLxSPXI5dxynrEJXyWPXyMb+WP9eop02QCV815u/vLH4MX6sEey1UyvEzr36LYaetHhsuIAf6Nb56BzXE92/YZhMbow=" Jan 11 06:14:15 volumio go-librespot[17670]: time="2026-01-11T06:14:15-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 06:14:15 volumio go-librespot[17670]: time="2026-01-11T06:14:15-06:00" level=debug msg="completed keyexchange" Jan 11 06:14:15 volumio go-librespot[17670]: time="2026-01-11T06:14:15-06:00" level=debug msg="completed challenge" Jan 11 06:14:15 volumio volumio[17639]: Starting albumart workers Jan 11 06:14:15 volumio go-librespot[17670]: time="2026-01-11T06:14:15-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 11 06:14:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 06:14:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 06:14:15 volumio volumio[17406]: info: Applying required configuration parameters for plugin backup_restore Jan 11 06:14:15 volumio volumio[17406]: info: Plugin rpi_eeprom_config is not enabled Jan 11 06:14:15 volumio volumio[17406]: info: Plugin rpi_eeprom_updater is not enabled Jan 11 06:14:15 volumio volumio[17406]: info: Loading plugin "scheduledrestart"... Jan 11 06:14:15 volumio volumio[17406]: info: Applying required configuration parameters for plugin scheduledrestart Jan 11 06:14:16 volumio volumio[17406]: info: Plugin Bluetoothremote is not enabled Jan 11 06:14:16 volumio volumio[17406]: info: Plugin music_services_shield is not enabled Jan 11 06:14:16 volumio volumio[17406]: info: Loading plugin "Systeminfo"... Jan 11 06:14:16 volumio volumio[17406]: info: Plugin peppymeterbasic is not enabled Jan 11 06:14:16 volumio volumio[17406]: info: Loading plugin "peppyspectrum"... Jan 11 06:14:16 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.249.126 Jan 11 06:14:16 volumio avahi-daemon[664]: Registering new address record for 169.254.249.126 on eth0.IPv4. Jan 11 06:14:16 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 11 06:14:16 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:14:16 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 06:14:16 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:14:17 volumio volumio[17406]: info: Loading i18n strings for locale en Jan 11 06:14:17 volumio volumio[17406]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Jan 11 06:14:17 volumio volumio[17406]: Updating browse sources language Jan 11 06:14:17 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:14:17 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 06:14:17 volumio volumio[17406]: info: CoreCommandRouter::initPlayerControls Jan 11 06:14:17 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:17 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:17 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:17 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:17 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:17 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:17 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:17 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:17 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 06:14:17 volumio volumio[17406]: Express server listening on port 3000 Jan 11 06:14:17 volumio volumio[17406]: [Metrics] WebUI: 19s 262.08ms Jan 11 06:14:17 volumio volumio[17406]: info: CoreStateMachine::resetVolumioState Jan 11 06:14:17 volumio volumio[17406]: info: CoreStateMachine::getcurrentVolume Jan 11 06:14:17 volumio volumio[17406]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 06:14:17 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 06:14:17 volumio sudo[17717]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 11 06:14:17 volumio sudo[17717]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:14:17 volumio sudo[17719]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 11 06:14:17 volumio sudo[17719]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:14:17 volumio sudo[17717]: pam_unix(sudo:session): session closed for user root Jan 11 06:14:17 volumio sudo[17719]: pam_unix(sudo:session): session closed for user root Jan 11 06:14:17 volumio volumio[17406]: info: Volumio Network Manager: Network status updated: 1 Jan 11 06:14:17 volumio volumio[17406]: info: VolumeController:: Volume=100 Mute =false Jan 11 06:14:17 volumio volumio[17406]: info: CoreStateMachine::pushState Jan 11 06:14:17 volumio volumio[17406]: info: CorePlayQueue::getTrack 0 Jan 11 06:14:17 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 06:14:17 volumio volumio[17406]: info: CoreCommandRouter::volumioPushState Jan 11 06:14:17 volumio volumio[17406]: info: CoreStateMachine::updateTrackBlock Jan 11 06:14:17 volumio volumio[17406]: info: CorePlayQueue::getTrackBlock Jan 11 06:14:17 volumio volumio[17406]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 06:14:17 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.249.126 Jan 11 06:14:17 volumio volumio-remote-updater[14193]: [2026-01-11 06:14:17] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1768133653 101 Jan 11 06:14:17 volumio volumio[17406]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Jan 11 06:14:17 volumio volumio[17406]: info: Reloading queue from file Jan 11 06:14:17 volumio volumio[17406]: info: CoreStateMachine::setRepeat null single undefined Jan 11 06:14:17 volumio volumio[17406]: info: CoreStateMachine::pushState Jan 11 06:14:17 volumio volumio[17406]: info: CorePlayQueue::getTrack 0 Jan 11 06:14:17 volumio volumio[17406]: info: CoreCommandRouter::volumioPushState Jan 11 06:14:17 volumio volumio[17406]: info: CoreStateMachine::setRandom null Jan 11 06:14:17 volumio volumio[17406]: info: CoreStateMachine::pushState Jan 11 06:14:17 volumio volumio[17406]: info: CorePlayQueue::getTrack 0 Jan 11 06:14:17 volumio volumio[17406]: info: CoreCommandRouter::volumioPushState Jan 11 06:14:17 volumio volumio[17406]: info: Setting Device type: Raspberry PI Jan 11 06:14:17 volumio volumio[17406]: info: VolumeController:: Volume=100 Mute =false Jan 11 06:14:17 volumio volumio[17406]: info: CoreStateMachine::pushState Jan 11 06:14:17 volumio volumio[17406]: info: CorePlayQueue::getTrack 0 Jan 11 06:14:17 volumio volumio[17406]: info: CoreCommandRouter::volumioPushState Jan 11 06:14:17 volumio volumio[17406]: info: Completed loading Core Plugins Jan 11 06:14:17 volumio volumio[17406]: info: Preparing to generate the ALSA configuration file Jan 11 06:14:17 volumio sudo[17733]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 11 06:14:17 volumio sudo[17733]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:14:17 volumio volumio[17406]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Jan 11 06:14:17 volumio volumio[17406]: info: Discovery: Found device Volumio Jan 11 06:14:17 volumio volumio[17406]: info: CoreCommandRouter::volumioGetState Jan 11 06:14:17 volumio volumio[17406]: info: CorePlayQueue::getTrack 0 Jan 11 06:14:17 volumio volumio[17406]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Jan 11 06:14:17 volumio volumio[17406]: info: Discovery: Found device Volumio Jan 11 06:14:17 volumio volumio[17406]: info: CoreCommandRouter::volumioGetState Jan 11 06:14:17 volumio volumio[17406]: info: CorePlayQueue::getTrack 0 Jan 11 06:14:17 volumio volumio[17406]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 11 06:14:17 volumio volumio[17406]: info: Reading ALSA contributions from plugins. Jan 11 06:14:17 volumio sudo[17733]: pam_unix(sudo:session): session closed for user root Jan 11 06:14:17 volumio volumio[17406]: info: Upmpdcli Daemon Started Jan 11 06:14:17 volumio volumio[17406]: info: Asound.conf file unchanged, so no further update is needed Jan 11 06:14:17 volumio volumio[17406]: info: Output device has changed, restarting MPD Jan 11 06:14:17 volumio volumio[17406]: info: Output device has changed, restarting Shairport Sync Jan 11 06:14:17 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:17 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 06:14:17 volumio sudo[17736]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 06:14:17 volumio sudo[17736]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:14:17 volumio sudo[17736]: pam_unix(sudo:session): session closed for user root Jan 11 06:14:17 volumio sudo[17738]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 06:14:17 volumio sudo[17738]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:14:17 volumio volumio[17406]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 06:14:17 volumio volumio[17406]: info: ___________ START PLUGINS ___________ Jan 11 06:14:17 volumio volumio[17406]: info: ControllerMpd::onStart: Initializing MPD Jan 11 06:14:17 volumio volumio[17406]: info: Creating MPD Configuration file Jan 11 06:14:17 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 06:14:17 volumio volumio[17406]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 06:14:17 volumio volumio[17406]: info: [1768133657805] CoreMusicLibrary::Adding element Media Servers Jan 11 06:14:17 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:14:17 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 11 06:14:17 volumio sudo[17746]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 06:14:17 volumio sudo[17746]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:14:17 volumio sudo[17746]: pam_unix(sudo:session): session closed for user root Jan 11 06:14:17 volumio sudo[17748]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 06:14:17 volumio sudo[17748]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:14:17 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:17 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 06:14:17 volumio volumio[17406]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 06:14:17 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:17 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 06:14:17 volumio volumio[17406]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 06:14:17 volumio volumio[17406]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 06:14:17 volumio volumio[17406]: info: [1768133657924] CoreMusicLibrary::Adding element Last_100 Jan 11 06:14:17 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:14:17 volumio volumio[17406]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 06:14:17 volumio volumio[17406]: info: [1768133657929] CoreMusicLibrary::Adding element Webradio Jan 11 06:14:17 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:14:17 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 06:14:17 volumio volumio[17406]: info: Initializing BBC Radios Jan 11 06:14:17 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 11 06:14:17 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 11 06:14:17 volumio systemd[1]: mpd.service: Consumed 5.030s CPU time. Jan 11 06:14:17 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 11 06:14:17 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 11 06:14:17 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 11 06:14:18 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 06:14:18 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 06:14:18 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 11 06:14:18 volumio volumio[17406]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 06:14:18 volumio volumio[17406]: info: [1768133658037] CoreMusicLibrary::Adding element Bandcamp Discover Jan 11 06:14:18 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:14:18 volumio volumio[17406]: Cannot find translation for source Bandcamp Discover Jan 11 06:14:18 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 11 06:14:18 volumio volumio[17406]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 06:14:18 volumio volumio[17406]: info: [1768133658061] CoreMusicLibrary::Adding element SoundCloud Jan 11 06:14:18 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:14:18 volumio volumio[17406]: Cannot find translation for source Bandcamp Discover Jan 11 06:14:18 volumio volumio[17406]: Cannot find translation for source SoundCloud Jan 11 06:14:18 volumio volumio[17406]: info: Creating Spotify config file Jan 11 06:14:18 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:18 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.249.126 Jan 11 06:14:18 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.249.126 Jan 11 06:14:18 volumio avahi-daemon[664]: Withdrawing address record for 169.254.249.126 on eth0. Jan 11 06:14:18 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 11 06:14:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Jan 11 06:14:18 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 11 06:14:18 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:14:18 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 06:14:18 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:14:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:14:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:14:18 volumio go-librespot[17790]: go-librespot daemon starting... Jan 11 06:14:18 volumio sudo[17773]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 11 06:14:18 volumio sudo[17773]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 11 06:14:18 volumio sudo[17773]: pam_unix(sudo:session): session closed for user root Jan 11 06:14:18 volumio go-librespot[17791]: time="2026-01-11T06:14:18-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 06:14:18 volumio volumio[17406]: info: [squeezelite_mc] Starting proxy server... Jan 11 06:14:18 volumio volumio[17406]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 06:14:18 volumio volumio[17406]: info: [1768133658818] CoreMusicLibrary::Adding element YouTube2 Jan 11 06:14:18 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:14:18 volumio volumio[17406]: Cannot find translation for source Bandcamp Discover Jan 11 06:14:18 volumio volumio[17406]: Cannot find translation for source SoundCloud Jan 11 06:14:18 volumio volumio[17406]: Cannot find translation for source YouTube2 Jan 11 06:14:18 volumio volumio[17406]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 06:14:18 volumio volumio[17406]: info: [1768133658854] CoreMusicLibrary::Adding element YouTube Music Jan 11 06:14:18 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:14:18 volumio volumio[17406]: Cannot find translation for source Bandcamp Discover Jan 11 06:14:18 volumio volumio[17406]: Cannot find translation for source SoundCloud Jan 11 06:14:18 volumio volumio[17406]: Cannot find translation for source YouTube2 Jan 11 06:14:18 volumio volumio[17406]: Cannot find translation for source YouTube Music Jan 11 06:14:18 volumio volumio[17406]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 06:14:18 volumio volumio[17406]: info: [1768133658876] CoreMusicLibrary::Adding element Podcast Jan 11 06:14:18 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:14:18 volumio volumio[17406]: Cannot find translation for source Bandcamp Discover Jan 11 06:14:18 volumio volumio[17406]: Cannot find translation for source SoundCloud Jan 11 06:14:18 volumio volumio[17406]: Cannot find translation for source YouTube2 Jan 11 06:14:18 volumio volumio[17406]: Cannot find translation for source YouTube Music Jan 11 06:14:18 volumio volumio[17406]: Cannot find translation for source Podcast Jan 11 06:14:18 volumio volumio[17406]: info: Loading i18n strings for locale en Jan 11 06:14:18 volumio volumio[17406]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Jan 11 06:14:18 volumio volumio[17406]: Updating browse sources language Jan 11 06:14:18 volumio volumio[17406]: Cannot find translation for source Bandcamp Discover Jan 11 06:14:18 volumio volumio[17406]: Cannot find translation for source SoundCloud Jan 11 06:14:18 volumio volumio[17406]: Cannot find translation for source YouTube2 Jan 11 06:14:18 volumio volumio[17406]: Cannot find translation for source YouTube Music Jan 11 06:14:18 volumio volumio[17406]: Cannot find translation for source Podcast Jan 11 06:14:18 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:14:18 volumio volumio[17406]: Cannot find translation for source Bandcamp Discover Jan 11 06:14:18 volumio volumio[17406]: Cannot find translation for source SoundCloud Jan 11 06:14:18 volumio volumio[17406]: Cannot find translation for source YouTube2 Jan 11 06:14:18 volumio volumio[17406]: Cannot find translation for source YouTube Music Jan 11 06:14:18 volumio volumio[17406]: Cannot find translation for source Podcast Jan 11 06:14:18 volumio volumio[17406]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 06:14:18 volumio volumio[17406]: info: [1768133658979] CoreMusicLibrary::Adding element Volusonic Jan 11 06:14:18 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:14:18 volumio volumio[17406]: Cannot find translation for source Bandcamp Discover Jan 11 06:14:18 volumio volumio[17406]: Cannot find translation for source SoundCloud Jan 11 06:14:18 volumio volumio[17406]: Cannot find translation for source YouTube2 Jan 11 06:14:18 volumio volumio[17406]: Cannot find translation for source YouTube Music Jan 11 06:14:18 volumio volumio[17406]: Cannot find translation for source Podcast Jan 11 06:14:18 volumio volumio[17406]: Cannot find translation for source Volusonic Jan 11 06:14:19 volumio volumio[17406]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Jan 11 06:14:19 volumio go-librespot[17791]: time="2026-01-11T06:14:19-06:00" level=info msg="zeroconf server listening on port 43267" Jan 11 06:14:19 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jan 11 06:14:19 volumio volumio[17406]: info: Volumio Calling Home Jan 11 06:14:19 volumio volumio[17406]: info: [squeezelite_mc] Proxy server started on port 40583 Jan 11 06:14:19 volumio volumio[17406]: info: Preparing to generate the ALSA configuration file Jan 11 06:14:19 volumio volumio[17406]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 06:14:19 volumio volumio[17406]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 11 06:14:19 volumio volumio[17406]: info: Reading ALSA contributions from plugins. Jan 11 06:14:19 volumio volumio[17406]: info: MPD Permissions set Jan 11 06:14:19 volumio volumio[17406]: info: MPD Permissions set Jan 11 06:14:19 volumio volumio[17406]: info: Volumio called home Jan 11 06:14:19 volumio volumio[17406]: info: Spotify config file written Jan 11 06:14:19 volumio sudo[17807]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 11 06:14:19 volumio sudo[17807]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:14:19 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 11 06:14:19 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 11 06:14:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:14:19 volumio volumio[17406]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 11 06:14:19 volumio volumio[17406]: info: VolumeController:: Volume=100 Mute =false Jan 11 06:14:19 volumio volumio[17406]: info: CoreStateMachine::pushState Jan 11 06:14:19 volumio volumio[17406]: info: CorePlayQueue::getTrack 0 Jan 11 06:14:19 volumio volumio[17406]: info: CoreCommandRouter::volumioPushState Jan 11 06:14:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:14:19 volumio go-librespot[17809]: go-librespot daemon starting... Jan 11 06:14:19 volumio volumio[17406]: info: [squeezelite_mc] Server discovery started Jan 11 06:14:19 volumio volumio[17406]: info: [squeezelite_mc] Player finder started Jan 11 06:14:19 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:19 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:19 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:19 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 06:14:19 volumio volumio[17406]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Jan 11 06:14:19 volumio sudo[17807]: pam_unix(sudo:session): session closed for user root Jan 11 06:14:19 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:19 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:19 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:19 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:19 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:19 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:19 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:19 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:19 volumio go-librespot[17810]: time="2026-01-11T06:14:19-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 06:14:19 volumio go-librespot[17810]: time="2026-01-11T06:14:19-06:00" level=debug msg="app state loaded" Jan 11 06:14:19 volumio go-librespot[17810]: time="2026-01-11T06:14:19-06:00" level=debug msg="stored credentials not found" Jan 11 06:14:19 volumio go-librespot[17810]: time="2026-01-11T06:14:19-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 06:14:19 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 06:14:19 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:19 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:19 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:19 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:19 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:19 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:19 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:19 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:19 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:20 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 06:14:20 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:20 volumio volumio[17406]: info: No need to fix Spotify hosts Jan 11 06:14:20 volumio volumio[17406]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 11 06:14:20 volumio go-librespot[17810]: time="2026-01-11T06:14:20-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 11 06:14:20 volumio go-librespot[17810]: time="2026-01-11T06:14:20-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 11 06:14:20 volumio go-librespot[17810]: time="2026-01-11T06:14:20-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 11 06:14:20 volumio go-librespot[17810]: time="2026-01-11T06:14:20-06:00" level=info msg="zeroconf server listening on port 45251" Jan 11 06:14:20 volumio volumio[17406]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Jan 11 06:14:20 volumio volumio[17406]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Jan 11 06:14:20 volumio volumio[17406]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf Jan 11 06:14:20 volumio go-librespot[17810]: time="2026-01-11T06:14:20-06:00" level=debug msg="obtained new client token: AAD7r7gsYIB2wrsrmBk4JZZcdxiSd64yy1Nj+pm2EGJWyt4GebHvii/aSptmksvRSwpzCrxfYIIBtE+QbCQPh2jXmFH8V/mvRse5eswdh+YmBUHf5/TH/v0iZy/Ps1bMol4FE3tTbGx1xBXGNpiJXZK7ovzDwh+lpUuOb1YgL2k2tP+5RVCq/IFmV0LfWpa2GjwtFAjg823rOXen4lXNYpy7d45KDZZhw8ks4UZIMq8DEBlRgHQ/5UE1Sg==" Jan 11 06:14:20 volumio volumio[17406]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 11 06:14:20 volumio volumio[17406]: SPOTIFY: BQCutJXfI7vxkBXzHK1okTy5esJCX8thjWh2goeXQBRqrwYdhnlaRt7c4bvDCjlov8XvE8Vw7HVyPOonxj2G81-VPM_2bwXSrlXB91zXvpUZXTdRcRgXJUo5q_Z0wFBz2LyTnUmRn5LDj7OHDg0fbUxuGl53tSAPLq3c7RylE8uJgENWKrsL5LwbtCCvLm_MNvAYJBPTRAM6MCIlZeft_8-mS4GDYzBx1b9lQ98 Jan 11 06:14:20 volumio volumio[17406]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 11 06:14:20 volumio volumio[17406]: info: New Spotify access token = BQCutJXfI7vxkBXzHK1okTy5esJCX8thjWh2goeXQBRqrwYdhnlaRt7c4bvDCjlov8XvE8Vw7HVyPOonxj2G81-VPM_2bwXSrlXB91zXvpUZXTdRcRgXJUo5q_Z0wFBz2LyTnUmRn5LDj7OHDg0fbUxuGl53tSAPLq3c7RylE8uJgENWKrsL5LwbtCCvLm_MNvAYJBPTRAM6MCIlZeft_8-mS4GDYzBx1b9lQ98 Jan 11 06:14:20 volumio volumio[17406]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 11 06:14:20 volumio go-librespot[17810]: time="2026-01-11T06:14:20-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 06:14:20 volumio go-librespot[17810]: time="2026-01-11T06:14:20-06:00" level=debug msg="completed keyexchange" Jan 11 06:14:20 volumio go-librespot[17810]: time="2026-01-11T06:14:20-06:00" level=debug msg="completed challenge" Jan 11 06:14:20 volumio volumio[17406]: info: Starting Shairport Sync Jan 11 06:14:20 volumio volumio[17406]: info: Starting Shairport Sync Jan 11 06:14:20 volumio go-librespot[17810]: time="2026-01-11T06:14:20-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 11 06:14:20 volumio volumio[17406]: info: Starting Shairport Sync Jan 11 06:14:20 volumio sudo[17831]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf Jan 11 06:14:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 06:14:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 06:14:20 volumio sudo[17831]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:14:20 volumio sudo[17834]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 06:14:20 volumio sudo[17834]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:14:20 volumio sudo[17831]: pam_unix(sudo:session): session closed for user root Jan 11 06:14:20 volumio sudo[17836]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 06:14:20 volumio sudo[17836]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:14:20 volumio sudo[17843]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 06:14:20 volumio sudo[17843]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:14:21 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 11 06:14:21 volumio volumio[17406]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Jan 11 06:14:21 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 11 06:14:21 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 11 06:14:21 volumio systemd[1]: shairport-sync.service: Consumed 2.091s CPU time. Jan 11 06:14:21 volumio volumio[17406]: info: Asound.conf file unchanged, so no further update is needed Jan 11 06:14:21 volumio volumio[17406]: info: Output device has changed, restarting MPD Jan 11 06:14:21 volumio sudo[17861]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Jan 11 06:14:21 volumio sudo[17861]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:14:21 volumio volumio[17406]: info: Output device has changed, restarting Shairport Sync Jan 11 06:14:21 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:21 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 06:14:21 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 11 06:14:21 volumio sudo[17863]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 06:14:21 volumio sudo[17863]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:14:21 volumio sudo[17836]: pam_unix(sudo:session): session closed for user root Jan 11 06:14:21 volumio sudo[17834]: pam_unix(sudo:session): session closed for user root Jan 11 06:14:21 volumio sudo[17843]: pam_unix(sudo:session): session closed for user root Jan 11 06:14:21 volumio sudo[17863]: pam_unix(sudo:session): session closed for user root Jan 11 06:14:21 volumio volumio[17406]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 06:14:21 volumio sudo[17866]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 06:14:21 volumio sudo[17861]: pam_unix(sudo:session): session closed for user root Jan 11 06:14:21 volumio sudo[17866]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:14:21 volumio volumio[17406]: info: PeppySpectrum ---peppyspectrum status stop Jan 11 06:14:21 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 11 06:14:21 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 11 06:14:21 volumio systemd[1]: mpd.service: Consumed 3.108s CPU time. Jan 11 06:14:21 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 11 06:14:21 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 11 06:14:21 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 11 06:14:21 volumio sudo[17891]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Jan 11 06:14:21 volumio sudo[17891]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:14:21 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 11 06:14:21 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 11 06:14:21 volumio volumio[17406]: info: MPD Permissions set Jan 11 06:14:21 volumio volumio[17406]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Jan 11 06:14:21 volumio volumio[17406]: info: Shairport-Sync Started Jan 11 06:14:21 volumio volumio[17406]: Error adding Membership: Error: addMembership EINVAL Jan 11 06:14:21 volumio volumio[17406]: info: Shairport-Sync Started Jan 11 06:14:21 volumio volumio[17406]: info: Shairport-Sync Started Jan 11 06:14:21 volumio sudo[17891]: pam_unix(sudo:session): session closed for user root Jan 11 06:14:21 volumio volumio[17406]: info: peppyspectrum Daemon Stop Jan 11 06:14:21 volumio sudo[17897]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Jan 11 06:14:21 volumio sudo[17897]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:14:21 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:21 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:21 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:21 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:21 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:21 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:21 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:21 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:21 volumio sudo[17897]: pam_unix(sudo:session): session closed for user root Jan 11 06:14:22 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 06:14:22 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:22 volumio sudo[17894]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 11 06:14:22 volumio sudo[17894]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 11 06:14:22 volumio sudo[17894]: pam_unix(sudo:session): session closed for user root Jan 11 06:14:22 volumio volumio[17406]: info: CoreCommandRouter::volumioGetState Jan 11 06:14:22 volumio volumio[17406]: info: CorePlayQueue::getTrack 0 Jan 11 06:14:22 volumio volumio[17406]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Jan 11 06:14:22 volumio sudo[17907]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Jan 11 06:14:22 volumio sudo[17907]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:14:22 volumio volumio[17406]: info: Starting Shairport Sync Jan 11 06:14:22 volumio sudo[17910]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 06:14:22 volumio sudo[17910]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:14:22 volumio volumio[17406]: SPOTIFY: User informations: {"display_name":"Clint Smith","external_urls":{"spotify":"https://open.spotify.com/user/clintsmith1"},"followers":{"href":null,"total":7},"href":"https://api.spotify.com/v1/users/clintsmith1","id":"clintsmith1","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee856520409d25d9cc210472a0fd","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b826520409d25d9cc210472a0fd","width":64}],"type":"user","uri":"spotify:user:clintsmith1"} Jan 11 06:14:22 volumio volumio[17406]: info: Spotify Successfully logged in Jan 11 06:14:22 volumio systemd[1]: Reloading. Jan 11 06:14:22 volumio volumio[17406]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 06:14:22 volumio volumio[17406]: info: [1768133662337] CoreMusicLibrary::Adding element Spotify Jan 11 06:14:22 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:14:22 volumio volumio[17406]: Cannot find translation for source Bandcamp Discover Jan 11 06:14:22 volumio volumio[17406]: Cannot find translation for source SoundCloud Jan 11 06:14:22 volumio volumio[17406]: Cannot find translation for source YouTube2 Jan 11 06:14:22 volumio volumio[17406]: Cannot find translation for source YouTube Music Jan 11 06:14:22 volumio volumio[17406]: Cannot find translation for source Podcast Jan 11 06:14:22 volumio volumio[17406]: Cannot find translation for source Volusonic Jan 11 06:14:22 volumio volumio[17406]: Cannot find translation for source Spotify Jan 11 06:14:22 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:22 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:22 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:14:22 volumio volumio[17406]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 06:14:23 volumio volumio[17406]: info: go-librespot daemon successfully initialized Jan 11 06:14:23 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.113.141 Jan 11 06:14:23 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 11 06:14:23 volumio avahi-daemon[664]: Registering new address record for 169.254.113.141 on eth0.IPv4. Jan 11 06:14:24 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.113.141 Jan 11 06:14:24 volumio volumio[17406]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 06:14:24 volumio volumio[17406]: Error: addMembership ENODEV Jan 11 06:14:24 volumio volumio[17406]: at Socket.addMembership (node:dgram:860:11) Jan 11 06:14:24 volumio volumio[17406]: at addMembership (/volumio/node_modules/node-ssdp/lib/index.js:264:16) { Jan 11 06:14:24 volumio volumio[17406]: errno: -19, Jan 11 06:14:24 volumio volumio[17406]: code: 'ENODEV', Jan 11 06:14:24 volumio volumio[17406]: syscall: 'addMembership' Jan 11 06:14:24 volumio volumio[17406]: } Jan 11 06:14:24 volumio volumio[17406]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 06:14:24 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.113.141 Jan 11 06:14:24 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.113.141 Jan 11 06:14:24 volumio avahi-daemon[664]: Withdrawing address record for 169.254.113.141 on eth0. Jan 11 06:14:24 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 11 06:14:24 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 11 06:14:24 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 11 06:14:24 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 11 06:14:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 11 06:14:25 volumio sudo[17907]: pam_unix(sudo:session): session closed for user root Jan 11 06:14:25 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:14:25 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 06:14:25 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:14:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:14:25 volumio sudo[17976]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-11 06:13' Jan 11 06:14:25 volumio sudo[17976]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 06:14:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 06:14:25 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 11 06:14:25 volumio go-librespot[17973]: go-librespot daemon starting... Jan 11 06:14:25 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 11 06:14:25 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 11 06:14:25 volumio systemd[1]: shairport-sync.service: Consumed 1.524s CPU time. Jan 11 06:14:25 volumio go-librespot[17978]: time="2026-01-11T06:14:25-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 06:14:25 volumio go-librespot[17978]: time="2026-01-11T06:14:25-06:00" level=debug msg="app state loaded" Jan 11 06:14:25 volumio go-librespot[17978]: time="2026-01-11T06:14:25-06:00" level=debug msg="stored credentials not found" Jan 11 06:14:25 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 11 06:14:25 volumio sudo[17910]: pam_unix(sudo:session): session closed for user root Jan 11 06:14:25 volumio go-librespot[17978]: time="2026-01-11T06:14:25-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 06:14:25 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 06:14:25 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 06:14:25 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="ac7dd5922ede329d1459d48b226ddc71f5209a2c" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="3441cddd43405c36fe444484553f10f2f5bc830b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Nov 13 11:04:27 UTC 2025" VOLUMIO_VERSION="4.069" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="7da8d6d9f8baf8621af4ec2af5a00f00"