Feb 08 04:45:00 volumio go-librespot[13578]: time="2026-02-08T04:45:00-06:00" level=debug msg="obtained new client token: AAC8Mhw/EeFa4cjdPsM54j3P5AoCJg9R7Df/pKv7f+zOm8ez8rGD0D0aWsk6tR9SGOyFVQAs2PnN9kN9qAe9rdd1wKRRZSrB3RgJu58y3Hmw1+LJFkWJfg4K5E6PW8zhJcSsND1nY3PwM7qJMRyKQ/6d8GJd462nfVsORm+ZBzGFILWAxybyCEOM65OUxdKGKSNWDIl6/WMVbZaAtctywWlLe4usYb0OXyVZnD3ukO1TI5K/vbFNZWk=" Feb 08 04:45:00 volumio go-librespot[13578]: time="2026-02-08T04:45:00-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" Feb 08 04:45:00 volumio go-librespot[13578]: time="2026-02-08T04:45:00-06:00" level=debug msg="connected to ap-guc3.spotify.com:443" Feb 08 04:45:00 volumio sudo[13612]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 08 04:45:00 volumio sudo[13612]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 08 04:45:00 volumio sudo[13612]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:00 volumio go-librespot[13578]: time="2026-02-08T04:45:00-06:00" level=debug msg="completed keyexchange" Feb 08 04:45:00 volumio go-librespot[13578]: time="2026-02-08T04:45:00-06:00" level=debug msg="completed challenge" Feb 08 04:45:00 volumio go-librespot[13578]: time="2026-02-08T04:45:00-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 " Feb 08 04:45:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 04:45:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 04:45:00 volumio volumio[13352]: info: [squeezelite_mc] Starting proxy server... Feb 08 04:45:00 volumio volumio[13352]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 04:45:00 volumio volumio[13352]: info: [1770547500488] CoreMusicLibrary::Adding element YouTube2 Feb 08 04:45:00 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 04:45:00 volumio volumio[13352]: Cannot find translation for source Bandcamp Discover Feb 08 04:45:00 volumio volumio[13352]: Cannot find translation for source SoundCloud Feb 08 04:45:00 volumio volumio[13352]: Cannot find translation for source YouTube2 Feb 08 04:45:00 volumio volumio[13352]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 04:45:00 volumio volumio[13352]: info: [1770547500520] CoreMusicLibrary::Adding element YouTube Music Feb 08 04:45:00 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 04:45:00 volumio volumio[13352]: Cannot find translation for source Bandcamp Discover Feb 08 04:45:00 volumio volumio[13352]: Cannot find translation for source SoundCloud Feb 08 04:45:00 volumio volumio[13352]: Cannot find translation for source YouTube2 Feb 08 04:45:00 volumio volumio[13352]: Cannot find translation for source YouTube Music Feb 08 04:45:00 volumio volumio[13352]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 04:45:00 volumio volumio[13352]: info: [1770547500540] CoreMusicLibrary::Adding element Podcast Feb 08 04:45:00 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 04:45:00 volumio volumio[13352]: Cannot find translation for source Bandcamp Discover Feb 08 04:45:00 volumio volumio[13352]: Cannot find translation for source SoundCloud Feb 08 04:45:00 volumio volumio[13352]: Cannot find translation for source YouTube2 Feb 08 04:45:00 volumio volumio[13352]: Cannot find translation for source YouTube Music Feb 08 04:45:00 volumio volumio[13352]: Cannot find translation for source Podcast Feb 08 04:45:00 volumio volumio[13352]: info: Loading i18n strings for locale en Feb 08 04:45:00 volumio volumio[13352]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Feb 08 04:45:00 volumio volumio[13352]: Updating browse sources language Feb 08 04:45:00 volumio volumio[13352]: Cannot find translation for source Bandcamp Discover Feb 08 04:45:00 volumio volumio[13352]: Cannot find translation for source SoundCloud Feb 08 04:45:00 volumio volumio[13352]: Cannot find translation for source YouTube2 Feb 08 04:45:00 volumio volumio[13352]: Cannot find translation for source YouTube Music Feb 08 04:45:00 volumio volumio[13352]: Cannot find translation for source Podcast Feb 08 04:45:00 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 04:45:00 volumio volumio[13352]: Cannot find translation for source Bandcamp Discover Feb 08 04:45:00 volumio volumio[13352]: Cannot find translation for source SoundCloud Feb 08 04:45:00 volumio volumio[13352]: Cannot find translation for source YouTube2 Feb 08 04:45:00 volumio volumio[13352]: Cannot find translation for source YouTube Music Feb 08 04:45:00 volumio volumio[13352]: Cannot find translation for source Podcast Feb 08 04:45:00 volumio volumio[13352]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 04:45:00 volumio volumio[13352]: info: [1770547500623] CoreMusicLibrary::Adding element Volusonic Feb 08 04:45:00 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 04:45:00 volumio volumio[13352]: Cannot find translation for source Bandcamp Discover Feb 08 04:45:00 volumio volumio[13352]: Cannot find translation for source SoundCloud Feb 08 04:45:00 volumio volumio[13352]: Cannot find translation for source YouTube2 Feb 08 04:45:00 volumio volumio[13352]: Cannot find translation for source YouTube Music Feb 08 04:45:00 volumio volumio[13352]: Cannot find translation for source Podcast Feb 08 04:45:00 volumio volumio[13352]: Cannot find translation for source Volusonic Feb 08 04:45:00 volumio volumio[13352]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Feb 08 04:45:00 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Feb 08 04:45:00 volumio volumio[13352]: info: Volumio Calling Home Feb 08 04:45:00 volumio volumio[13352]: info: [squeezelite_mc] Proxy server started on port 36817 Feb 08 04:45:00 volumio volumio[13352]: info: Preparing to generate the ALSA configuration file Feb 08 04:45:01 volumio volumio[13352]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 04:45:01 volumio volumio[13352]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Feb 08 04:45:01 volumio volumio[13352]: info: Reading ALSA contributions from plugins. Feb 08 04:45:01 volumio volumio[13352]: info: MPD Permissions set Feb 08 04:45:01 volumio volumio[13352]: info: MPD Permissions set Feb 08 04:45:01 volumio volumio[13352]: info: Upmpdcli Daemon Started Feb 08 04:45:01 volumio volumio[13352]: info: Volumio called home Feb 08 04:45:01 volumio volumio[13352]: info: Spotify config file written Feb 08 04:45:01 volumio sudo[13623]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 08 04:45:01 volumio sudo[13623]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:01 volumio volumio[13352]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 08 04:45:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:45:01 volumio volumio[13352]: info: VolumeController:: Volume=100 Mute =false Feb 08 04:45:01 volumio volumio[13352]: info: CoreStateMachine::pushState Feb 08 04:45:01 volumio volumio[13352]: info: CorePlayQueue::getTrack 0 Feb 08 04:45:01 volumio volumio[13352]: info: CoreCommandRouter::volumioPushState Feb 08 04:45:01 volumio volumio[13352]: info: [squeezelite_mc] Server discovery started Feb 08 04:45:01 volumio volumio[13352]: info: [squeezelite_mc] Player finder started Feb 08 04:45:01 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:01 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:01 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:01 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 04:45:01 volumio volumio[13352]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Feb 08 04:45:01 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:01 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:01 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:01 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:01 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:01 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:01 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:45:01 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:01 volumio go-librespot[13625]: go-librespot daemon starting... Feb 08 04:45:01 volumio sudo[13623]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:01 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 04:45:01 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:01 volumio go-librespot[13629]: time="2026-02-08T04:45:01-06:00" level=info msg="running go-librespot 0.4.0" Feb 08 04:45:01 volumio go-librespot[13629]: time="2026-02-08T04:45:01-06:00" level=debug msg="app state loaded" Feb 08 04:45:01 volumio go-librespot[13629]: time="2026-02-08T04:45:01-06:00" level=debug msg="stored credentials not found" Feb 08 04:45:01 volumio go-librespot[13629]: time="2026-02-08T04:45:01-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 04:45:01 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:01 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:01 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:01 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:01 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:01 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:01 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:01 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:01 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 04:45:01 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:01 volumio volumio[13352]: info: No need to fix Spotify hosts Feb 08 04:45:01 volumio volumio[13352]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 08 04:45:01 volumio go-librespot[13629]: time="2026-02-08T04:45:01-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]" Feb 08 04:45:01 volumio go-librespot[13629]: time="2026-02-08T04:45:01-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]" Feb 08 04:45:01 volumio go-librespot[13629]: time="2026-02-08T04:45:01-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]" Feb 08 04:45:01 volumio volumio[13352]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Feb 08 04:45:01 volumio volumio[13352]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Feb 08 04:45:01 volumio volumio[13352]: 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 Feb 08 04:45:02 volumio go-librespot[13629]: time="2026-02-08T04:45:02-06:00" level=info msg="zeroconf server listening on port 32819" Feb 08 04:45:02 volumio volumio[13352]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 08 04:45:02 volumio volumio[13352]: SPOTIFY: BQD7_NfbZapyUXbcm6o5M08DIwM5-LipyZwB6EQTu5qRnqN21JUwT7CjjCdRscyO5xlC5QsL9y7eHYlXJAlGTjEHlITF8iG7TV1wvENJRqUtpDyY8f_TyugF24noXgnRWvG3geFkSbLrz9Xtg1WdXNQjjo1HGxk9W6D93SI8YtUFU_He0K3Bc9-IvXgZeYkUTgZSYCK_UbuW7YDX9Mv3md_G_WJkCUyZGfeR7FA Feb 08 04:45:02 volumio volumio[13352]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 08 04:45:02 volumio volumio[13352]: info: New Spotify access token = BQD7_NfbZapyUXbcm6o5M08DIwM5-LipyZwB6EQTu5qRnqN21JUwT7CjjCdRscyO5xlC5QsL9y7eHYlXJAlGTjEHlITF8iG7TV1wvENJRqUtpDyY8f_TyugF24noXgnRWvG3geFkSbLrz9Xtg1WdXNQjjo1HGxk9W6D93SI8YtUFU_He0K3Bc9-IvXgZeYkUTgZSYCK_UbuW7YDX9Mv3md_G_WJkCUyZGfeR7FA Feb 08 04:45:02 volumio volumio[13352]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 08 04:45:02 volumio sudo[13648]: 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 Feb 08 04:45:02 volumio sudo[13648]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:02 volumio volumio[13352]: info: Starting Shairport Sync Feb 08 04:45:02 volumio sudo[13648]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:02 volumio volumio[13352]: info: Starting Shairport Sync Feb 08 04:45:02 volumio volumio[13352]: info: Starting Shairport Sync Feb 08 04:45:02 volumio go-librespot[13629]: time="2026-02-08T04:45:02-06:00" level=debug msg="obtained new client token: AAAfy9ZchLw2ZeDsPJWynTBfmkETi/kk55u+JRp9c9E+Ri5E+x+X/RVrKa9BRyIgA0+ZQ8rewy+fb3HiUdi2gwG8Xv2SjHfGfYF/WrHPNELfRGwG0QRQMVagENENYlLYkQvpJ4mP8ttZ0+NNS0Xqr4MhAC2gvDMH631ZUs/lT6hvO4eFE4rA7uwP7dkzOV5MMyHYmNeQlwZ70fcFg8TgDriN4aSlEj7FGSIGYGZLSGhuDXZP+9up6rM=" Feb 08 04:45:02 volumio sudo[13651]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 04:45:02 volumio sudo[13651]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:02 volumio sudo[13653]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 04:45:02 volumio sudo[13653]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:02 volumio go-librespot[13629]: time="2026-02-08T04:45:02-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 08 04:45:02 volumio sudo[13655]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 04:45:02 volumio sudo[13655]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:02 volumio go-librespot[13629]: time="2026-02-08T04:45:02-06:00" level=debug msg="completed keyexchange" Feb 08 04:45:02 volumio go-librespot[13629]: time="2026-02-08T04:45:02-06:00" level=debug msg="completed challenge" Feb 08 04:45:02 volumio volumio[13352]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Feb 08 04:45:02 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 08 04:45:02 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 08 04:45:02 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 04:45:02 volumio systemd[1]: shairport-sync.service: Consumed 2.047s CPU time. Feb 08 04:45:02 volumio volumio[13352]: info: Asound.conf file unchanged, so no further update is needed Feb 08 04:45:02 volumio volumio[13352]: info: Output device has changed, restarting MPD Feb 08 04:45:02 volumio go-librespot[13629]: time="2026-02-08T04:45:02-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 " Feb 08 04:45:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 04:45:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 04:45:02 volumio volumio[13352]: info: Output device has changed, restarting Shairport Sync Feb 08 04:45:02 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:02 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 04:45:02 volumio sudo[13662]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Feb 08 04:45:02 volumio sudo[13662]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:02 volumio sudo[13666]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 08 04:45:02 volumio sudo[13666]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:02 volumio sudo[13664]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 08 04:45:02 volumio sudo[13664]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:02 volumio sudo[13662]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:02 volumio sudo[13664]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:02 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 04:45:02 volumio sudo[13653]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:02 volumio sudo[13651]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:02 volumio volumio[13352]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 04:45:02 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 08 04:45:02 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 08 04:45:02 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 04:45:02 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 04:45:02 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 08 04:45:02 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 08 04:45:02 volumio systemd[1]: mpd.service: Consumed 2.740s CPU time. Feb 08 04:45:02 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 08 04:45:02 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 08 04:45:02 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 08 04:45:02 volumio sudo[13655]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:02 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 08 04:45:02 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 08 04:45:02 volumio volumio[13352]: info: MPD Permissions set Feb 08 04:45:02 volumio volumio[13352]: info: Shairport-Sync Started Feb 08 04:45:02 volumio volumio[13352]: Error adding Membership: Error: addMembership EINVAL Feb 08 04:45:02 volumio volumio[13352]: info: Shairport-Sync Started Feb 08 04:45:02 volumio volumio[13352]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Feb 08 04:45:03 volumio volumio[13352]: info: Shairport-Sync Started Feb 08 04:45:03 volumio sudo[13710]: 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 Feb 08 04:45:03 volumio sudo[13710]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:03 volumio sudo[13710]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:03 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:03 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:03 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:03 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:03 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:03 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:03 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:03 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:03 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 04:45:03 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:03 volumio volumio[13352]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Feb 08 04:45:03 volumio volumio[13352]: info: CoreCommandRouter::volumioGetState Feb 08 04:45:03 volumio volumio[13352]: info: CorePlayQueue::getTrack 0 Feb 08 04:45:03 volumio sudo[13719]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Feb 08 04:45:03 volumio sudo[13719]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:03 volumio volumio[13352]: info: Starting Shairport Sync Feb 08 04:45:03 volumio volumio[13352]: 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"} Feb 08 04:45:03 volumio sudo[13722]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 04:45:03 volumio volumio[13352]: info: Spotify Successfully logged in Feb 08 04:45:03 volumio sudo[13722]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:03 volumio volumio[13352]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 04:45:03 volumio volumio[13352]: info: [1770547503362] CoreMusicLibrary::Adding element Spotify Feb 08 04:45:03 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 04:45:03 volumio volumio[13352]: Cannot find translation for source Bandcamp Discover Feb 08 04:45:03 volumio volumio[13352]: Cannot find translation for source SoundCloud Feb 08 04:45:03 volumio volumio[13352]: Cannot find translation for source YouTube2 Feb 08 04:45:03 volumio volumio[13352]: Cannot find translation for source YouTube Music Feb 08 04:45:03 volumio volumio[13352]: Cannot find translation for source Podcast Feb 08 04:45:03 volumio volumio[13352]: Cannot find translation for source Volusonic Feb 08 04:45:03 volumio volumio[13352]: Cannot find translation for source Spotify Feb 08 04:45:03 volumio sudo[13694]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 08 04:45:03 volumio systemd[1]: Reloading. Feb 08 04:45:03 volumio sudo[13694]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 08 04:45:03 volumio sudo[13694]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:04 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:04 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:04 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:04 volumio volumio[13352]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 04:45:04 volumio volumio[13352]: info: go-librespot daemon successfully initialized Feb 08 04:45: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. Feb 08 04:45: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. Feb 08 04:45:06 volumio sudo[13719]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:06 volumio volumio[13352]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 08 04:45:06 volumio sudo[13744]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 08 04:45:06 volumio sudo[13744]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Feb 08 04:45:06 volumio sudo[13744]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:06 volumio volumio[13352]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Feb 08 04:45:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:45:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:45:06 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 08 04:45:06 volumio go-librespot[13747]: go-librespot daemon starting... Feb 08 04:45:06 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 08 04:45:06 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 04:45:06 volumio systemd[1]: shairport-sync.service: Consumed 1.596s CPU time. Feb 08 04:45:06 volumio sudo[13748]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Feb 08 04:45:06 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 04:45:06 volumio sudo[13748]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:06 volumio go-librespot[13749]: time="2026-02-08T04:45:06-06:00" level=info msg="running go-librespot 0.4.0" Feb 08 04:45:06 volumio go-librespot[13749]: time="2026-02-08T04:45:06-06:00" level=debug msg="app state loaded" Feb 08 04:45:06 volumio go-librespot[13749]: time="2026-02-08T04:45:06-06:00" level=debug msg="stored credentials not found" Feb 08 04:45:06 volumio sudo[13722]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:06 volumio go-librespot[13749]: time="2026-02-08T04:45:06-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 04:45:06 volumio volumio[13352]: info: Shairport-Sync Started Feb 08 04:45:06 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Feb 08 04:45:06 volumio systemd[1]: squeezelite.service: Deactivated successfully. Feb 08 04:45:06 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Feb 08 04:45:06 volumio sudo[13748]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:07 volumio go-librespot[13749]: time="2026-02-08T04:45:07-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]" Feb 08 04:45:07 volumio go-librespot[13749]: time="2026-02-08T04:45:07-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]" Feb 08 04:45:07 volumio go-librespot[13749]: time="2026-02-08T04:45:07-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]" Feb 08 04:45:07 volumio go-librespot[13749]: time="2026-02-08T04:45:07-06:00" level=info msg="zeroconf server listening on port 36835" Feb 08 04:45:07 volumio go-librespot[13749]: time="2026-02-08T04:45:07-06:00" level=debug msg="obtained new client token: AABoI9VT1GCHzKAvDTkv4ZNLLHO1JzKJiVQjn+eS2qqNzSHyL61AfvCVSlolUvdUv5o9uB52zhO/yrSf9Jx2F/w5cZwpfWJE1vSNt/rxr8fiDugeBkjCNgdqdXbCXAuqXnBmaqrCwXp2UDv3M40witi+S2vZf6iRER1EZ28Q9zWuk6R53nj/rkvU1no18Fotc0/EKPo+FTHtq3DybKrTh21XhZ+7614sCqxFIi1OZaO4GcRiYBUW+xc=" Feb 08 04:45:07 volumio go-librespot[13749]: time="2026-02-08T04:45:07-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 08 04:45:07 volumio go-librespot[13749]: time="2026-02-08T04:45:07-06:00" level=debug msg="completed keyexchange" Feb 08 04:45:07 volumio go-librespot[13749]: time="2026-02-08T04:45:07-06:00" level=debug msg="completed challenge" Feb 08 04:45:07 volumio go-librespot[13749]: time="2026-02-08T04:45: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 " Feb 08 04:45:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 04:45:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 04:45:07 volumio volumio[13352]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 08 04:45:07 volumio sudo[13773]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 08 04:45:07 volumio sudo[13773]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:07 volumio sudo[13773]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:07 volumio volumio[13352]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Feb 08 04:45:07 volumio sudo[13777]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Feb 08 04:45:07 volumio sudo[13777]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:07 volumio sudo[13777]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:07 volumio volumio[13352]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Feb 08 04:45:07 volumio sudo[13780]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Feb 08 04:45:07 volumio sudo[13780]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:07 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Feb 08 04:45:07 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Feb 08 04:45:07 volumio sudo[13780]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:07 volumio volumio[13352]: info: Initializing connection to go-librespot Websocket Feb 08 04:45:07 volumio volumio[13352]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 04:45:08 volumio volumio[13352]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 08 04:45:08 volumio sudo[13787]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 08 04:45:08 volumio sudo[13787]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:08 volumio sudo[13787]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:08 volumio kernel: hwmon hwmon1: Voltage normalised Feb 08 04:45:08 volumio volumio[13352]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 08 04:45:08 volumio sudo[13791]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 08 04:45:08 volumio sudo[13791]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:09 volumio sudo[13791]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:09 volumio volumio[13352]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 08 04:45:09 volumio sudo[13794]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 08 04:45:09 volumio sudo[13794]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:09 volumio sudo[13794]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:09 volumio mpd[13742]: 2026-02-08T04:45:09 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 08 04:45:09 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 08 04:45:09 volumio sudo[13586]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:09 volumio sudo[13666]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:09 volumio sudo[13571]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:09 volumio volumio[13352]: error: MPD error: The expression evaluated to a falsy value: Feb 08 04:45:09 volumio volumio[13352]: assert.ok(self.idling) Feb 08 04:45:09 volumio volumio[13352]: error: The expression evaluated to a falsy value: Feb 08 04:45:09 volumio volumio[13352]: assert.ok(self.idling) Feb 08 04:45:09 volumio volumio[13352]: error: MPD error: The expression evaluated to a falsy value: Feb 08 04:45:09 volumio volumio[13352]: assert.ok(self.idling) Feb 08 04:45:09 volumio volumio[13352]: error: The expression evaluated to a falsy value: Feb 08 04:45:09 volumio volumio[13352]: assert.ok(self.idling) Feb 08 04:45:09 volumio volumio[13352]: info: MPD running with PID13742 Feb 08 04:45:09 volumio volumio[13352]: ,establishing connection Feb 08 04:45:09 volumio volumio[13352]: error: updateQueue error: null Feb 08 04:45:09 volumio volumio[13352]: error: updateQueue error: null Feb 08 04:45:10 volumio volumio[13352]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 08 04:45:10 volumio sudo[13801]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 08 04:45:10 volumio sudo[13801]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:10 volumio sudo[13801]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Feb 08 04:45:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:45:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:45:10 volumio go-librespot[13803]: go-librespot daemon starting... Feb 08 04:45:10 volumio go-librespot[13804]: time="2026-02-08T04:45:10-06:00" level=info msg="running go-librespot 0.4.0" Feb 08 04:45:10 volumio go-librespot[13804]: time="2026-02-08T04:45:10-06:00" level=debug msg="app state loaded" Feb 08 04:45:10 volumio go-librespot[13804]: time="2026-02-08T04:45:10-06:00" level=debug msg="stored credentials not found" Feb 08 04:45:10 volumio go-librespot[13804]: time="2026-02-08T04:45:10-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 04:45:10 volumio volumio[13352]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 08 04:45:10 volumio sudo[13812]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 08 04:45:10 volumio sudo[13812]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:10 volumio sudo[13812]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:10 volumio volumio[13352]: info: Completed starting Core Plugins Feb 08 04:45:10 volumio go-librespot[13804]: time="2026-02-08T04:45: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 04:45:10 volumio go-librespot[13804]: time="2026-02-08T04:45:10-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]" Feb 08 04:45:10 volumio go-librespot[13804]: time="2026-02-08T04:45:10-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]" Feb 08 04:45:10 volumio volumio[13352]: info: ------------------------------------------- Feb 08 04:45:10 volumio volumio[13352]: info: ----- MyVolumio plugins startup ---- Feb 08 04:45:10 volumio volumio[13352]: info: ------------------------------------------- Feb 08 04:45:10 volumio volumio[13352]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 08 04:45:10 volumio go-librespot[13804]: time="2026-02-08T04:45:10-06:00" level=info msg="zeroconf server listening on port 36945" Feb 08 04:45:10 volumio go-librespot[13804]: time="2026-02-08T04:45:10-06:00" level=debug msg="obtained new client token: AACE/hTdZQkQbSU424hn2aUJUMt8vpP6Di+9ISJ4gwBMqCg6MsCpIwKSzh72Gt8+4BPaxX8NlPL0dDvM7gHVNlmiBykvoq3RMjvie9yQK6oOq3IoMbk2weV6we9mQQfhaMW+dOhjipE4i7NVXdORowq64/4K39fPGGiINHYPO6NatKDHoM8rPlREbPmGRK+ilnrtHcFUdPkrYhmuuemEC4HLgk/d46PRwkLpmPLKMGVvZWiQIGR1QweZLQ==" Feb 08 04:45:10 volumio go-librespot[13804]: time="2026-02-08T04:45:10-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 08 04:45:10 volumio volumio[13352]: info: Initializing connection to go-librespot Websocket Feb 08 04:45:11 volumio go-librespot[13804]: time="2026-02-08T04:45:11-06:00" level=debug msg="new websocket client" Feb 08 04:45:11 volumio volumio[13352]: info: Connection to go-librespot Websocket established Feb 08 04:45:11 volumio go-librespot[13804]: time="2026-02-08T04:45:11-06:00" level=debug msg="completed keyexchange" Feb 08 04:45:11 volumio go-librespot[13804]: time="2026-02-08T04:45:11-06:00" level=debug msg="completed challenge" Feb 08 04:45:11 volumio go-librespot[13804]: time="2026-02-08T04:45: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 " Feb 08 04:45:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 04:45:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 04:45:11 volumio volumio[13352]: info: Connection to go-librespot Websocket closed Feb 08 04:45:12 volumio sudo[13831]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 08 04:45:12 volumio sudo[13831]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:12 volumio sudo[13834]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 08 04:45:12 volumio sudo[13834]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:12 volumio sudo[13836]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 08 04:45:12 volumio sudo[13836]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:12 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 08 04:45:12 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 08 04:45:12 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 08 04:45:13 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 08 04:45:13 volumio sudo[13831]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:13 volumio mpd_monitor.sh[13840]: MPD Monitor Service: Starting MPD Monitor Service Feb 08 04:45:13 volumio sudo[13836]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:13 volumio sudo[13834]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:13 volumio volumio[13352]: info: Successfully started MPD Monitor Feb 08 04:45:13 volumio volumio[13352]: info: Successfully started MPD Monitor Feb 08 04:45:13 volumio volumio[13352]: info: Successfully started MPD Monitor Feb 08 04:45:14 volumio volumio[13352]: info: Getting Spotify volume Feb 08 04:45:14 volumio volumio[13352]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 08 04:45:14 volumio volumio[13352]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 04:45:14 volumio volumio[13352]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 08 04:45:14 volumio volumio[13352]: errno: -111, Feb 08 04:45:14 volumio volumio[13352]: code: 'ECONNREFUSED', Feb 08 04:45:14 volumio volumio[13352]: syscall: 'connect', Feb 08 04:45:14 volumio volumio[13352]: address: '127.0.0.1', Feb 08 04:45:14 volumio volumio[13352]: port: 9879, Feb 08 04:45:14 volumio volumio[13352]: response: undefined Feb 08 04:45:14 volumio volumio[13352]: } Feb 08 04:45:14 volumio volumio[13352]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 08 04:45:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31. Feb 08 04:45:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:45:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:45:14 volumio go-librespot[13856]: go-librespot daemon starting... Feb 08 04:45:14 volumio go-librespot[13857]: time="2026-02-08T04:45:14-06:00" level=info msg="running go-librespot 0.4.0" Feb 08 04:45:14 volumio go-librespot[13857]: time="2026-02-08T04:45:14-06:00" level=debug msg="app state loaded" Feb 08 04:45:14 volumio go-librespot[13857]: time="2026-02-08T04:45:14-06:00" level=debug msg="stored credentials not found" Feb 08 04:45:14 volumio go-librespot[13857]: time="2026-02-08T04:45:14-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 04:45:14 volumio go-librespot[13857]: time="2026-02-08T04:45: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]" Feb 08 04:45:14 volumio go-librespot[13857]: time="2026-02-08T04:45: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]" Feb 08 04:45:14 volumio go-librespot[13857]: time="2026-02-08T04:45: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]" Feb 08 04:45:14 volumio go-librespot[13857]: time="2026-02-08T04:45:14-06:00" level=info msg="zeroconf server listening on port 45887" Feb 08 04:45:14 volumio go-librespot[13857]: time="2026-02-08T04:45:14-06:00" level=debug msg="obtained new client token: AAA8TOymJ4z/THSE8iGtywRp8fJVHnpUqGmbBqW4vHqIQVGVwZ5nArTlU3Kf10dF0B2C1gZVmikRH5ni5kJNgu3rqnpE7N3WXbZrm1N+8inTzYPP05XP4vFeIB8Wkan6LT2pssxdsRwiw0RHa8Nk5dHQygJr9XkOUjsWeKLgUIszZT+27gqfPrBHGc1aBqcOWJbcuXWSOFcbSYN//Re5uiuoi/YHnpnNc2eC0qA4rgE8fRGVf3xBBCC/fA==" Feb 08 04:45:14 volumio go-librespot[13857]: time="2026-02-08T04:45:14-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 08 04:45:14 volumio sudo[13866]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-08 04:44' Feb 08 04:45:14 volumio sudo[13866]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:14 volumio go-librespot[13857]: time="2026-02-08T04:45:14-06:00" level=debug msg="completed keyexchange" Feb 08 04:45:14 volumio go-librespot[13857]: time="2026-02-08T04:45:14-06:00" level=debug msg="completed challenge" Feb 08 04:45:14 volumio go-librespot[13857]: time="2026-02-08T04:45:14-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 " Feb 08 04:45:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 04:45:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 04:45:15 volumio sudo[13866]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:15 volumio volumio-remote-updater[751]: [2026-02-08 04:45:15] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 08 04:45:15 volumio volumio-remote-updater[751]: [2026-02-08 04:45:15] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 08 04:45:15 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 08 04:45:15 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 08 04:45:15 volumio systemd[1]: volumio.service: Consumed 45.358s CPU time. Feb 08 04:45:15 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 08 04:45:15 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 08 04:45:15 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 697. Feb 08 04:45:15 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 08 04:45:15 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 08 04:45:15 volumio systemd[1]: volumio.service: Consumed 45.358s CPU time. Feb 08 04:45:15 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 08 04:45:15 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 08 04:45:17 volumio volumio[13879]: info: ------------------------------------------- Feb 08 04:45:17 volumio volumio[13879]: info: ----- Volumio3 ---- Feb 08 04:45:17 volumio volumio[13879]: info: ------------------------------------------- Feb 08 04:45:17 volumio volumio[13879]: info: ----- System startup ---- Feb 08 04:45:17 volumio volumio[13879]: info: ------------------------------------------- Feb 08 04:45:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32. Feb 08 04:45:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:45:18 volumio volumio[13879]: info: MYVOLUMIO Environment detected Feb 08 04:45:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:45:18 volumio go-librespot[13904]: go-librespot daemon starting... Feb 08 04:45:18 volumio go-librespot[13905]: time="2026-02-08T04:45:18-06:00" level=info msg="running go-librespot 0.4.0" Feb 08 04:45:18 volumio go-librespot[13905]: time="2026-02-08T04:45:18-06:00" level=debug msg="app state loaded" Feb 08 04:45:18 volumio go-librespot[13905]: time="2026-02-08T04:45:18-06:00" level=debug msg="stored credentials not found" Feb 08 04:45:18 volumio go-librespot[13905]: time="2026-02-08T04:45:18-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 04:45:18 volumio volumio[13879]: info: Plugin folders cleanup Feb 08 04:45:18 volumio volumio[13879]: info: Scanning into folder /volumio/app/plugins/ Feb 08 04:45:18 volumio volumio[13879]: info: Scanning category audio_interface Feb 08 04:45:18 volumio volumio[13879]: info: Scanning category miscellanea Feb 08 04:45:18 volumio volumio[13879]: info: Scanning category music_service Feb 08 04:45:18 volumio volumio[13879]: info: Scanning category plugins.json Feb 08 04:45:18 volumio volumio[13879]: info: Scanning category system_controller Feb 08 04:45:18 volumio volumio[13879]: info: Scanning category user_interface Feb 08 04:45:18 volumio volumio[13879]: info: Scanning into folder /data/plugins/ Feb 08 04:45:18 volumio volumio[13879]: info: Scanning category audio_interface Feb 08 04:45:18 volumio volumio[13879]: info: Scanning category music_service Feb 08 04:45:18 volumio volumio[13879]: info: Scanning category system_controller Feb 08 04:45:18 volumio volumio[13879]: info: Scanning category system_hardware Feb 08 04:45:18 volumio volumio[13879]: info: Scanning category user_interface Feb 08 04:45:18 volumio volumio[13879]: info: Plugin folders cleanup completed Feb 08 04:45:18 volumio volumio[13879]: info: ------------------------------------------- Feb 08 04:45:18 volumio volumio[13879]: info: ----- Core plugins startup ---- Feb 08 04:45:18 volumio volumio[13879]: info: ------------------------------------------- Feb 08 04:45:18 volumio volumio[13879]: info: Loading plugins from folder /volumio/app/plugins/ Feb 08 04:45:18 volumio volumio[13879]: info: Adding plugin upnp to MyMusic Plugins Feb 08 04:45:18 volumio volumio[13879]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 08 04:45:18 volumio volumio[13879]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 08 04:45:18 volumio volumio[13879]: info: Loading plugins from folder /data/plugins/ Feb 08 04:45:18 volumio volumio[13879]: info: Loading plugin "system"... Feb 08 04:45:18 volumio volumio[13879]: info: Loading plugin "appearance"... Feb 08 04:45:18 volumio go-librespot[13905]: time="2026-02-08T04:45:18-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]" Feb 08 04:45:18 volumio go-librespot[13905]: time="2026-02-08T04:45:18-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]" Feb 08 04:45:18 volumio go-librespot[13905]: time="2026-02-08T04:45:18-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]" Feb 08 04:45:18 volumio go-librespot[13905]: time="2026-02-08T04:45:18-06:00" level=info msg="zeroconf server listening on port 38191" Feb 08 04:45:18 volumio go-librespot[13905]: time="2026-02-08T04:45:18-06:00" level=debug msg="obtained new client token: AAB/dPySKwH3IRJvI7WROrEhxpoIC8/MrmpZV586oJacD2iAV45d722qQN/O8qevzUv6cG4M8CSPzjqHgHmr6mxx6YZpV5Qf7kOx5M2NAWHx0oh0hGYomvuZvMSkAukyMefBiYwjQyibCxAsp3sNdJkgfotTOvOMsQNEiRf0ZGleKr57VesicRqdlMav1/lBO88FmvqiFVlG41aWckE14P8qNlKsqD5YShMxT6P7wXQASGjLTkWOan1OIg==" Feb 08 04:45:18 volumio go-librespot[13905]: time="2026-02-08T04:45:18-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 08 04:45:18 volumio go-librespot[13905]: time="2026-02-08T04:45:18-06:00" level=debug msg="completed keyexchange" Feb 08 04:45:18 volumio go-librespot[13905]: time="2026-02-08T04:45:18-06:00" level=debug msg="completed challenge" Feb 08 04:45:18 volumio go-librespot[13905]: time="2026-02-08T04:45:18-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 " Feb 08 04:45:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 04:45:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 04:45:19 volumio volumio[13879]: info: Loading plugin "network"... Feb 08 04:45:19 volumio volumio[13879]: info: Refreshing Cached IP Addresses Feb 08 04:45:19 volumio sudo[13917]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 08 04:45:19 volumio sudo[13917]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:19 volumio sudo[13917]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:19 volumio sudo[13919]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 08 04:45:19 volumio sudo[13919]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:19 volumio volumio[13879]: info: Loading plugin "services"... Feb 08 04:45:19 volumio sudo[13919]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:19 volumio volumio[13879]: info: Loading plugin "alsa_controller"... Feb 08 04:45:19 volumio sudo[13927]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 08 04:45:19 volumio sudo[13927]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:19 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 04:45:19 volumio volumio[13879]: info: Loading plugin "wizard"... Feb 08 04:45:19 volumio volumio[13879]: info: Loading plugin "networkfs"... Feb 08 04:45:19 volumio volumio[13879]: info: Starting Udev Watcher for removable devices Feb 08 04:45:19 volumio volumio[13879]: info: Ignoring mount for partition: boot Feb 08 04:45:19 volumio volumio[13879]: info: Ignoring mount for partition: volumio Feb 08 04:45:19 volumio volumio[13879]: info: Ignoring mount for partition: volumio_data Feb 08 04:45:19 volumio volumio[13879]: info: Mounting Device Wikipedia Feb 08 04:45:19 volumio sudo[13956]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime Feb 08 04:45:19 volumio sudo[13956]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:19 volumio sudo[13956]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:19 volumio volumio[13879]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Feb 08 04:45:19 volumio volumio[13879]: dmesg(1) may have more information after failed mount system call. Feb 08 04:45:19 volumio volumio[13879]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime Feb 08 04:45:19 volumio volumio[13879]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Feb 08 04:45:19 volumio volumio[13879]: dmesg(1) may have more information after failed mount system call. Feb 08 04:45:19 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 04:45:19 volumio volumio[13879]: info: Loading plugin "volumio_command_line_client"... Feb 08 04:45:19 volumio volumio[13879]: info: Loading plugin "upnp"... Feb 08 04:45:19 volumio volumio[13879]: info: [1770547519753] Starting Upmpd Daemon Feb 08 04:45:19 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 04:45:19 volumio volumio[13879]: info: Loading plugin "my_music"... Feb 08 04:45:19 volumio volumio[13879]: info: Loading plugin "mpd"... Feb 08 04:45:19 volumio sudo[13927]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:20 volumio volumio-remote-updater[751]: [2026-02-08 04:45:20] [connect] Successful connection Feb 08 04:45:20 volumio volumio[13879]: info: Loading plugin "upnp_browser"... Feb 08 04:45:21 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 08 04:45:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33. Feb 08 04:45:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:45:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:45:21 volumio go-librespot[13959]: go-librespot daemon starting... Feb 08 04:45:21 volumio go-librespot[13960]: time="2026-02-08T04:45:21-06:00" level=info msg="running go-librespot 0.4.0" Feb 08 04:45:21 volumio go-librespot[13960]: time="2026-02-08T04:45:21-06:00" level=debug msg="app state loaded" Feb 08 04:45:21 volumio go-librespot[13960]: time="2026-02-08T04:45:21-06:00" level=debug msg="stored credentials not found" Feb 08 04:45:21 volumio go-librespot[13960]: time="2026-02-08T04:45:21-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 04:45:22 volumio go-librespot[13960]: time="2026-02-08T04:45:22-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]" Feb 08 04:45:22 volumio go-librespot[13960]: time="2026-02-08T04:45:22-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]" Feb 08 04:45:22 volumio go-librespot[13960]: time="2026-02-08T04:45:22-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]" Feb 08 04:45:22 volumio go-librespot[13960]: time="2026-02-08T04:45:22-06:00" level=info msg="zeroconf server listening on port 45975" Feb 08 04:45:22 volumio go-librespot[13960]: time="2026-02-08T04:45:22-06:00" level=debug msg="obtained new client token: AAAGRCmlvTkp+CwCc716/4KzpDLO3uARprnLzcCXU3Yb5Tl8ShjZWbJukwq5KpRwvlWpj9hqzOYSvVGFuOU+DhQUp60OIIOH11U8jHRFu22oJ1oIzKmQAtOyX0d2+TXsW75cQ5JncF462wSW2jmPfelHUojEyd96xk4XvYJoFahBzFD3VnJTgWCOfGZpjB3c5dOTfSpRguKOyFOY/qDv1++dGam8/o74IwAqkgOwwHwNFModkd4YqNIrDw==" Feb 08 04:45:22 volumio go-librespot[13960]: time="2026-02-08T04:45:22-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 08 04:45:22 volumio go-librespot[13960]: time="2026-02-08T04:45:22-06:00" level=debug msg="completed keyexchange" Feb 08 04:45:22 volumio go-librespot[13960]: time="2026-02-08T04:45:22-06:00" level=debug msg="completed challenge" Feb 08 04:45:22 volumio go-librespot[13960]: time="2026-02-08T04:45:22-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 " Feb 08 04:45:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 04:45:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 04:45:23 volumio volumio[13879]: info: Loading plugin "alarm-clock"... Feb 08 04:45:23 volumio volumio[13879]: info: Loading plugin "airplay_emulation"... Feb 08 04:45:23 volumio volumio[13879]: info: Starting Shairport Sync Feb 08 04:45:23 volumio volumio[13879]: info: Loading plugin "last_100"... Feb 08 04:45:23 volumio volumio[13879]: info: Loading plugin "webradio"... Feb 08 04:45:23 volumio volumio[13879]: info: Loading plugin "i2s_dacs"... Feb 08 04:45:23 volumio volumio[13879]: info: I2S DAC not set, start Auto-detection Feb 08 04:45:23 volumio volumio[13879]: info: Loading plugin "volumiodiscovery"... Feb 08 04:45:23 volumio volumio[13879]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 08 04:45:23 volumio volumio[13879]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 04:45:23 volumio volumio[13879]: *** WARNING *** For more information see Feb 08 04:45:23 volumio volumio[13879]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 08 04:45:23 volumio volumio[13879]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 04:45:23 volumio volumio[13879]: *** WARNING *** For more information see Feb 08 04:45:23 volumio node[13879]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 08 04:45:23 volumio node[13879]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 04:45:23 volumio node[13879]: *** WARNING *** For more information see Feb 08 04:45:23 volumio node[13879]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 08 04:45:23 volumio node[13879]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 04:45:23 volumio node[13879]: *** WARNING *** For more information see Feb 08 04:45:23 volumio volumio[13879]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 08 04:45:23 volumio volumio[13879]: info: Discovery: Started advertising with name: Volumio Feb 08 04:45:23 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 04:45:23 volumio volumio[13879]: info: Loading plugin "bandcamp"... Feb 08 04:45:24 volumio volumio[13879]: info: Plugin calmradio is not enabled Feb 08 04:45:24 volumio volumio[13879]: info: Loading plugin "soundcloud"... Feb 08 04:45:25 volumio volumio[13879]: info: Loading plugin "spop"... Feb 08 04:45:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34. Feb 08 04:45:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:45:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:45:25 volumio go-librespot[13970]: go-librespot daemon starting... Feb 08 04:45:25 volumio go-librespot[13971]: time="2026-02-08T04:45:25-06:00" level=info msg="running go-librespot 0.4.0" Feb 08 04:45:25 volumio go-librespot[13971]: time="2026-02-08T04:45:25-06:00" level=debug msg="app state loaded" Feb 08 04:45:25 volumio go-librespot[13971]: time="2026-02-08T04:45:25-06:00" level=debug msg="stored credentials not found" Feb 08 04:45:25 volumio go-librespot[13971]: time="2026-02-08T04:45:25-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 04:45:26 volumio go-librespot[13971]: time="2026-02-08T04:45:26-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]" Feb 08 04:45:26 volumio go-librespot[13971]: time="2026-02-08T04:45:26-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]" Feb 08 04:45:26 volumio go-librespot[13971]: time="2026-02-08T04:45:26-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]" Feb 08 04:45:26 volumio go-librespot[13971]: time="2026-02-08T04:45:26-06:00" level=info msg="zeroconf server listening on port 35817" Feb 08 04:45:26 volumio go-librespot[13971]: time="2026-02-08T04:45:26-06:00" level=debug msg="obtained new client token: AAAeOSUHApwy3u5eLSuTirkUy7AiXBbUrNEkZM151uhBbhl4yLQnu161NceQxXzRPvS5jJXR4wnZhoHA/YCrusqqkvLJeC7CuICRG2oU+ibi/6qjTHZ0QNWHoAyvYe8p+rCh6hSqNtcCSBPCA90uD9x5s8Pz/VP70zSiNTPh/A0MRlX4tNb7zAM2PYw/EiBpdPIu12I9TFza4jxEIZQbXXyuVGa2RZ+5CKOzF3S69HVRL1o0vie1EGEDXg==" Feb 08 04:45:26 volumio go-librespot[13971]: time="2026-02-08T04:45:26-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 08 04:45:26 volumio go-librespot[13971]: time="2026-02-08T04:45:26-06:00" level=debug msg="completed keyexchange" Feb 08 04:45:26 volumio go-librespot[13971]: time="2026-02-08T04:45:26-06:00" level=debug msg="completed challenge" Feb 08 04:45:26 volumio go-librespot[13971]: time="2026-02-08T04:45:26-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 " Feb 08 04:45:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 04:45:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 04:45:27 volumio volumio[13879]: info: Loading plugin "squeezelite_mc"... Feb 08 04:45:28 volumio volumio[13879]: info: Loading plugin "youtube2"... Feb 08 04:45:28 volumio volumio[13879]: info: Loading plugin "ytcr"... Feb 08 04:45:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 35. Feb 08 04:45:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:45:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:45:29 volumio go-librespot[13992]: go-librespot daemon starting... Feb 08 04:45:29 volumio go-librespot[13993]: time="2026-02-08T04:45:29-06:00" level=info msg="running go-librespot 0.4.0" Feb 08 04:45:29 volumio go-librespot[13993]: time="2026-02-08T04:45:29-06:00" level=debug msg="app state loaded" Feb 08 04:45:29 volumio go-librespot[13993]: time="2026-02-08T04:45:29-06:00" level=debug msg="stored credentials not found" Feb 08 04:45:29 volumio go-librespot[13993]: time="2026-02-08T04:45:29-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 04:45:30 volumio go-librespot[13993]: time="2026-02-08T04:45:30-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]" Feb 08 04:45:30 volumio go-librespot[13993]: time="2026-02-08T04:45:30-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]" Feb 08 04:45:30 volumio go-librespot[13993]: time="2026-02-08T04:45:30-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]" Feb 08 04:45:30 volumio volumio[13879]: info: Loading plugin "ytmusic"... Feb 08 04:45:30 volumio go-librespot[13993]: time="2026-02-08T04:45:30-06:00" level=info msg="zeroconf server listening on port 45241" Feb 08 04:45:30 volumio go-librespot[13993]: time="2026-02-08T04:45:30-06:00" level=debug msg="obtained new client token: AABKsPzT6J0aYsNIXo8xb7+W2sY8AKIGCoFaGtpiPHZcICpdhzGxNvEHHMKR7UkgB0DD6dVB2YKVyzCks50wlQ6zm/fDMlFsZj2+PANUmjdVBHourYrKUv1hCCD3lbgT4uj4kfpdpamsfwYYPIH124DkM1sUKow9RmWeXEFPbNbce5hfqUpiFePSO/Lw/JDge8gsXthBsz2C0TGydKGVixQ1Blk/N0AtggwYHbAfdITAZJNKWFSLrrkNQw==" Feb 08 04:45:30 volumio go-librespot[13993]: time="2026-02-08T04:45:30-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 08 04:45:30 volumio go-librespot[13993]: time="2026-02-08T04:45:30-06:00" level=debug msg="completed keyexchange" Feb 08 04:45:30 volumio go-librespot[13993]: time="2026-02-08T04:45:30-06:00" level=debug msg="completed challenge" Feb 08 04:45:30 volumio go-librespot[13993]: time="2026-02-08T04:45:30-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 " Feb 08 04:45:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 04:45:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 04:45:30 volumio volumio[13879]: info: Plugin now_playing is not enabled Feb 08 04:45:30 volumio volumio[13879]: info: Loading plugin "outputs"... Feb 08 04:45:30 volumio volumio[13879]: info: Loading plugin "albumart"... Feb 08 04:45:30 volumio volumio[13879]: info: Plugin example_plugin is not enabled Feb 08 04:45:30 volumio volumio[13879]: info: Loading plugin "inputs"... Feb 08 04:45:30 volumio volumio[13879]: info: Loading plugin "updater_comm"... Feb 08 04:45:30 volumio volumio[13879]: info: Plugin mpdemulation is not enabled Feb 08 04:45:30 volumio volumio[13879]: info: Loading plugin "rest_api"... Feb 08 04:45:30 volumio volumio[13879]: info: Loading plugin "websocket"... Feb 08 04:45:30 volumio volumio[13879]: info: Starting Socket.io Server version 1.7.4 Feb 08 04:45:30 volumio volumio[13879]: info: Plugin fusiondsp is not enabled Feb 08 04:45:30 volumio volumio[13879]: info: Plugin mpdoutput is not enabled Feb 08 04:45:30 volumio volumio[13879]: info: Plugin RoonBridge is not enabled Feb 08 04:45:30 volumio volumio[13879]: info: Loading plugin "podcast"... Feb 08 04:45:31 volumio volumio[13879]: info: ControllerPodcast::constructor Feb 08 04:45:31 volumio volumio[13879]: info: Loading plugin "volusonic"... Feb 08 04:45:31 volumio volumio[14002]: Forking 3 albumart workers Feb 08 04:45:31 volumio kernel: hwmon hwmon1: Voltage normalised Feb 08 04:45:32 volumio volumio-remote-updater[751]: [2026-02-08 04:45:32] [connect] Successful connection Feb 08 04:45:33 volumio volumio[13879]: info: Applying required configuration parameters for plugin volusonic Feb 08 04:45:33 volumio volumio[13879]: info: Loading plugin "backup_restore"... Feb 08 04:45:33 volumio volumio[14012]: Starting albumart workers Feb 08 04:45:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 36. Feb 08 04:45:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:45:33 volumio volumio[14014]: Starting albumart workers Feb 08 04:45:33 volumio volumio[13879]: info: Applying required configuration parameters for plugin backup_restore Feb 08 04:45:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:45:33 volumio go-librespot[14046]: go-librespot daemon starting... Feb 08 04:45:33 volumio volumio[13879]: info: Plugin rpi_eeprom_config is not enabled Feb 08 04:45:33 volumio volumio[13879]: info: Plugin rpi_eeprom_updater is not enabled Feb 08 04:45:33 volumio volumio[13879]: info: Loading plugin "scheduledrestart"... Feb 08 04:45:33 volumio volumio[14013]: Starting albumart workers Feb 08 04:45:33 volumio go-librespot[14047]: time="2026-02-08T04:45:33-06:00" level=info msg="running go-librespot 0.4.0" Feb 08 04:45:33 volumio go-librespot[14047]: time="2026-02-08T04:45:33-06:00" level=debug msg="app state loaded" Feb 08 04:45:33 volumio go-librespot[14047]: time="2026-02-08T04:45:33-06:00" level=debug msg="stored credentials not found" Feb 08 04:45:33 volumio go-librespot[14047]: time="2026-02-08T04:45:33-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 04:45:33 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 08 04:45:34 volumio volumio[13879]: info: Applying required configuration parameters for plugin scheduledrestart Feb 08 04:45:34 volumio volumio[13879]: info: Plugin Bluetoothremote is not enabled Feb 08 04:45:34 volumio volumio[13879]: info: Plugin music_services_shield is not enabled Feb 08 04:45:34 volumio volumio[13879]: info: Loading plugin "Systeminfo"... Feb 08 04:45:34 volumio go-librespot[14047]: time="2026-02-08T04:45:34-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]" Feb 08 04:45:34 volumio go-librespot[14047]: time="2026-02-08T04:45:34-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]" Feb 08 04:45:34 volumio go-librespot[14047]: time="2026-02-08T04:45:34-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]" Feb 08 04:45:34 volumio go-librespot[14047]: time="2026-02-08T04:45:34-06:00" level=info msg="zeroconf server listening on port 45691" Feb 08 04:45:34 volumio go-librespot[14047]: time="2026-02-08T04:45:34-06:00" level=debug msg="obtained new client token: AAD96EIJGz/d9VN2t1q7MNS9PS4VMNmbGI/2Ptbo/ZA3pO9FhjXHB7WZng49WomVt6eHOZu472EDLuMIl9B9lGpMk9pK8fABdERmFGmw0r2GXhzS02R+06jLn8aOKcDCoAO3BlUcYgCE1OM8JI17fOPhWlvV03wtzMsM4ZhGzAnU8Y0tb6U+/Z0eHYL7q8gSGjRiazvRH+F0Ntv+qDOqscB8EG7urwFinAOXQht8dao/M2VSJRr4NxkL2w==" Feb 08 04:45:34 volumio go-librespot[14047]: time="2026-02-08T04:45:34-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 08 04:45:34 volumio go-librespot[14047]: time="2026-02-08T04:45:34-06:00" level=debug msg="completed keyexchange" Feb 08 04:45:34 volumio go-librespot[14047]: time="2026-02-08T04:45:34-06:00" level=debug msg="completed challenge" Feb 08 04:45:34 volumio go-librespot[14047]: time="2026-02-08T04:45:34-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 " Feb 08 04:45:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 04:45:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 04:45:35 volumio volumio[13879]: info: Plugin peppymeterbasic is not enabled Feb 08 04:45:35 volumio volumio[13879]: info: Loading plugin "peppyspectrum"... Feb 08 04:45:35 volumio volumio[13879]: info: Loading i18n strings for locale en Feb 08 04:45:35 volumio volumio[13879]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Feb 08 04:45:35 volumio volumio[13879]: Updating browse sources language Feb 08 04:45:35 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 04:45:35 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 04:45:35 volumio volumio[13879]: info: CoreCommandRouter::initPlayerControls Feb 08 04:45:35 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:35 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:35 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:35 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:35 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:35 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:35 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:35 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:35 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 04:45:35 volumio volumio[13879]: Express server listening on port 3000 Feb 08 04:45:35 volumio volumio[13879]: [Metrics] WebUI: 18s 922.57ms Feb 08 04:45:35 volumio volumio[13879]: info: CoreStateMachine::resetVolumioState Feb 08 04:45:35 volumio volumio[13879]: info: CoreStateMachine::getcurrentVolume Feb 08 04:45:35 volumio volumio[13879]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 04:45:35 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 04:45:35 volumio sudo[14077]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 08 04:45:35 volumio sudo[14077]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:35 volumio sudo[14077]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:35 volumio sudo[14079]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 08 04:45:35 volumio sudo[14079]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:35 volumio sudo[14079]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:35 volumio volumio[13879]: info: Volumio Network Manager: Network status updated: 1 Feb 08 04:45:35 volumio volumio[13879]: info: VolumeController:: Volume=100 Mute =false Feb 08 04:45:35 volumio volumio[13879]: info: CoreStateMachine::pushState Feb 08 04:45:35 volumio volumio[13879]: info: CorePlayQueue::getTrack 0 Feb 08 04:45:35 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 08 04:45:35 volumio volumio[13879]: info: CoreCommandRouter::volumioPushState Feb 08 04:45:35 volumio volumio[13879]: info: CoreStateMachine::updateTrackBlock Feb 08 04:45:35 volumio volumio[13879]: info: CorePlayQueue::getTrackBlock Feb 08 04:45:35 volumio volumio[13879]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 04:45:35 volumio volumio-remote-updater[751]: [2026-02-08 04:45:35] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770547532 101 Feb 08 04:45:35 volumio volumio[13879]: 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 Feb 08 04:45:36 volumio volumio[13879]: info: Reloading queue from file Feb 08 04:45:36 volumio volumio[13879]: info: CoreStateMachine::setRepeat null single undefined Feb 08 04:45:36 volumio volumio[13879]: info: CoreStateMachine::pushState Feb 08 04:45:36 volumio volumio[13879]: info: CorePlayQueue::getTrack 0 Feb 08 04:45:36 volumio volumio[13879]: info: CoreCommandRouter::volumioPushState Feb 08 04:45:36 volumio volumio[13879]: info: CoreStateMachine::setRandom null Feb 08 04:45:36 volumio volumio[13879]: info: CoreStateMachine::pushState Feb 08 04:45:36 volumio volumio[13879]: info: CorePlayQueue::getTrack 0 Feb 08 04:45:36 volumio volumio[13879]: info: CoreCommandRouter::volumioPushState Feb 08 04:45:36 volumio volumio[13879]: info: Setting Device type: Raspberry PI Feb 08 04:45:36 volumio volumio[13879]: info: VolumeController:: Volume=100 Mute =false Feb 08 04:45:36 volumio volumio[13879]: info: CoreStateMachine::pushState Feb 08 04:45:36 volumio volumio[13879]: info: CorePlayQueue::getTrack 0 Feb 08 04:45:36 volumio volumio[13879]: info: CoreCommandRouter::volumioPushState Feb 08 04:45:36 volumio volumio[13879]: info: Completed loading Core Plugins Feb 08 04:45:36 volumio volumio[13879]: info: Preparing to generate the ALSA configuration file Feb 08 04:45:36 volumio sudo[14093]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 08 04:45:36 volumio sudo[14093]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:36 volumio volumio[13879]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Feb 08 04:45:36 volumio volumio[13879]: info: Discovery: Found device Volumio Feb 08 04:45:36 volumio volumio[13879]: info: CoreCommandRouter::volumioGetState Feb 08 04:45:36 volumio volumio[13879]: info: CorePlayQueue::getTrack 0 Feb 08 04:45:36 volumio sudo[14093]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:36 volumio volumio[13879]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Feb 08 04:45:36 volumio volumio[13879]: info: Reading ALSA contributions from plugins. Feb 08 04:45:36 volumio volumio[13879]: info: Upmpdcli Daemon Started Feb 08 04:45:36 volumio volumio[13879]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Feb 08 04:45:36 volumio volumio[13879]: info: Discovery: Found device Volumio Feb 08 04:45:36 volumio volumio[13879]: info: CoreCommandRouter::volumioGetState Feb 08 04:45:36 volumio volumio[13879]: info: CorePlayQueue::getTrack 0 Feb 08 04:45:36 volumio volumio[13879]: info: Asound.conf file unchanged, so no further update is needed Feb 08 04:45:36 volumio volumio[13879]: info: Output device has changed, restarting MPD Feb 08 04:45:36 volumio volumio[13879]: info: Output device has changed, restarting Shairport Sync Feb 08 04:45:36 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:36 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 04:45:36 volumio sudo[14096]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 08 04:45:36 volumio sudo[14096]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:36 volumio sudo[14098]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 08 04:45:36 volumio sudo[14098]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:36 volumio sudo[14096]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:36 volumio volumio[13879]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 04:45:36 volumio volumio[13879]: info: ___________ START PLUGINS ___________ Feb 08 04:45:36 volumio volumio[13879]: info: ControllerMpd::onStart: Initializing MPD Feb 08 04:45:36 volumio volumio[13879]: info: Creating MPD Configuration file Feb 08 04:45:36 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 04:45:36 volumio volumio[13879]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 04:45:36 volumio volumio[13879]: info: [1770547536282] CoreMusicLibrary::Adding element Media Servers Feb 08 04:45:36 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 04:45:36 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 08 04:45:36 volumio sudo[14107]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 08 04:45:36 volumio sudo[14107]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:36 volumio sudo[14107]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:36 volumio sudo[14109]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 08 04:45:36 volumio sudo[14109]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:36 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:36 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 04:45:36 volumio volumio[13879]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 04:45:36 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:36 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 04:45:36 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 08 04:45:36 volumio volumio[13879]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 04:45:36 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 08 04:45:36 volumio volumio[13879]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 04:45:36 volumio volumio[13879]: info: [1770547536405] CoreMusicLibrary::Adding element Last_100 Feb 08 04:45:36 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 04:45:36 volumio systemd[1]: mpd.service: Consumed 3.786s CPU time. Feb 08 04:45:36 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 08 04:45:36 volumio volumio[13879]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 04:45:36 volumio volumio[13879]: info: [1770547536411] CoreMusicLibrary::Adding element Webradio Feb 08 04:45:36 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 04:45:36 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 08 04:45:36 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 08 04:45:36 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 04:45:36 volumio volumio[13879]: info: Initializing BBC Radios Feb 08 04:45:36 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 08 04:45:36 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 08 04:45:36 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 04:45:36 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 04:45:36 volumio volumio[13879]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 04:45:36 volumio volumio[13879]: info: [1770547536503] CoreMusicLibrary::Adding element Bandcamp Discover Feb 08 04:45:36 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 04:45:36 volumio volumio[13879]: Cannot find translation for source Bandcamp Discover Feb 08 04:45:36 volumio volumio[13879]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 04:45:36 volumio volumio[13879]: info: [1770547536515] CoreMusicLibrary::Adding element SoundCloud Feb 08 04:45:36 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 04:45:36 volumio volumio[13879]: Cannot find translation for source Bandcamp Discover Feb 08 04:45:36 volumio volumio[13879]: Cannot find translation for source SoundCloud Feb 08 04:45:36 volumio volumio[13879]: info: Creating Spotify config file Feb 08 04:45:36 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:36 volumio sudo[14131]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 08 04:45:36 volumio sudo[14131]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 08 04:45:36 volumio sudo[14131]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:36 volumio volumio[13879]: info: [squeezelite_mc] Starting proxy server... Feb 08 04:45:36 volumio volumio[13879]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 04:45:36 volumio volumio[13879]: info: [1770547536872] CoreMusicLibrary::Adding element YouTube2 Feb 08 04:45:36 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 04:45:36 volumio volumio[13879]: Cannot find translation for source Bandcamp Discover Feb 08 04:45:36 volumio volumio[13879]: Cannot find translation for source SoundCloud Feb 08 04:45:36 volumio volumio[13879]: Cannot find translation for source YouTube2 Feb 08 04:45:36 volumio volumio[13879]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 04:45:36 volumio volumio[13879]: info: [1770547536891] CoreMusicLibrary::Adding element YouTube Music Feb 08 04:45:36 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 04:45:36 volumio volumio[13879]: Cannot find translation for source Bandcamp Discover Feb 08 04:45:36 volumio volumio[13879]: Cannot find translation for source SoundCloud Feb 08 04:45:36 volumio volumio[13879]: Cannot find translation for source YouTube2 Feb 08 04:45:36 volumio volumio[13879]: Cannot find translation for source YouTube Music Feb 08 04:45:36 volumio volumio[13879]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 04:45:36 volumio volumio[13879]: info: [1770547536903] CoreMusicLibrary::Adding element Podcast Feb 08 04:45:36 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 04:45:36 volumio volumio[13879]: Cannot find translation for source Bandcamp Discover Feb 08 04:45:36 volumio volumio[13879]: Cannot find translation for source SoundCloud Feb 08 04:45:36 volumio volumio[13879]: Cannot find translation for source YouTube2 Feb 08 04:45:36 volumio volumio[13879]: Cannot find translation for source YouTube Music Feb 08 04:45:36 volumio volumio[13879]: Cannot find translation for source Podcast Feb 08 04:45:36 volumio volumio[13879]: info: Loading i18n strings for locale en Feb 08 04:45:36 volumio volumio[13879]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Feb 08 04:45:36 volumio volumio[13879]: Updating browse sources language Feb 08 04:45:36 volumio volumio[13879]: Cannot find translation for source Bandcamp Discover Feb 08 04:45:36 volumio volumio[13879]: Cannot find translation for source SoundCloud Feb 08 04:45:36 volumio volumio[13879]: Cannot find translation for source YouTube2 Feb 08 04:45:36 volumio volumio[13879]: Cannot find translation for source YouTube Music Feb 08 04:45:36 volumio volumio[13879]: Cannot find translation for source Podcast Feb 08 04:45:36 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 04:45:36 volumio volumio[13879]: Cannot find translation for source Bandcamp Discover Feb 08 04:45:36 volumio volumio[13879]: Cannot find translation for source SoundCloud Feb 08 04:45:36 volumio volumio[13879]: Cannot find translation for source YouTube2 Feb 08 04:45:36 volumio volumio[13879]: Cannot find translation for source YouTube Music Feb 08 04:45:36 volumio volumio[13879]: Cannot find translation for source Podcast Feb 08 04:45:36 volumio volumio[13879]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 04:45:36 volumio volumio[13879]: info: [1770547536960] CoreMusicLibrary::Adding element Volusonic Feb 08 04:45:36 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 04:45:36 volumio volumio[13879]: Cannot find translation for source Bandcamp Discover Feb 08 04:45:36 volumio volumio[13879]: Cannot find translation for source SoundCloud Feb 08 04:45:36 volumio volumio[13879]: Cannot find translation for source YouTube2 Feb 08 04:45:36 volumio volumio[13879]: Cannot find translation for source YouTube Music Feb 08 04:45:36 volumio volumio[13879]: Cannot find translation for source Podcast Feb 08 04:45:36 volumio volumio[13879]: Cannot find translation for source Volusonic Feb 08 04:45:36 volumio volumio[13879]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Feb 08 04:45:37 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Feb 08 04:45:37 volumio volumio[13879]: info: Volumio Calling Home Feb 08 04:45:37 volumio volumio[13879]: info: [squeezelite_mc] Proxy server started on port 45665 Feb 08 04:45:37 volumio volumio[13879]: info: Preparing to generate the ALSA configuration file Feb 08 04:45:37 volumio volumio[13879]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 04:45:37 volumio volumio[13879]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Feb 08 04:45:37 volumio volumio[13879]: info: Reading ALSA contributions from plugins. Feb 08 04:45:37 volumio volumio[13879]: info: MPD Permissions set Feb 08 04:45:37 volumio volumio[13879]: info: MPD Permissions set Feb 08 04:45:37 volumio volumio[13879]: info: Spotify config file written Feb 08 04:45:37 volumio sudo[14144]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 08 04:45:37 volumio sudo[14144]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:37 volumio volumio[13879]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 08 04:45:37 volumio volumio[13879]: info: VolumeController:: Volume=100 Mute =false Feb 08 04:45:37 volumio volumio[13879]: info: CoreStateMachine::pushState Feb 08 04:45:37 volumio volumio[13879]: info: CorePlayQueue::getTrack 0 Feb 08 04:45:37 volumio volumio[13879]: info: CoreCommandRouter::volumioPushState Feb 08 04:45:37 volumio volumio[13879]: info: [squeezelite_mc] Server discovery started Feb 08 04:45:37 volumio volumio[13879]: info: [squeezelite_mc] Player finder started Feb 08 04:45:37 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:37 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:37 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:37 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 04:45:37 volumio volumio[13879]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Feb 08 04:45:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:45:37 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:37 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:37 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:37 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:37 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:37 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:37 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:37 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:37 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 04:45:37 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:37 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:37 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:37 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:37 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:37 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:37 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:37 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:37 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:37 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 04:45:37 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:37 volumio volumio[13879]: info: No need to fix Spotify hosts Feb 08 04:45:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:45:37 volumio go-librespot[14148]: go-librespot daemon starting... Feb 08 04:45:37 volumio sudo[14144]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:37 volumio go-librespot[14159]: time="2026-02-08T04:45:37-06:00" level=info msg="running go-librespot 0.4.0" Feb 08 04:45:37 volumio go-librespot[14159]: time="2026-02-08T04:45:37-06:00" level=debug msg="app state loaded" Feb 08 04:45:37 volumio go-librespot[14159]: time="2026-02-08T04:45:37-06:00" level=debug msg="stored credentials not found" Feb 08 04:45:37 volumio go-librespot[14159]: time="2026-02-08T04:45:37-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 04:45:37 volumio volumio[13879]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 08 04:45:37 volumio volumio[13879]: info: Volumio called home Feb 08 04:45:37 volumio volumio[13879]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Feb 08 04:45:37 volumio volumio[13879]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Feb 08 04:45:37 volumio volumio[13879]: 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 Feb 08 04:45:37 volumio go-librespot[14159]: time="2026-02-08T04:45: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]" Feb 08 04:45:37 volumio go-librespot[14159]: time="2026-02-08T04:45: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]" Feb 08 04:45:37 volumio go-librespot[14159]: time="2026-02-08T04:45: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]" Feb 08 04:45:37 volumio go-librespot[14159]: time="2026-02-08T04:45:37-06:00" level=info msg="zeroconf server listening on port 37369" Feb 08 04:45:37 volumio volumio[13879]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 08 04:45:37 volumio volumio[13879]: SPOTIFY: BQAbxYRDZ2qyoWawsZrDXl0uu64VUuHVfTzy7wVfbcswbdT6DL72xsbQMq36kNyJIdwmhkwOs9neTwg3Z29aiyW1wa9jojsa4B6zEpiBJzXbqQc_wW3ZZUEZlRJ4eFKVJA78uSEMdhQKKTYpWEeTftJQzYHvxio0wADEmgTlnKuU_MNAyjzva97z38KwaqMsnqzt5saOwK5ejNl7Z8lMPOlRJIupSLzkl7VZ-cc Feb 08 04:45:37 volumio volumio[13879]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 08 04:45:37 volumio volumio[13879]: info: New Spotify access token = BQAbxYRDZ2qyoWawsZrDXl0uu64VUuHVfTzy7wVfbcswbdT6DL72xsbQMq36kNyJIdwmhkwOs9neTwg3Z29aiyW1wa9jojsa4B6zEpiBJzXbqQc_wW3ZZUEZlRJ4eFKVJA78uSEMdhQKKTYpWEeTftJQzYHvxio0wADEmgTlnKuU_MNAyjzva97z38KwaqMsnqzt5saOwK5ejNl7Z8lMPOlRJIupSLzkl7VZ-cc Feb 08 04:45:37 volumio volumio[13879]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 08 04:45:37 volumio sudo[14169]: 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 Feb 08 04:45:37 volumio sudo[14169]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:37 volumio sudo[14169]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:37 volumio volumio[13879]: info: Starting Shairport Sync Feb 08 04:45:37 volumio volumio[13879]: info: Starting Shairport Sync Feb 08 04:45:37 volumio volumio[13879]: info: Starting Shairport Sync Feb 08 04:45:37 volumio sudo[14172]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 04:45:37 volumio sudo[14172]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:37 volumio go-librespot[14159]: time="2026-02-08T04:45:37-06:00" level=debug msg="obtained new client token: AABLIhRcUTBO9SiVllJuzuWmQdu4/rnCQSRtbtZxZiudzlrHGy+ESZ3O7ainzvRGuwvRoFgTMNssbe79O6NQiQiT2N23iksRuqvIkqRlEvGix/LqybpUeOGLd6qjsr19oRGg42D52TE88GUeUQMNi0aTobf4ae3nbPxvg6li4GcNmvfDZMMexmLjbASZscrHEA61nF7BrrfbOOhQW06J2zvsM9iBAEUxgy8Dh//dFvp0unY3uHpU/yImaA==" Feb 08 04:45:37 volumio sudo[14174]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 04:45:37 volumio sudo[14174]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:37 volumio sudo[14177]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 04:45:37 volumio sudo[14177]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:37 volumio go-librespot[14159]: time="2026-02-08T04:45:37-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 08 04:45:38 volumio kernel: hwmon hwmon1: Voltage normalised Feb 08 04:45:38 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 08 04:45:38 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 08 04:45:38 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 04:45:38 volumio systemd[1]: shairport-sync.service: Consumed 2.023s CPU time. Feb 08 04:45:38 volumio go-librespot[14159]: time="2026-02-08T04:45:38-06:00" level=debug msg="completed keyexchange" Feb 08 04:45:38 volumio go-librespot[14159]: time="2026-02-08T04:45:38-06:00" level=debug msg="completed challenge" Feb 08 04:45:38 volumio volumio[13879]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Feb 08 04:45:38 volumio volumio[13879]: info: Asound.conf file unchanged, so no further update is needed Feb 08 04:45:38 volumio volumio[13879]: info: Output device has changed, restarting MPD Feb 08 04:45:38 volumio go-librespot[14159]: time="2026-02-08T04:45:38-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 " Feb 08 04:45:38 volumio volumio[13879]: info: Output device has changed, restarting Shairport Sync Feb 08 04:45:38 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:38 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 04:45:38 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 04:45:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 04:45:38 volumio sudo[14174]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:38 volumio sudo[14172]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 04:45:38 volumio sudo[14184]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Feb 08 04:45:38 volumio sudo[14184]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:38 volumio sudo[14186]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 08 04:45:38 volumio sudo[14186]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:38 volumio sudo[14177]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:38 volumio sudo[14186]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:38 volumio sudo[14188]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 08 04:45:38 volumio sudo[14188]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:38 volumio sudo[14184]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:38 volumio volumio[13879]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 04:45:38 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 08 04:45:38 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 08 04:45:38 volumio systemd[1]: mpd.service: Consumed 1.647s CPU time. Feb 08 04:45:38 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 08 04:45:38 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 08 04:45:38 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 08 04:45:38 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 08 04:45:38 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 08 04:45:38 volumio volumio[13879]: info: MPD Permissions set Feb 08 04:45:38 volumio volumio[13879]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Feb 08 04:45:38 volumio volumio[13879]: info: Shairport-Sync Started Feb 08 04:45:38 volumio volumio[13879]: Error adding Membership: Error: addMembership EINVAL Feb 08 04:45:38 volumio volumio[13879]: info: Shairport-Sync Started Feb 08 04:45:38 volumio volumio[13879]: info: Shairport-Sync Started Feb 08 04:45:38 volumio sudo[14218]: 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 Feb 08 04:45:38 volumio sudo[14218]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:38 volumio sudo[14218]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:38 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:38 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:38 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:38 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:38 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:38 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:38 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:38 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:38 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 04:45:38 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:38 volumio volumio[13879]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Feb 08 04:45:38 volumio volumio[13879]: info: CoreCommandRouter::volumioGetState Feb 08 04:45:38 volumio volumio[13879]: info: CorePlayQueue::getTrack 0 Feb 08 04:45:38 volumio sudo[14226]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Feb 08 04:45:38 volumio sudo[14226]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:38 volumio volumio[13879]: info: Starting Shairport Sync Feb 08 04:45:38 volumio systemd[1]: Reloading. Feb 08 04:45:38 volumio sudo[14215]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 08 04:45:38 volumio sudo[14215]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 08 04:45:38 volumio sudo[14215]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:38 volumio sudo[14229]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 04:45:38 volumio sudo[14229]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:38 volumio volumio[13879]: 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"} Feb 08 04:45:38 volumio volumio[13879]: info: Spotify Successfully logged in Feb 08 04:45:38 volumio volumio[13879]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 04:45:38 volumio volumio[13879]: info: [1770547538988] CoreMusicLibrary::Adding element Spotify Feb 08 04:45:38 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 04:45:38 volumio volumio[13879]: Cannot find translation for source Bandcamp Discover Feb 08 04:45:38 volumio volumio[13879]: Cannot find translation for source SoundCloud Feb 08 04:45:38 volumio volumio[13879]: Cannot find translation for source YouTube2 Feb 08 04:45:38 volumio volumio[13879]: Cannot find translation for source YouTube Music Feb 08 04:45:39 volumio volumio[13879]: Cannot find translation for source Podcast Feb 08 04:45:39 volumio volumio[13879]: Cannot find translation for source Volusonic Feb 08 04:45:39 volumio volumio[13879]: Cannot find translation for source Spotify Feb 08 04:45:39 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:39 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:39 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:45:39 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 04:45:40 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 08 04:45:40 volumio volumio[13879]: info: go-librespot daemon successfully initialized Feb 08 04:45:41 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. Feb 08 04:45:41 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. Feb 08 04:45:41 volumio sudo[14226]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:41 volumio volumio[13879]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 08 04:45:41 volumio sudo[14265]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 08 04:45:41 volumio sudo[14265]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 37. Feb 08 04:45:42 volumio sudo[14265]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:42 volumio volumio[13879]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Feb 08 04:45:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:45:42 volumio sudo[14269]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Feb 08 04:45:42 volumio sudo[14269]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:45:42 volumio go-librespot[14268]: go-librespot daemon starting... Feb 08 04:45:42 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 08 04:45:42 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 08 04:45:42 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 04:45:42 volumio systemd[1]: shairport-sync.service: Consumed 1.499s CPU time. Feb 08 04:45:42 volumio go-librespot[14271]: time="2026-02-08T04:45:42-06:00" level=info msg="running go-librespot 0.4.0" Feb 08 04:45:42 volumio go-librespot[14271]: time="2026-02-08T04:45:42-06:00" level=debug msg="app state loaded" Feb 08 04:45:42 volumio go-librespot[14271]: time="2026-02-08T04:45:42-06:00" level=debug msg="stored credentials not found" Feb 08 04:45:42 volumio go-librespot[14271]: time="2026-02-08T04:45:42-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 04:45:42 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 04:45:42 volumio sudo[14229]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:42 volumio volumio[13879]: info: Shairport-Sync Started Feb 08 04:45:42 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Feb 08 04:45:42 volumio systemd[1]: squeezelite.service: Deactivated successfully. Feb 08 04:45:42 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Feb 08 04:45:42 volumio sudo[14269]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:42 volumio go-librespot[14271]: time="2026-02-08T04:45:42-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]" Feb 08 04:45:42 volumio go-librespot[14271]: time="2026-02-08T04:45:42-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]" Feb 08 04:45:42 volumio go-librespot[14271]: time="2026-02-08T04:45:42-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]" Feb 08 04:45:42 volumio go-librespot[14271]: time="2026-02-08T04:45:42-06:00" level=info msg="zeroconf server listening on port 38775" Feb 08 04:45:42 volumio go-librespot[14271]: time="2026-02-08T04:45:42-06:00" level=debug msg="obtained new client token: AABgyE2ktVVTAMF6gtFDab+p0r3jMdNp4jEhNmFF9Mbfsoo+cR+Jlg4cquCCG2P2fYYpLoPwrGUbzSp6FEpg1lcZrJXVLDX4Ql0en0OCm/KpT4jd9xHpNC3F67Y1d/nx4WyzLdLWesqkIv05JIMH8koX3VNw+7SjWVdkWJOqyr8J57pHphJjCIG27FoDkIG+3hIHyIWd8OLPaYkdOgyzdMobYGC+jSzOrAwnd6r7Beri314bq2I52gYFDg==" Feb 08 04:45:42 volumio go-librespot[14271]: time="2026-02-08T04:45:42-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 08 04:45:42 volumio go-librespot[14271]: time="2026-02-08T04:45:42-06:00" level=debug msg="completed keyexchange" Feb 08 04:45:42 volumio go-librespot[14271]: time="2026-02-08T04:45:42-06:00" level=debug msg="completed challenge" Feb 08 04:45:42 volumio go-librespot[14271]: time="2026-02-08T04:45:42-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 " Feb 08 04:45:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 04:45:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 04:45:42 volumio volumio[13879]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 08 04:45:43 volumio sudo[14295]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 08 04:45:43 volumio sudo[14295]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:43 volumio sudo[14295]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:43 volumio volumio[13879]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Feb 08 04:45:43 volumio sudo[14299]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Feb 08 04:45:43 volumio sudo[14299]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:43 volumio sudo[14299]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:43 volumio volumio[13879]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Feb 08 04:45:43 volumio sudo[14302]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Feb 08 04:45:43 volumio sudo[14302]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:43 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Feb 08 04:45:43 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Feb 08 04:45:43 volumio sudo[14302]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:43 volumio volumio[13879]: info: Initializing connection to go-librespot Websocket Feb 08 04:45:43 volumio volumio[13879]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 04:45:43 volumio volumio[13879]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 08 04:45:43 volumio sudo[14309]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 08 04:45:43 volumio sudo[14309]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:43 volumio sudo[14309]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:44 volumio kernel: hwmon hwmon1: Voltage normalised Feb 08 04:45:44 volumio volumio[13879]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 08 04:45:44 volumio sudo[14313]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 08 04:45:44 volumio sudo[14313]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:44 volumio sudo[14313]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:45 volumio mpd[14263]: 2026-02-08T04:45:45 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 08 04:45:45 volumio volumio[13879]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 08 04:45:45 volumio sudo[14316]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 08 04:45:45 volumio sudo[14316]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:45 volumio sudo[14316]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:45 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 08 04:45:45 volumio sudo[14188]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:45 volumio sudo[14098]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:45 volumio sudo[14109]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:45 volumio volumio[13879]: error: MPD error: The expression evaluated to a falsy value: Feb 08 04:45:45 volumio volumio[13879]: assert.ok(self.idling) Feb 08 04:45:45 volumio volumio[13879]: error: The expression evaluated to a falsy value: Feb 08 04:45:45 volumio volumio[13879]: assert.ok(self.idling) Feb 08 04:45:45 volumio volumio[13879]: error: MPD error: The expression evaluated to a falsy value: Feb 08 04:45:45 volumio volumio[13879]: assert.ok(self.idling) Feb 08 04:45:45 volumio volumio[13879]: error: The expression evaluated to a falsy value: Feb 08 04:45:45 volumio volumio[13879]: assert.ok(self.idling) Feb 08 04:45:45 volumio volumio[13879]: info: MPD running with PID14263 Feb 08 04:45:45 volumio volumio[13879]: ,establishing connection Feb 08 04:45:45 volumio volumio[13879]: error: updateQueue error: null Feb 08 04:45:45 volumio volumio[13879]: error: updateQueue error: null Feb 08 04:45:45 volumio volumio[13879]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 08 04:45:45 volumio sudo[14323]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 08 04:45:45 volumio sudo[14323]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:45 volumio sudo[14323]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38. Feb 08 04:45:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:45:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:45:46 volumio go-librespot[14325]: go-librespot daemon starting... Feb 08 04:45:46 volumio go-librespot[14326]: time="2026-02-08T04:45:46-06:00" level=info msg="running go-librespot 0.4.0" Feb 08 04:45:46 volumio go-librespot[14326]: time="2026-02-08T04:45:46-06:00" level=debug msg="app state loaded" Feb 08 04:45:46 volumio go-librespot[14326]: time="2026-02-08T04:45:46-06:00" level=debug msg="stored credentials not found" Feb 08 04:45:46 volumio go-librespot[14326]: time="2026-02-08T04:45:46-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 04:45:46 volumio volumio[13879]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 08 04:45:46 volumio sudo[14334]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 08 04:45:46 volumio sudo[14334]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:46 volumio go-librespot[14326]: time="2026-02-08T04:45:46-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]" Feb 08 04:45:46 volumio go-librespot[14326]: time="2026-02-08T04:45:46-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]" Feb 08 04:45:46 volumio go-librespot[14326]: time="2026-02-08T04:45:46-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]" Feb 08 04:45:46 volumio go-librespot[14326]: time="2026-02-08T04:45:46-06:00" level=info msg="zeroconf server listening on port 41011" Feb 08 04:45:46 volumio sudo[14334]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:46 volumio volumio[13879]: info: Completed starting Core Plugins Feb 08 04:45:46 volumio volumio[13879]: info: ------------------------------------------- Feb 08 04:45:46 volumio volumio[13879]: info: ----- MyVolumio plugins startup ---- Feb 08 04:45:46 volumio volumio[13879]: info: ------------------------------------------- Feb 08 04:45:46 volumio volumio[13879]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 08 04:45:46 volumio go-librespot[14326]: time="2026-02-08T04:45:46-06:00" level=debug msg="obtained new client token: AADpMXEknk37Ir6GXuWi+TanYUu5u6z4Ty9pbZbQPor7StU9vsjjBPJ8FjPCBGUlNhlkt0ztRWcfy812eKw6lX8nBlWMqQFjfLu3fGV1q7fmqPg1anHfjJ3xq54SlNKdpcBaCk3CF264a2eVtN7hRDb1jmVQ0eLfSH0TbW0B7BIBb76YnwHjjJyalikaHvd3NpbgBCw/NJ+iZFowt10Ee14rpf72et/4Ili165Wi8Jh9moyYNUncc47ZqQ==" Feb 08 04:45:46 volumio go-librespot[14326]: time="2026-02-08T04:45:46-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" Feb 08 04:45:46 volumio go-librespot[14326]: time="2026-02-08T04:45:46-06:00" level=debug msg="connected to ap-guc3.spotify.com:443" Feb 08 04:45:46 volumio go-librespot[14326]: time="2026-02-08T04:45:46-06:00" level=debug msg="completed keyexchange" Feb 08 04:45:46 volumio go-librespot[14326]: time="2026-02-08T04:45:46-06:00" level=debug msg="completed challenge" Feb 08 04:45:46 volumio go-librespot[14326]: time="2026-02-08T04:45:46-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 " Feb 08 04:45:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 04:45:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 04:45:46 volumio volumio[13879]: info: Initializing connection to go-librespot Websocket Feb 08 04:45:46 volumio volumio[13879]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 04:45:48 volumio sudo[14338]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 08 04:45:48 volumio sudo[14338]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:48 volumio sudo[14340]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 08 04:45:48 volumio sudo[14340]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:48 volumio sudo[14342]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 08 04:45:48 volumio sudo[14342]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:48 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 08 04:45:48 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 08 04:45:48 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 08 04:45:48 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 08 04:45:48 volumio sudo[14340]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:48 volumio mpd_monitor.sh[14346]: MPD Monitor Service: Starting MPD Monitor Service Feb 08 04:45:48 volumio sudo[14338]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:48 volumio sudo[14342]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:48 volumio volumio[13879]: info: Successfully started MPD Monitor Feb 08 04:45:48 volumio volumio[13879]: info: Successfully started MPD Monitor Feb 08 04:45:48 volumio volumio[13879]: info: Successfully started MPD Monitor Feb 08 04:45:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 39. Feb 08 04:45:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:45:49 volumio volumio[13879]: info: Initializing connection to go-librespot Websocket Feb 08 04:45:49 volumio volumio[13879]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 04:45:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:45:49 volumio go-librespot[14364]: go-librespot daemon starting... Feb 08 04:45:49 volumio go-librespot[14365]: time="2026-02-08T04:45:49-06:00" level=info msg="running go-librespot 0.4.0" Feb 08 04:45:49 volumio go-librespot[14365]: time="2026-02-08T04:45:49-06:00" level=debug msg="app state loaded" Feb 08 04:45:49 volumio go-librespot[14365]: time="2026-02-08T04:45:49-06:00" level=debug msg="stored credentials not found" Feb 08 04:45:49 volumio go-librespot[14365]: time="2026-02-08T04:45:49-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 04:45:50 volumio go-librespot[14365]: time="2026-02-08T04:45:50-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]" Feb 08 04:45:50 volumio go-librespot[14365]: time="2026-02-08T04:45:50-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]" Feb 08 04:45:50 volumio go-librespot[14365]: time="2026-02-08T04:45:50-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]" Feb 08 04:45:50 volumio go-librespot[14365]: time="2026-02-08T04:45:50-06:00" level=info msg="zeroconf server listening on port 46547" Feb 08 04:45:50 volumio go-librespot[14365]: time="2026-02-08T04:45:50-06:00" level=debug msg="obtained new client token: AABTh5euk33UBbCNCZUBmvgqJE0o3VyJdts45v3MwjehK4/49dFzyzaAT7ABy0VHH49FbGBGVlXcevKVJ8slFYAGHewD07dETy0Z4kO8eFPfhOAvcwLRMH1+y2MMTRvPvfyQWgztmYTRagzHKiIeI396++Cugahpuh8fKbaq/t7QIBPf0tVPtAz96xBjMlaGtaSUD20FmD+ryCDC0cEJc/56MWGupZS7M3sOOq+WoLUiZ+paf2vGIEM=" Feb 08 04:45:50 volumio go-librespot[14365]: time="2026-02-08T04:45:50-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 08 04:45:50 volumio go-librespot[14365]: time="2026-02-08T04:45:50-06:00" level=debug msg="completed keyexchange" Feb 08 04:45:50 volumio go-librespot[14365]: time="2026-02-08T04:45:50-06:00" level=debug msg="completed challenge" Feb 08 04:45:50 volumio go-librespot[14365]: time="2026-02-08T04:45:50-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 " Feb 08 04:45:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 04:45:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 04:45:52 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 08 04:45:52 volumio volumio[13879]: info: Initializing connection to go-librespot Websocket Feb 08 04:45:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 40. Feb 08 04:45:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:45:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:45:53 volumio go-librespot[14373]: go-librespot daemon starting... Feb 08 04:45:53 volumio go-librespot[14374]: time="2026-02-08T04:45:53-06:00" level=info msg="running go-librespot 0.4.0" Feb 08 04:45:53 volumio go-librespot[14374]: time="2026-02-08T04:45:53-06:00" level=debug msg="app state loaded" Feb 08 04:45:53 volumio go-librespot[14374]: time="2026-02-08T04:45:53-06:00" level=debug msg="stored credentials not found" Feb 08 04:45:53 volumio go-librespot[14374]: time="2026-02-08T04:45:53-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 04:45:54 volumio go-librespot[14374]: time="2026-02-08T04:45:54-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]" Feb 08 04:45:54 volumio go-librespot[14374]: time="2026-02-08T04:45:54-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]" Feb 08 04:45:54 volumio go-librespot[14374]: time="2026-02-08T04:45:54-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]" Feb 08 04:45:54 volumio go-librespot[14374]: time="2026-02-08T04:45:54-06:00" level=info msg="zeroconf server listening on port 45477" Feb 08 04:45:54 volumio go-librespot[14374]: time="2026-02-08T04:45:54-06:00" level=debug msg="obtained new client token: AADbKNv1ttA6pZanUi7s6GwZpPgWoLOvS1K9Xhp0UrzPyjIaZjGLq6MAUAdZuNx2hlvnv/7lQC8ItKKaQb8K01GPcbwCwoeK2gUV4ll96nQj70GfIuBkguiizDfTfbcoVugLZcwOJBKhLMd/I5OOi1mKjj8vkApMMTboCYocvvCEn63V8CGH/eFYT6Gc7pyRmvY66sB6565PnpDPGd6ZAZtacP+uXqDV4l+3udL+67eiJdPt8BCofQI=" Feb 08 04:45:54 volumio go-librespot[14374]: time="2026-02-08T04:45:54-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 08 04:45:54 volumio go-librespot[14374]: time="2026-02-08T04:45:54-06:00" level=debug msg="completed keyexchange" Feb 08 04:45:54 volumio go-librespot[14374]: time="2026-02-08T04:45:54-06:00" level=debug msg="completed challenge" Feb 08 04:45:54 volumio go-librespot[14374]: time="2026-02-08T04:45:54-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 " Feb 08 04:45:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 04:45:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 04:45:54 volumio volumio[13879]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 04:45:55 volumio volumio[13879]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 08 04:45:55 volumio volumio[13879]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 08 04:45:55 volumio volumio[13879]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 08 04:45:55 volumio volumio[13879]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 08 04:45:55 volumio volumio[13879]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 08 04:45:55 volumio volumio[13879]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 08 04:45:55 volumio volumio[13879]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 08 04:45:55 volumio volumio[13879]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 08 04:45:55 volumio volumio[13879]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 08 04:45:55 volumio volumio[13879]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 08 04:45:55 volumio volumio[13879]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 08 04:45:55 volumio volumio[13879]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 08 04:45:55 volumio volumio[13879]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 08 04:45:55 volumio volumio[13879]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 08 04:45:55 volumio volumio[13879]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 08 04:45:55 volumio volumio[13879]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 08 04:45:55 volumio volumio[13879]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 08 04:45:55 volumio volumio[13879]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 08 04:45:55 volumio volumio[13879]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 08 04:45:55 volumio volumio[13879]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 08 04:45:55 volumio volumio[13879]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 08 04:45:55 volumio volumio[13879]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 08 04:45:55 volumio volumio[13879]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 08 04:45:55 volumio volumio[13879]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 08 04:45:55 volumio volumio[13879]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 08 04:45:55 volumio volumio[13879]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 08 04:45:55 volumio volumio[13879]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 08 04:45:55 volumio volumio[13879]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 08 04:45:55 volumio volumio[13879]: info: Adding plugin bluetooth to MyMusic Plugins Feb 08 04:45:55 volumio volumio[13879]: info: Adding plugin multiroom to MyMusic Plugins Feb 08 04:45:55 volumio volumio[13879]: info: Adding plugin metavolumio to MyMusic Plugins Feb 08 04:45:55 volumio volumio[13879]: info: Adding plugin cd_controller to MyMusic Plugins Feb 08 04:45:55 volumio volumio[13879]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 08 04:45:55 volumio volumio[13879]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 08 04:45:55 volumio volumio[13879]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 08 04:45:55 volumio volumio[13879]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 08 04:45:55 volumio volumio[13879]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 08 04:45:55 volumio volumio[13879]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 08 04:45:55 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 04:45:55 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 04:45:56 volumio volumio[13879]: info: Starting MyVolumio Remote Streaming Endpoints Feb 08 04:45:56 volumio volumio[13879]: info: MyVolumio login type: Token Feb 08 04:45:56 volumio volumio[13879]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 08 04:45:56 volumio volumio[13879]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 08 04:45:56 volumio kernel: hwmon hwmon1: Voltage normalised Feb 08 04:45:56 volumio volumio[13879]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 08 04:45:56 volumio volumio[13879]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 08 04:45:56 volumio volumio[13879]: info: Streaming services startup Feb 08 04:45:56 volumio volumio[13879]: info: Starting Streaming Daemon Feb 08 04:45:56 volumio sudo[14385]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 08 04:45:56 volumio sudo[14385]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:56 volumio volumio[13879]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 08 04:45:56 volumio sudo[14385]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:57 volumio volumio[13879]: error: Cannot start Volumio Streaming Daemon Feb 08 04:45:57 volumio volumio[13879]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 08 04:45:57 volumio volumio[13879]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 08 04:45:57 volumio volumio[13879]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 08 04:45:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 41. Feb 08 04:45:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:45:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:45:57 volumio go-librespot[14392]: go-librespot daemon starting... Feb 08 04:45:57 volumio go-librespot[14393]: time="2026-02-08T04:45:57-06:00" level=info msg="running go-librespot 0.4.0" Feb 08 04:45:57 volumio go-librespot[14393]: time="2026-02-08T04:45:57-06:00" level=debug msg="app state loaded" Feb 08 04:45:57 volumio go-librespot[14393]: time="2026-02-08T04:45:57-06:00" level=debug msg="stored credentials not found" Feb 08 04:45:57 volumio go-librespot[14393]: time="2026-02-08T04:45:57-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 04:45:57 volumio volumio[13879]: info: MyVolumio token set successfully Feb 08 04:45:57 volumio volumio[13879]: info: MYVOLUMIO: Adding device Feb 08 04:45:57 volumio volumio[13879]: info: MYVOLUMIO: Evaluating Server Feb 08 04:45:57 volumio go-librespot[14393]: time="2026-02-08T04:45:57-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]" Feb 08 04:45:57 volumio go-librespot[14393]: time="2026-02-08T04:45:57-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]" Feb 08 04:45:57 volumio go-librespot[14393]: time="2026-02-08T04:45:57-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]" Feb 08 04:45:57 volumio go-librespot[14393]: time="2026-02-08T04:45:57-06:00" level=info msg="zeroconf server listening on port 45813" Feb 08 04:45:57 volumio go-librespot[14393]: time="2026-02-08T04:45:57-06:00" level=debug msg="obtained new client token: AADHaEsI0/9tHZwWVRXU5q4rwTroRw8e1X5Z9V4ykNyvoFp9cjmBey8XlxBhuoAIayaRVd5GLWXFvi+n9+rtBWmybLaEMe2Q0t9zBZUq/gAYUfs7rhTXK3HCZlvWY2Ratv5cPFXq4ubZ8XnlGEBf7NRH35Nn5EsJ93Zb599F4aO9sspglbV3ANvqSZrXAzsSwsixUtNBcN5GS7tcxPad+TJ+aqHzOXon79l27/0EnEQZrXWWBCRSaRQ1nA==" Feb 08 04:45:57 volumio volumio[13879]: info: Initializing connection to go-librespot Websocket Feb 08 04:45:57 volumio volumio[13879]: info: MyVolumio status changed Feb 08 04:45:57 volumio volumio[13879]: info: Streaming services startup Feb 08 04:45:58 volumio volumio[13879]: info: Starting Streaming Daemon Feb 08 04:45:58 volumio go-librespot[14393]: time="2026-02-08T04:45:58-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 08 04:45:58 volumio volumio[13879]: info: Removing browser output: myVolumio user plan is not superstar Feb 08 04:45:58 volumio volumio[13879]: info: Removing audio output: Feb 08 04:45:58 volumio volumio[13879]: info: Stoppping Tunnel 1 Feb 08 04:45:58 volumio sudo[14421]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 08 04:45:58 volumio sudo[14421]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:58 volumio go-librespot[14393]: time="2026-02-08T04:45:58-06:00" level=debug msg="completed keyexchange" Feb 08 04:45:58 volumio go-librespot[14393]: time="2026-02-08T04:45:58-06:00" level=debug msg="completed challenge" Feb 08 04:45:58 volumio sudo[14423]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 08 04:45:58 volumio sudo[14423]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:45:58 volumio go-librespot[14393]: time="2026-02-08T04:45:58-06:00" level=debug msg="new websocket client" Feb 08 04:45:58 volumio volumio[13879]: info: Connection to go-librespot Websocket established Feb 08 04:45:58 volumio go-librespot[14393]: time="2026-02-08T04:45:58-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 " Feb 08 04:45:58 volumio volumio[13879]: info: Connection to go-librespot Websocket closed Feb 08 04:45:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 04:45:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 04:45:58 volumio sudo[14421]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:58 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 08 04:45:58 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 08 04:45:58 volumio volumio[13879]: error: Cannot start Volumio Streaming Daemon Feb 08 04:45:58 volumio volumio[13879]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 08 04:45:58 volumio volumio[13879]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 08 04:45:58 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 08 04:45:58 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 08 04:45:58 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 08 04:45:58 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 08 04:45:58 volumio sudo[14423]: pam_unix(sudo:session): session closed for user root Feb 08 04:45:58 volumio volumio[13879]: info: Remote SSH Stopped Feb 08 04:45:58 volumio volumio[13879]: info: Setting Geolocation for MyVolumio to us1 Feb 08 04:45:58 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 04:45:58 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 04:45:58 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 04:45:58 volumio volumio[13879]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 08 04:45:59 volumio volumio[13879]: info: Updating MyVolumio device info Feb 08 04:45:59 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 04:45:59 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 04:45:59 volumio volumio[13879]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 04:45:59 volumio volumio[13879]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 08 04:46:01 volumio volumio[13879]: info: Getting Spotify volume Feb 08 04:46:01 volumio volumio[13879]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 08 04:46:01 volumio volumio[13879]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 04:46:01 volumio volumio[13879]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 08 04:46:01 volumio volumio[13879]: errno: -111, Feb 08 04:46:01 volumio volumio[13879]: code: 'ECONNREFUSED', Feb 08 04:46:01 volumio volumio[13879]: syscall: 'connect', Feb 08 04:46:01 volumio volumio[13879]: address: '127.0.0.1', Feb 08 04:46:01 volumio volumio[13879]: port: 9879, Feb 08 04:46:01 volumio volumio[13879]: response: undefined Feb 08 04:46:01 volumio volumio[13879]: } Feb 08 04:46:01 volumio volumio[13879]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 08 04:46:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 42. Feb 08 04:46:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:46:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:46:01 volumio go-librespot[14452]: go-librespot daemon starting... Feb 08 04:46:01 volumio go-librespot[14453]: time="2026-02-08T04:46:01-06:00" level=info msg="running go-librespot 0.4.0" Feb 08 04:46:01 volumio go-librespot[14453]: time="2026-02-08T04:46:01-06:00" level=debug msg="app state loaded" Feb 08 04:46:01 volumio go-librespot[14453]: time="2026-02-08T04:46:01-06:00" level=debug msg="stored credentials not found" Feb 08 04:46:01 volumio go-librespot[14453]: time="2026-02-08T04:46:01-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 04:46:01 volumio go-librespot[14453]: time="2026-02-08T04:46:01-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]" Feb 08 04:46:01 volumio go-librespot[14453]: time="2026-02-08T04:46:01-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]" Feb 08 04:46:01 volumio go-librespot[14453]: time="2026-02-08T04:46:01-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]" Feb 08 04:46:01 volumio go-librespot[14453]: time="2026-02-08T04:46:01-06:00" level=info msg="zeroconf server listening on port 45259" Feb 08 04:46:01 volumio go-librespot[14453]: time="2026-02-08T04:46:01-06:00" level=debug msg="obtained new client token: AACx90x4GpzdJ7WQi2WVdSclzboV0H9dGiGuXK6V7Os58ou6fgAlXlQrALNOS/nqIZt8Pl50QS22wpH7IPkpaDJ+D4P6feqWdESNMT69ONJuYyVkskhkzp8fmMwbAcyth+HldOF/lwxx7AVN3JjigLMdoLx/hB0fx4Fj6HndD40Zl2HO8KI1MrzWn0QPj9ZA7puB0ZQkEff7ni/MFujYyfHOgLV//F8Mkeigpe5A//R10Q8RcZJv3Y+Dpw==" Feb 08 04:46:01 volumio go-librespot[14453]: time="2026-02-08T04:46:01-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 08 04:46:01 volumio go-librespot[14453]: time="2026-02-08T04:46:01-06:00" level=debug msg="completed keyexchange" Feb 08 04:46:01 volumio go-librespot[14453]: time="2026-02-08T04:46:01-06:00" level=debug msg="completed challenge" Feb 08 04:46:01 volumio go-librespot[14453]: time="2026-02-08T04:46: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 " Feb 08 04:46:01 volumio sudo[14463]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-08 04:45' Feb 08 04:46:01 volumio sudo[14463]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:46:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 04:46:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 04:46:02 volumio sudo[14463]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:02 volumio volumio-remote-updater[751]: [2026-02-08 04:46:02] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 08 04:46:02 volumio volumio-remote-updater[751]: [2026-02-08 04:46:02] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 08 04:46:02 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 08 04:46:02 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 08 04:46:02 volumio systemd[1]: volumio.service: Consumed 56.490s CPU time. Feb 08 04:46:02 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 08 04:46:02 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 08 04:46:02 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 698. Feb 08 04:46:02 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 08 04:46:02 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 08 04:46:02 volumio systemd[1]: volumio.service: Consumed 56.490s CPU time. Feb 08 04:46:02 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 08 04:46:02 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 08 04:46:04 volumio volumio[14476]: info: ------------------------------------------- Feb 08 04:46:04 volumio volumio[14476]: info: ----- Volumio3 ---- Feb 08 04:46:04 volumio volumio[14476]: info: ------------------------------------------- Feb 08 04:46:04 volumio volumio[14476]: info: ----- System startup ---- Feb 08 04:46:04 volumio volumio[14476]: info: ------------------------------------------- Feb 08 04:46:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 43. Feb 08 04:46:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:46:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:46:05 volumio go-librespot[14497]: go-librespot daemon starting... Feb 08 04:46:05 volumio go-librespot[14498]: time="2026-02-08T04:46:05-06:00" level=info msg="running go-librespot 0.4.0" Feb 08 04:46:05 volumio go-librespot[14498]: time="2026-02-08T04:46:05-06:00" level=debug msg="app state loaded" Feb 08 04:46:05 volumio go-librespot[14498]: time="2026-02-08T04:46:05-06:00" level=debug msg="stored credentials not found" Feb 08 04:46:05 volumio go-librespot[14498]: time="2026-02-08T04:46:05-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 04:46:05 volumio volumio[14476]: info: MYVOLUMIO Environment detected Feb 08 04:46:05 volumio go-librespot[14498]: time="2026-02-08T04:46: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]" Feb 08 04:46:05 volumio go-librespot[14498]: time="2026-02-08T04:46: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]" Feb 08 04:46:05 volumio go-librespot[14498]: time="2026-02-08T04:46: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]" Feb 08 04:46:05 volumio go-librespot[14498]: time="2026-02-08T04:46:05-06:00" level=info msg="zeroconf server listening on port 36639" Feb 08 04:46:05 volumio volumio[14476]: info: Plugin folders cleanup Feb 08 04:46:05 volumio volumio[14476]: info: Scanning into folder /volumio/app/plugins/ Feb 08 04:46:05 volumio volumio[14476]: info: Scanning category audio_interface Feb 08 04:46:05 volumio volumio[14476]: info: Scanning category miscellanea Feb 08 04:46:05 volumio volumio[14476]: info: Scanning category music_service Feb 08 04:46:05 volumio volumio[14476]: info: Scanning category plugins.json Feb 08 04:46:05 volumio volumio[14476]: info: Scanning category system_controller Feb 08 04:46:05 volumio volumio[14476]: info: Scanning category user_interface Feb 08 04:46:05 volumio volumio[14476]: info: Scanning into folder /data/plugins/ Feb 08 04:46:05 volumio volumio[14476]: info: Scanning category audio_interface Feb 08 04:46:05 volumio volumio[14476]: info: Scanning category music_service Feb 08 04:46:05 volumio volumio[14476]: info: Scanning category system_controller Feb 08 04:46:05 volumio volumio[14476]: info: Scanning category system_hardware Feb 08 04:46:05 volumio volumio[14476]: info: Scanning category user_interface Feb 08 04:46:05 volumio volumio[14476]: info: Plugin folders cleanup completed Feb 08 04:46:05 volumio volumio[14476]: info: ------------------------------------------- Feb 08 04:46:05 volumio volumio[14476]: info: ----- Core plugins startup ---- Feb 08 04:46:05 volumio volumio[14476]: info: ------------------------------------------- Feb 08 04:46:05 volumio go-librespot[14498]: time="2026-02-08T04:46:05-06:00" level=debug msg="obtained new client token: AABy4Wn8bEyfrLgG3yXoKOeqnMzbVolv/dP6JUjK1Sprs7MCG3uxrJGSJBdDQmoNTKqefjUGgAO204uHz/OInzjq75O2gYkZwu18/CmNH7fnBIi0X1bDHM1ZwM3EMp0hl3TPItRUd2zLqIvag7wjpCPYUsPA8sInjhEug5eoc8/CwKCYAeFn3BcOUNcyEVrpZBitejQ8Zo2XVPzLinq2rBt/tJ0S/Cu0GjMs7sWPKT/nycLMOqHv07NU8w==" Feb 08 04:46:05 volumio volumio[14476]: info: Loading plugins from folder /volumio/app/plugins/ Feb 08 04:46:05 volumio volumio[14476]: info: Adding plugin upnp to MyMusic Plugins Feb 08 04:46:05 volumio volumio[14476]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 08 04:46:05 volumio volumio[14476]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 08 04:46:05 volumio volumio[14476]: info: Loading plugins from folder /data/plugins/ Feb 08 04:46:05 volumio volumio[14476]: info: Loading plugin "system"... Feb 08 04:46:05 volumio go-librespot[14498]: time="2026-02-08T04:46:05-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 08 04:46:05 volumio volumio[14476]: info: Loading plugin "appearance"... Feb 08 04:46:05 volumio go-librespot[14498]: time="2026-02-08T04:46:05-06:00" level=debug msg="completed keyexchange" Feb 08 04:46:05 volumio go-librespot[14498]: time="2026-02-08T04:46:05-06:00" level=debug msg="completed challenge" Feb 08 04:46:05 volumio go-librespot[14498]: time="2026-02-08T04:46:05-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 " Feb 08 04:46:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 04:46:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 04:46:06 volumio volumio[14476]: info: Loading plugin "network"... Feb 08 04:46:06 volumio volumio[14476]: info: Refreshing Cached IP Addresses Feb 08 04:46:06 volumio sudo[14512]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 08 04:46:06 volumio sudo[14512]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:46:06 volumio sudo[14512]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:06 volumio volumio[14476]: info: Loading plugin "services"... Feb 08 04:46:06 volumio sudo[14514]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 08 04:46:06 volumio sudo[14514]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:46:06 volumio volumio[14476]: info: Loading plugin "alsa_controller"... Feb 08 04:46:06 volumio sudo[14514]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:06 volumio sudo[14522]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 08 04:46:06 volumio sudo[14522]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:46:06 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 04:46:06 volumio volumio[14476]: info: Loading plugin "wizard"... Feb 08 04:46:06 volumio volumio[14476]: info: Loading plugin "networkfs"... Feb 08 04:46:06 volumio volumio[14476]: info: Starting Udev Watcher for removable devices Feb 08 04:46:06 volumio volumio[14476]: info: Ignoring mount for partition: boot Feb 08 04:46:06 volumio volumio[14476]: info: Ignoring mount for partition: volumio Feb 08 04:46:06 volumio volumio[14476]: info: Ignoring mount for partition: volumio_data Feb 08 04:46:06 volumio volumio[14476]: info: Mounting Device Wikipedia Feb 08 04:46:06 volumio sudo[14551]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime Feb 08 04:46:06 volumio sudo[14551]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:46:06 volumio sudo[14551]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:06 volumio volumio[14476]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Feb 08 04:46:06 volumio volumio[14476]: dmesg(1) may have more information after failed mount system call. Feb 08 04:46:06 volumio volumio[14476]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime Feb 08 04:46:06 volumio volumio[14476]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Feb 08 04:46:06 volumio volumio[14476]: dmesg(1) may have more information after failed mount system call. Feb 08 04:46:06 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 04:46:06 volumio volumio[14476]: info: Loading plugin "volumio_command_line_client"... Feb 08 04:46:07 volumio volumio[14476]: info: Loading plugin "upnp"... Feb 08 04:46:07 volumio volumio[14476]: info: [1770547567013] Starting Upmpd Daemon Feb 08 04:46:07 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 04:46:07 volumio volumio[14476]: info: Loading plugin "my_music"... Feb 08 04:46:07 volumio volumio[14476]: info: Loading plugin "mpd"... Feb 08 04:46:07 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 08 04:46:07 volumio volumio-remote-updater[751]: [2026-02-08 04:46:07] [connect] Successful connection Feb 08 04:46:07 volumio sudo[14522]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:07 volumio volumio[14476]: info: Loading plugin "upnp_browser"... Feb 08 04:46:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 44. Feb 08 04:46:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:46:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:46:08 volumio go-librespot[14557]: go-librespot daemon starting... Feb 08 04:46:08 volumio go-librespot[14558]: time="2026-02-08T04:46:08-06:00" level=info msg="running go-librespot 0.4.0" Feb 08 04:46:08 volumio go-librespot[14558]: time="2026-02-08T04:46:08-06:00" level=debug msg="app state loaded" Feb 08 04:46:08 volumio go-librespot[14558]: time="2026-02-08T04:46:08-06:00" level=debug msg="stored credentials not found" Feb 08 04:46:08 volumio go-librespot[14558]: time="2026-02-08T04:46:08-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 04:46:09 volumio go-librespot[14558]: time="2026-02-08T04:46: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 04:46:09 volumio go-librespot[14558]: time="2026-02-08T04:46:09-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]" Feb 08 04:46:09 volumio go-librespot[14558]: time="2026-02-08T04:46:09-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]" Feb 08 04:46:09 volumio go-librespot[14558]: time="2026-02-08T04:46:09-06:00" level=info msg="zeroconf server listening on port 34251" Feb 08 04:46:09 volumio go-librespot[14558]: time="2026-02-08T04:46:09-06:00" level=debug msg="obtained new client token: AACkuCdan4KN2dbuCeBJ/j5u6KxgUycACC9qfQVYHbXYwMVf8s3dMVzJ1qekm37i6cnkCmTGy6cZWUfo2EIAtRJqhQwtbGIntJIRYnyG/ReMBRcp5MMn4dehur7HJn+YazE0bD0uB4R3q/KhRw01zQVjuo1VJXjnrnVYPVOQOIA6zWyWHmyg1vSYqcoYeYk9P/auOh3UFXiqBVecmfh31NBbMrwKvB0qfOzgF6d6Hox4EDDmdar2D6Hg5g==" Feb 08 04:46:09 volumio go-librespot[14558]: time="2026-02-08T04:46:09-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 08 04:46:09 volumio go-librespot[14558]: time="2026-02-08T04:46:09-06:00" level=debug msg="completed keyexchange" Feb 08 04:46:09 volumio go-librespot[14558]: time="2026-02-08T04:46:09-06:00" level=debug msg="completed challenge" Feb 08 04:46:09 volumio go-librespot[14558]: time="2026-02-08T04:46: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 " Feb 08 04:46:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 04:46:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 04:46:10 volumio volumio[14476]: info: Loading plugin "alarm-clock"... Feb 08 04:46:10 volumio volumio[14476]: info: Loading plugin "airplay_emulation"... Feb 08 04:46:10 volumio volumio[14476]: info: Starting Shairport Sync Feb 08 04:46:10 volumio volumio[14476]: info: Loading plugin "last_100"... Feb 08 04:46:10 volumio volumio[14476]: info: Loading plugin "webradio"... Feb 08 04:46:10 volumio volumio[14476]: info: Loading plugin "i2s_dacs"... Feb 08 04:46:10 volumio volumio[14476]: info: I2S DAC not set, start Auto-detection Feb 08 04:46:10 volumio volumio[14476]: info: Loading plugin "volumiodiscovery"... Feb 08 04:46:10 volumio volumio[14476]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 08 04:46:10 volumio volumio[14476]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 04:46:10 volumio volumio[14476]: *** WARNING *** For more information see Feb 08 04:46:10 volumio volumio[14476]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 08 04:46:10 volumio volumio[14476]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 04:46:10 volumio volumio[14476]: *** WARNING *** For more information see Feb 08 04:46:10 volumio node[14476]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 08 04:46:10 volumio node[14476]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 04:46:10 volumio node[14476]: *** WARNING *** For more information see Feb 08 04:46:10 volumio node[14476]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 08 04:46:10 volumio node[14476]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 04:46:10 volumio node[14476]: *** WARNING *** For more information see Feb 08 04:46:10 volumio volumio[14476]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 08 04:46:10 volumio volumio[14476]: info: Discovery: Started advertising with name: Volumio Feb 08 04:46:10 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 04:46:10 volumio volumio[14476]: info: Loading plugin "bandcamp"... Feb 08 04:46:11 volumio volumio[14476]: info: Plugin calmradio is not enabled Feb 08 04:46:11 volumio volumio[14476]: info: Loading plugin "soundcloud"... Feb 08 04:46:12 volumio volumio[14476]: info: Loading plugin "spop"... Feb 08 04:46:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 45. Feb 08 04:46:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:46:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:46:12 volumio go-librespot[14567]: go-librespot daemon starting... Feb 08 04:46:12 volumio go-librespot[14568]: time="2026-02-08T04:46:12-06:00" level=info msg="running go-librespot 0.4.0" Feb 08 04:46:12 volumio go-librespot[14568]: time="2026-02-08T04:46:12-06:00" level=debug msg="app state loaded" Feb 08 04:46:12 volumio go-librespot[14568]: time="2026-02-08T04:46:12-06:00" level=debug msg="stored credentials not found" Feb 08 04:46:12 volumio go-librespot[14568]: time="2026-02-08T04:46:12-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 04:46:13 volumio go-librespot[14568]: time="2026-02-08T04:46: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 04:46:13 volumio go-librespot[14568]: time="2026-02-08T04:46:13-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]" Feb 08 04:46:13 volumio go-librespot[14568]: time="2026-02-08T04:46:13-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]" Feb 08 04:46:13 volumio go-librespot[14568]: time="2026-02-08T04:46:13-06:00" level=info msg="zeroconf server listening on port 42499" Feb 08 04:46:13 volumio go-librespot[14568]: time="2026-02-08T04:46:13-06:00" level=debug msg="obtained new client token: AABsSAMMBOtwYWYdl1enP5IraZ/vKLuRbfhL720FQQHtxRz0VvD/dzmsg+AbwWQ2xoXr6bCnf10ajd8godNCJYwrKmnipDvjPuGXvQvvltQVJtV5fuwExf0aLh65wvc69RFwDO69MPNMsPTV14FtrXgFU3kOEcITu7YpW3KKr5h7oqVxrgEa+JxCvOHfFoqYOVFl10MbMn+dfhCXPmoPBsw+npfpJ1ZvRBAlZUfKGISiKreTyWsEWVE=" Feb 08 04:46:13 volumio go-librespot[14568]: time="2026-02-08T04:46:13-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 08 04:46:13 volumio go-librespot[14568]: time="2026-02-08T04:46:13-06:00" level=debug msg="completed keyexchange" Feb 08 04:46:13 volumio go-librespot[14568]: time="2026-02-08T04:46:13-06:00" level=debug msg="completed challenge" Feb 08 04:46:13 volumio volumio[14476]: info: Loading plugin "squeezelite_mc"... Feb 08 04:46:13 volumio go-librespot[14568]: time="2026-02-08T04:46: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 " Feb 08 04:46:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 04:46:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 04:46:13 volumio kernel: hwmon hwmon1: Voltage normalised Feb 08 04:46:14 volumio volumio[14476]: info: Loading plugin "youtube2"... Feb 08 04:46:14 volumio volumio[14476]: info: Loading plugin "ytcr"... Feb 08 04:46:15 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 08 04:46:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 46. Feb 08 04:46:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:46:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:46:16 volumio go-librespot[14578]: go-librespot daemon starting... Feb 08 04:46:16 volumio go-librespot[14579]: time="2026-02-08T04:46:16-06:00" level=info msg="running go-librespot 0.4.0" Feb 08 04:46:16 volumio go-librespot[14579]: time="2026-02-08T04:46:16-06:00" level=debug msg="app state loaded" Feb 08 04:46:16 volumio go-librespot[14579]: time="2026-02-08T04:46:16-06:00" level=debug msg="stored credentials not found" Feb 08 04:46:16 volumio go-librespot[14579]: time="2026-02-08T04:46:16-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 04:46:17 volumio go-librespot[14579]: time="2026-02-08T04:46: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-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 04:46:17 volumio go-librespot[14579]: time="2026-02-08T04:46:17-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]" Feb 08 04:46:17 volumio go-librespot[14579]: time="2026-02-08T04:46:17-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]" Feb 08 04:46:17 volumio go-librespot[14579]: time="2026-02-08T04:46:17-06:00" level=info msg="zeroconf server listening on port 35857" Feb 08 04:46:17 volumio volumio[14476]: info: Loading plugin "ytmusic"... Feb 08 04:46:17 volumio go-librespot[14579]: time="2026-02-08T04:46:17-06:00" level=debug msg="obtained new client token: AACmgrHGP1AFM7gqFwoUvQ0wyq4zst2mwqIq235Tm/jSagSORSzIpd6AFx8eu98BDek21ATg3VMTyczBjCr3fXQBSj2xiRVDwuzMhSiwLfQEBmo3SykmCXntO9YqktubAOJYKWdV8GYfLpzGuou8cNq1tBCkHnnOBbO3fMm2Xe3MEqeY7qBicdJ/HoeG8xwv3BUBJAUw+zByVUfgmqA8PLnpjxpHeCcCDI1uUFCGDtsGSra9iWRTKZA=" Feb 08 04:46:17 volumio go-librespot[14579]: time="2026-02-08T04:46:17-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 08 04:46:17 volumio go-librespot[14579]: time="2026-02-08T04:46:17-06:00" level=debug msg="completed keyexchange" Feb 08 04:46:17 volumio go-librespot[14579]: time="2026-02-08T04:46:17-06:00" level=debug msg="completed challenge" Feb 08 04:46:17 volumio go-librespot[14579]: time="2026-02-08T04:46: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 " Feb 08 04:46:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 04:46:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 04:46:18 volumio volumio[14476]: info: Plugin now_playing is not enabled Feb 08 04:46:18 volumio volumio[14476]: info: Loading plugin "outputs"... Feb 08 04:46:18 volumio volumio[14476]: info: Loading plugin "albumart"... Feb 08 04:46:18 volumio volumio[14476]: info: Plugin example_plugin is not enabled Feb 08 04:46:18 volumio volumio[14476]: info: Loading plugin "inputs"... Feb 08 04:46:18 volumio volumio[14476]: info: Loading plugin "updater_comm"... Feb 08 04:46:18 volumio volumio[14476]: info: Plugin mpdemulation is not enabled Feb 08 04:46:18 volumio volumio[14476]: info: Loading plugin "rest_api"... Feb 08 04:46:18 volumio volumio[14476]: info: Loading plugin "websocket"... Feb 08 04:46:18 volumio volumio[14476]: info: Starting Socket.io Server version 1.7.4 Feb 08 04:46:18 volumio volumio[14476]: info: Plugin fusiondsp is not enabled Feb 08 04:46:18 volumio volumio[14476]: info: Plugin mpdoutput is not enabled Feb 08 04:46:18 volumio volumio[14476]: info: Plugin RoonBridge is not enabled Feb 08 04:46:18 volumio volumio[14476]: info: Loading plugin "podcast"... Feb 08 04:46:18 volumio volumio[14476]: info: ControllerPodcast::constructor Feb 08 04:46:18 volumio volumio[14476]: info: Loading plugin "volusonic"... Feb 08 04:46:18 volumio volumio[14601]: Forking 3 albumart workers Feb 08 04:46:19 volumio volumio-remote-updater[751]: [2026-02-08 04:46:19] [connect] Successful connection Feb 08 04:46:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 47. Feb 08 04:46:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:46:20 volumio volumio[14476]: info: Applying required configuration parameters for plugin volusonic Feb 08 04:46:20 volumio volumio[14476]: info: Loading plugin "backup_restore"... Feb 08 04:46:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:46:20 volumio go-librespot[14642]: go-librespot daemon starting... Feb 08 04:46:20 volumio go-librespot[14643]: time="2026-02-08T04:46:20-06:00" level=info msg="running go-librespot 0.4.0" Feb 08 04:46:20 volumio go-librespot[14643]: time="2026-02-08T04:46:20-06:00" level=debug msg="app state loaded" Feb 08 04:46:20 volumio go-librespot[14643]: time="2026-02-08T04:46:20-06:00" level=debug msg="stored credentials not found" Feb 08 04:46:20 volumio go-librespot[14643]: time="2026-02-08T04:46:20-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 04:46:20 volumio volumio[14614]: Starting albumart workers Feb 08 04:46:20 volumio volumio[14612]: Starting albumart workers Feb 08 04:46:20 volumio volumio[14613]: Starting albumart workers Feb 08 04:46:21 volumio go-librespot[14643]: time="2026-02-08T04:46: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 04:46:21 volumio go-librespot[14643]: time="2026-02-08T04:46:21-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]" Feb 08 04:46:21 volumio go-librespot[14643]: time="2026-02-08T04:46:21-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]" Feb 08 04:46:21 volumio go-librespot[14643]: time="2026-02-08T04:46:21-06:00" level=info msg="zeroconf server listening on port 41011" Feb 08 04:46:21 volumio volumio[14476]: info: Applying required configuration parameters for plugin backup_restore Feb 08 04:46:21 volumio go-librespot[14643]: time="2026-02-08T04:46:21-06:00" level=debug msg="obtained new client token: AADnZ9tM3EVEsQ/2TmsGDdvjG9jjbLD1WUlxcjBW4bB8ZzIDDQVhGK1aaAa8IEiUwjwCewWSWmx6sAjv9XyGCmzQl6ih/5QxQIdbK45xgJtkmOMgjnROgIpcTFgef5M9m+xz6EuE1KaIJmwh6zOYnLGkk/+Pz0893cPsdG4VcFgBJttfglKn4GKXoeW1VD0e40B7NR5MPjCwt8EZPfe9IXffoH2vvECIK3VYRp1+OaZrlp4Y5BZBnq6haw==" Feb 08 04:46:21 volumio volumio[14476]: info: Plugin rpi_eeprom_config is not enabled Feb 08 04:46:21 volumio volumio[14476]: info: Plugin rpi_eeprom_updater is not enabled Feb 08 04:46:21 volumio volumio[14476]: info: Loading plugin "scheduledrestart"... Feb 08 04:46:21 volumio go-librespot[14643]: time="2026-02-08T04:46:21-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 08 04:46:21 volumio go-librespot[14643]: time="2026-02-08T04:46:21-06:00" level=debug msg="completed keyexchange" Feb 08 04:46:21 volumio go-librespot[14643]: time="2026-02-08T04:46:21-06:00" level=debug msg="completed challenge" Feb 08 04:46:21 volumio go-librespot[14643]: time="2026-02-08T04:46: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 " Feb 08 04:46:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 04:46:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 04:46:21 volumio volumio[14476]: info: Applying required configuration parameters for plugin scheduledrestart Feb 08 04:46:21 volumio volumio[14476]: info: Plugin Bluetoothremote is not enabled Feb 08 04:46:21 volumio volumio[14476]: info: Plugin music_services_shield is not enabled Feb 08 04:46:21 volumio volumio[14476]: info: Loading plugin "Systeminfo"... Feb 08 04:46:22 volumio volumio[14476]: info: Plugin peppymeterbasic is not enabled Feb 08 04:46:22 volumio volumio[14476]: info: Loading plugin "peppyspectrum"... Feb 08 04:46:22 volumio volumio[14476]: info: Loading i18n strings for locale en Feb 08 04:46:22 volumio volumio[14476]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Feb 08 04:46:22 volumio volumio[14476]: Updating browse sources language Feb 08 04:46:22 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::initPlayerControls Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 04:46:23 volumio volumio[14476]: Express server listening on port 3000 Feb 08 04:46:23 volumio volumio[14476]: [Metrics] WebUI: 19s 58.39ms Feb 08 04:46:23 volumio volumio[14476]: info: CoreStateMachine::resetVolumioState Feb 08 04:46:23 volumio volumio[14476]: info: CoreStateMachine::getcurrentVolume Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 04:46:23 volumio sudo[14673]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 08 04:46:23 volumio sudo[14673]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:46:23 volumio sudo[14673]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:23 volumio sudo[14675]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 08 04:46:23 volumio sudo[14675]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:46:23 volumio sudo[14675]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:23 volumio volumio[14476]: info: Volumio Network Manager: Network status updated: 1 Feb 08 04:46:23 volumio volumio[14476]: info: VolumeController:: Volume=100 Mute =false Feb 08 04:46:23 volumio volumio[14476]: info: CoreStateMachine::pushState Feb 08 04:46:23 volumio volumio[14476]: info: CorePlayQueue::getTrack 0 Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::volumioPushState Feb 08 04:46:23 volumio volumio[14476]: info: CoreStateMachine::updateTrackBlock Feb 08 04:46:23 volumio volumio[14476]: info: CorePlayQueue::getTrackBlock Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 04:46:23 volumio volumio-remote-updater[751]: [2026-02-08 04:46:23] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770547579 101 Feb 08 04:46:23 volumio volumio[14476]: 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 Feb 08 04:46:23 volumio volumio[14476]: info: Reloading queue from file Feb 08 04:46:23 volumio volumio[14476]: info: CoreStateMachine::setRepeat null single undefined Feb 08 04:46:23 volumio volumio[14476]: info: CoreStateMachine::pushState Feb 08 04:46:23 volumio volumio[14476]: info: CorePlayQueue::getTrack 0 Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::volumioPushState Feb 08 04:46:23 volumio volumio[14476]: info: CoreStateMachine::setRandom null Feb 08 04:46:23 volumio volumio[14476]: info: CoreStateMachine::pushState Feb 08 04:46:23 volumio volumio[14476]: info: CorePlayQueue::getTrack 0 Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::volumioPushState Feb 08 04:46:23 volumio volumio[14476]: info: Setting Device type: Raspberry PI Feb 08 04:46:23 volumio volumio[14476]: info: VolumeController:: Volume=100 Mute =false Feb 08 04:46:23 volumio volumio[14476]: info: CoreStateMachine::pushState Feb 08 04:46:23 volumio volumio[14476]: info: CorePlayQueue::getTrack 0 Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::volumioPushState Feb 08 04:46:23 volumio volumio[14476]: info: Completed loading Core Plugins Feb 08 04:46:23 volumio volumio[14476]: info: Preparing to generate the ALSA configuration file Feb 08 04:46:23 volumio sudo[14688]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 08 04:46:23 volumio sudo[14688]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:46:23 volumio volumio[14476]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Feb 08 04:46:23 volumio volumio[14476]: info: Discovery: Found device Volumio Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::volumioGetState Feb 08 04:46:23 volumio volumio[14476]: info: CorePlayQueue::getTrack 0 Feb 08 04:46:23 volumio volumio[14476]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Feb 08 04:46:23 volumio volumio[14476]: info: Discovery: Found device Volumio Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::volumioGetState Feb 08 04:46:23 volumio volumio[14476]: info: CorePlayQueue::getTrack 0 Feb 08 04:46:23 volumio volumio[14476]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Feb 08 04:46:23 volumio volumio[14476]: info: Reading ALSA contributions from plugins. Feb 08 04:46:23 volumio volumio[14476]: info: Asound.conf file unchanged, so no further update is needed Feb 08 04:46:23 volumio volumio[14476]: info: Output device has changed, restarting MPD Feb 08 04:46:23 volumio sudo[14688]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:23 volumio volumio[14476]: info: Output device has changed, restarting Shairport Sync Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 04:46:23 volumio sudo[14691]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 08 04:46:23 volumio sudo[14691]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:46:23 volumio sudo[14691]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:23 volumio sudo[14693]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 08 04:46:23 volumio sudo[14693]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:46:23 volumio volumio[14476]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 04:46:23 volumio volumio[14476]: info: ___________ START PLUGINS ___________ Feb 08 04:46:23 volumio volumio[14476]: info: ControllerMpd::onStart: Initializing MPD Feb 08 04:46:23 volumio volumio[14476]: info: Creating MPD Configuration file Feb 08 04:46:23 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 04:46:23 volumio volumio[14476]: info: [1770547583691] CoreMusicLibrary::Adding element Media Servers Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 04:46:23 volumio sudo[14703]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 08 04:46:23 volumio sudo[14701]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 08 04:46:23 volumio sudo[14701]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:46:23 volumio sudo[14703]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:46:23 volumio sudo[14701]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 04:46:23 volumio volumio[14476]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 04:46:23 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 08 04:46:23 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 08 04:46:23 volumio systemd[1]: mpd.service: Consumed 4.194s CPU time. Feb 08 04:46:23 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 08 04:46:23 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 08 04:46:23 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 08 04:46:23 volumio volumio[14476]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 04:46:23 volumio volumio[14476]: info: [1770547583800] CoreMusicLibrary::Adding element Last_100 Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 04:46:23 volumio volumio[14476]: info: [1770547583805] CoreMusicLibrary::Adding element Webradio Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 04:46:23 volumio volumio[14476]: info: Initializing BBC Radios Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 04:46:23 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 04:46:23 volumio volumio[14476]: info: [1770547583882] CoreMusicLibrary::Adding element Bandcamp Discover Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 04:46:23 volumio volumio[14476]: Cannot find translation for source Bandcamp Discover Feb 08 04:46:23 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 04:46:23 volumio volumio[14476]: info: [1770547583900] CoreMusicLibrary::Adding element SoundCloud Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 04:46:23 volumio volumio[14476]: Cannot find translation for source Bandcamp Discover Feb 08 04:46:23 volumio volumio[14476]: Cannot find translation for source SoundCloud Feb 08 04:46:23 volumio volumio[14476]: info: Creating Spotify config file Feb 08 04:46:23 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:24 volumio sudo[14728]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 08 04:46:24 volumio sudo[14728]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 08 04:46:24 volumio sudo[14728]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:24 volumio volumio[14476]: info: [squeezelite_mc] Starting proxy server... Feb 08 04:46:24 volumio volumio[14476]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 04:46:24 volumio volumio[14476]: info: [1770547584253] CoreMusicLibrary::Adding element YouTube2 Feb 08 04:46:24 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 04:46:24 volumio volumio[14476]: Cannot find translation for source Bandcamp Discover Feb 08 04:46:24 volumio volumio[14476]: Cannot find translation for source SoundCloud Feb 08 04:46:24 volumio volumio[14476]: Cannot find translation for source YouTube2 Feb 08 04:46:24 volumio volumio[14476]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 04:46:24 volumio volumio[14476]: info: [1770547584272] CoreMusicLibrary::Adding element YouTube Music Feb 08 04:46:24 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 04:46:24 volumio volumio[14476]: Cannot find translation for source Bandcamp Discover Feb 08 04:46:24 volumio volumio[14476]: Cannot find translation for source SoundCloud Feb 08 04:46:24 volumio volumio[14476]: Cannot find translation for source YouTube2 Feb 08 04:46:24 volumio volumio[14476]: Cannot find translation for source YouTube Music Feb 08 04:46:24 volumio volumio[14476]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 04:46:24 volumio volumio[14476]: info: [1770547584284] CoreMusicLibrary::Adding element Podcast Feb 08 04:46:24 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 04:46:24 volumio volumio[14476]: Cannot find translation for source Bandcamp Discover Feb 08 04:46:24 volumio volumio[14476]: Cannot find translation for source SoundCloud Feb 08 04:46:24 volumio volumio[14476]: Cannot find translation for source YouTube2 Feb 08 04:46:24 volumio volumio[14476]: Cannot find translation for source YouTube Music Feb 08 04:46:24 volumio volumio[14476]: Cannot find translation for source Podcast Feb 08 04:46:24 volumio volumio[14476]: info: Loading i18n strings for locale en Feb 08 04:46:24 volumio volumio[14476]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Feb 08 04:46:24 volumio volumio[14476]: Updating browse sources language Feb 08 04:46:24 volumio volumio[14476]: Cannot find translation for source Bandcamp Discover Feb 08 04:46:24 volumio volumio[14476]: Cannot find translation for source SoundCloud Feb 08 04:46:24 volumio volumio[14476]: Cannot find translation for source YouTube2 Feb 08 04:46:24 volumio volumio[14476]: Cannot find translation for source YouTube Music Feb 08 04:46:24 volumio volumio[14476]: Cannot find translation for source Podcast Feb 08 04:46:24 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 04:46:24 volumio volumio[14476]: Cannot find translation for source Bandcamp Discover Feb 08 04:46:24 volumio volumio[14476]: Cannot find translation for source SoundCloud Feb 08 04:46:24 volumio volumio[14476]: Cannot find translation for source YouTube2 Feb 08 04:46:24 volumio volumio[14476]: Cannot find translation for source YouTube Music Feb 08 04:46:24 volumio volumio[14476]: Cannot find translation for source Podcast Feb 08 04:46:24 volumio volumio[14476]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 04:46:24 volumio volumio[14476]: info: [1770547584330] CoreMusicLibrary::Adding element Volusonic Feb 08 04:46:24 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 04:46:24 volumio volumio[14476]: Cannot find translation for source Bandcamp Discover Feb 08 04:46:24 volumio volumio[14476]: Cannot find translation for source SoundCloud Feb 08 04:46:24 volumio volumio[14476]: Cannot find translation for source YouTube2 Feb 08 04:46:24 volumio volumio[14476]: Cannot find translation for source YouTube Music Feb 08 04:46:24 volumio volumio[14476]: Cannot find translation for source Podcast Feb 08 04:46:24 volumio volumio[14476]: Cannot find translation for source Volusonic Feb 08 04:46:24 volumio volumio[14476]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Feb 08 04:46:24 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Feb 08 04:46:24 volumio volumio[14476]: info: Volumio Calling Home Feb 08 04:46:24 volumio volumio[14476]: info: [squeezelite_mc] Proxy server started on port 37633 Feb 08 04:46:24 volumio volumio[14476]: info: Preparing to generate the ALSA configuration file Feb 08 04:46:24 volumio volumio[14476]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 04:46:24 volumio volumio[14476]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Feb 08 04:46:24 volumio volumio[14476]: info: Reading ALSA contributions from plugins. Feb 08 04:46:24 volumio volumio[14476]: info: MPD Permissions set Feb 08 04:46:24 volumio volumio[14476]: info: MPD Permissions set Feb 08 04:46:24 volumio volumio[14476]: info: Upmpdcli Daemon Started Feb 08 04:46:24 volumio volumio[14476]: info: Spotify config file written Feb 08 04:46:24 volumio sudo[14739]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 08 04:46:24 volumio sudo[14739]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:46:24 volumio volumio[14476]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 08 04:46:24 volumio volumio[14476]: info: VolumeController:: Volume=100 Mute =false Feb 08 04:46:24 volumio volumio[14476]: info: CoreStateMachine::pushState Feb 08 04:46:24 volumio volumio[14476]: info: CorePlayQueue::getTrack 0 Feb 08 04:46:24 volumio volumio[14476]: info: CoreCommandRouter::volumioPushState Feb 08 04:46:24 volumio volumio[14476]: info: [squeezelite_mc] Server discovery started Feb 08 04:46:24 volumio volumio[14476]: info: [squeezelite_mc] Player finder started Feb 08 04:46:24 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:24 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:24 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:24 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 04:46:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 48. Feb 08 04:46:24 volumio volumio[14476]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Feb 08 04:46:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:46:24 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:24 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:24 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:24 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:24 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:24 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:24 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:24 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:24 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 04:46:24 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:24 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:24 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:24 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:24 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:24 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:24 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:24 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:24 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:24 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 04:46:24 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:24 volumio volumio[14476]: info: No need to fix Spotify hosts Feb 08 04:46:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:46:24 volumio go-librespot[14743]: go-librespot daemon starting... Feb 08 04:46:24 volumio sudo[14739]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:24 volumio go-librespot[14754]: time="2026-02-08T04:46:24-06:00" level=info msg="running go-librespot 0.4.0" Feb 08 04:46:24 volumio go-librespot[14754]: time="2026-02-08T04:46:24-06:00" level=debug msg="app state loaded" Feb 08 04:46:24 volumio go-librespot[14754]: time="2026-02-08T04:46:24-06:00" level=debug msg="stored credentials not found" Feb 08 04:46:24 volumio go-librespot[14754]: time="2026-02-08T04:46:24-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 04:46:25 volumio volumio[14476]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 08 04:46:25 volumio volumio[14476]: info: Volumio called home Feb 08 04:46:25 volumio volumio[14476]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Feb 08 04:46:25 volumio volumio[14476]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Feb 08 04:46:25 volumio volumio[14476]: 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 Feb 08 04:46:25 volumio volumio[14476]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 08 04:46:25 volumio volumio[14476]: SPOTIFY: BQBTnugebLrL0RrISjsaQukbqDarwTcp1U-2dGUaayFLPTFXNsz5e9CU0_5hjKB7RQWlXU93ic9-cR9pYv27ZNN7zjeZukbWQDAHY0JfHySO_BoWzvCm5wAOIFzM9pR8IVbCGjAJ4Gbt7YHfybLbtzQuOhrja7J_PCRAvv6mLC96S5CRrdg32VzyiDklbmBiuD9yePsaSWogKX5erFt_1uDgIyMLx0UQTLwi9I4 Feb 08 04:46:25 volumio volumio[14476]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 08 04:46:25 volumio volumio[14476]: info: New Spotify access token = BQBTnugebLrL0RrISjsaQukbqDarwTcp1U-2dGUaayFLPTFXNsz5e9CU0_5hjKB7RQWlXU93ic9-cR9pYv27ZNN7zjeZukbWQDAHY0JfHySO_BoWzvCm5wAOIFzM9pR8IVbCGjAJ4Gbt7YHfybLbtzQuOhrja7J_PCRAvv6mLC96S5CRrdg32VzyiDklbmBiuD9yePsaSWogKX5erFt_1uDgIyMLx0UQTLwi9I4 Feb 08 04:46:25 volumio volumio[14476]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 08 04:46:25 volumio go-librespot[14754]: time="2026-02-08T04:46: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-gew1.spotify.com:80]" Feb 08 04:46:25 volumio go-librespot[14754]: time="2026-02-08T04:46:25-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]" Feb 08 04:46:25 volumio go-librespot[14754]: time="2026-02-08T04:46:25-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]" Feb 08 04:46:25 volumio sudo[14764]: 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 Feb 08 04:46:25 volumio sudo[14764]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:46:25 volumio go-librespot[14754]: time="2026-02-08T04:46:25-06:00" level=info msg="zeroconf server listening on port 37335" Feb 08 04:46:25 volumio sudo[14764]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:25 volumio volumio[14476]: info: Starting Shairport Sync Feb 08 04:46:25 volumio volumio[14476]: info: Starting Shairport Sync Feb 08 04:46:25 volumio volumio[14476]: info: Starting Shairport Sync Feb 08 04:46:25 volumio sudo[14767]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 04:46:25 volumio sudo[14767]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:46:25 volumio go-librespot[14754]: time="2026-02-08T04:46:25-06:00" level=debug msg="obtained new client token: AABN7QegpKRdIQMP/amSS0ze+j8kE/GcJKPBBEzbHZra9S6znPqGw3wHo1Mxk926y6afB+pPBE5yXpMnIhvtIyFSvbCSOSM4dw/X8mYN6m5U+M74bxcoZYPuxPJ88+Dj7/RGjc23vqgyojgD6/a7wuGV4tuqPOOYR1exQ7GhQPVF/Hdm0cJF6ZG9AVqhp50MN6V4gP8jsdsBRxR6iA04xCoP8PbDV7OF6Ic5eXF2J0kgDxiSVSeUW3WoKQ==" Feb 08 04:46:25 volumio volumio[14476]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Feb 08 04:46:25 volumio sudo[14771]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 04:46:25 volumio sudo[14771]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:46:25 volumio sudo[14769]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 04:46:25 volumio sudo[14769]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:46:25 volumio go-librespot[14754]: time="2026-02-08T04:46:25-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 08 04:46:25 volumio sudo[14776]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Feb 08 04:46:25 volumio sudo[14776]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:46:25 volumio volumio[14476]: info: Asound.conf file unchanged, so no further update is needed Feb 08 04:46:25 volumio volumio[14476]: info: Output device has changed, restarting MPD Feb 08 04:46:25 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 08 04:46:25 volumio sudo[14776]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:25 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 08 04:46:25 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 04:46:25 volumio systemd[1]: shairport-sync.service: Consumed 2.137s CPU time. Feb 08 04:46:25 volumio go-librespot[14754]: time="2026-02-08T04:46:25-06:00" level=debug msg="completed keyexchange" Feb 08 04:46:25 volumio go-librespot[14754]: time="2026-02-08T04:46:25-06:00" level=debug msg="completed challenge" Feb 08 04:46:25 volumio volumio[14476]: info: Output device has changed, restarting Shairport Sync Feb 08 04:46:25 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:25 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 04:46:25 volumio sudo[14780]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 08 04:46:25 volumio sudo[14780]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:46:25 volumio sudo[14783]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 08 04:46:25 volumio go-librespot[14754]: time="2026-02-08T04:46: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 " Feb 08 04:46:25 volumio sudo[14780]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:25 volumio sudo[14783]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:46:25 volumio volumio[14476]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 04:46:25 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 04:46:25 volumio sudo[14771]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:25 volumio sudo[14769]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 04:46:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 04:46:25 volumio sudo[14767]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:25 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 08 04:46:25 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 08 04:46:25 volumio systemd[1]: mpd.service: Consumed 1.574s CPU time. Feb 08 04:46:25 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 08 04:46:25 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 08 04:46:25 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 08 04:46:25 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 08 04:46:25 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 08 04:46:25 volumio volumio[14476]: info: MPD Permissions set Feb 08 04:46:25 volumio volumio[14476]: info: Shairport-Sync Started Feb 08 04:46:25 volumio volumio[14476]: Error adding Membership: Error: addMembership EINVAL Feb 08 04:46:25 volumio volumio[14476]: info: Shairport-Sync Started Feb 08 04:46:25 volumio volumio[14476]: info: Shairport-Sync Started Feb 08 04:46:25 volumio volumio[14476]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Feb 08 04:46:25 volumio sudo[14812]: 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 Feb 08 04:46:25 volumio sudo[14812]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:46:25 volumio sudo[14812]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:25 volumio kernel: hwmon hwmon1: Voltage normalised Feb 08 04:46:25 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:25 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:25 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:25 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:25 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:25 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:25 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:25 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:25 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 04:46:25 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:25 volumio volumio[14476]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Feb 08 04:46:25 volumio volumio[14476]: info: CoreCommandRouter::volumioGetState Feb 08 04:46:25 volumio volumio[14476]: info: CorePlayQueue::getTrack 0 Feb 08 04:46:25 volumio volumio[14476]: info: Starting Shairport Sync Feb 08 04:46:25 volumio sudo[14821]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Feb 08 04:46:25 volumio sudo[14821]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:46:25 volumio sudo[14809]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 08 04:46:25 volumio sudo[14809]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 08 04:46:26 volumio sudo[14809]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:26 volumio sudo[14823]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 04:46:26 volumio sudo[14823]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:46:26 volumio volumio[14476]: 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"} Feb 08 04:46:26 volumio volumio[14476]: info: Spotify Successfully logged in Feb 08 04:46:26 volumio volumio[14476]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 04:46:26 volumio volumio[14476]: info: [1770547586058] CoreMusicLibrary::Adding element Spotify Feb 08 04:46:26 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 04:46:26 volumio volumio[14476]: Cannot find translation for source Bandcamp Discover Feb 08 04:46:26 volumio volumio[14476]: Cannot find translation for source SoundCloud Feb 08 04:46:26 volumio volumio[14476]: Cannot find translation for source YouTube2 Feb 08 04:46:26 volumio volumio[14476]: Cannot find translation for source YouTube Music Feb 08 04:46:26 volumio volumio[14476]: Cannot find translation for source Podcast Feb 08 04:46:26 volumio volumio[14476]: Cannot find translation for source Volusonic Feb 08 04:46:26 volumio volumio[14476]: Cannot find translation for source Spotify Feb 08 04:46:26 volumio systemd[1]: Reloading. Feb 08 04:46:27 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:27 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:27 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 04:46:27 volumio volumio[14476]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 04:46:27 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 08 04:46:28 volumio volumio[14476]: info: go-librespot daemon successfully initialized Feb 08 04:46:28 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. Feb 08 04:46:28 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. Feb 08 04:46:29 volumio sudo[14821]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:29 volumio volumio[14476]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 08 04:46:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 49. Feb 08 04:46:29 volumio sudo[14862]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 08 04:46:29 volumio sudo[14862]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:46:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:46:29 volumio go-librespot[14864]: go-librespot daemon starting... Feb 08 04:46:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:46:29 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 08 04:46:29 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 08 04:46:29 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 04:46:29 volumio systemd[1]: shairport-sync.service: Consumed 1.483s CPU time. Feb 08 04:46:29 volumio go-librespot[14865]: time="2026-02-08T04:46:29-06:00" level=info msg="running go-librespot 0.4.0" Feb 08 04:46:29 volumio go-librespot[14865]: time="2026-02-08T04:46:29-06:00" level=debug msg="app state loaded" Feb 08 04:46:29 volumio go-librespot[14865]: time="2026-02-08T04:46:29-06:00" level=debug msg="stored credentials not found" Feb 08 04:46:29 volumio go-librespot[14865]: time="2026-02-08T04:46:29-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 04:46:29 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 04:46:29 volumio sudo[14823]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:29 volumio volumio[14476]: info: Shairport-Sync Started Feb 08 04:46:29 volumio sudo[14862]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:29 volumio volumio[14476]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Feb 08 04:46:29 volumio sudo[14882]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Feb 08 04:46:29 volumio sudo[14882]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:46:30 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Feb 08 04:46:30 volumio go-librespot[14865]: time="2026-02-08T04:46:30-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]" Feb 08 04:46:30 volumio go-librespot[14865]: time="2026-02-08T04:46:30-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]" Feb 08 04:46:30 volumio go-librespot[14865]: time="2026-02-08T04:46:30-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]" Feb 08 04:46:30 volumio go-librespot[14865]: time="2026-02-08T04:46:30-06:00" level=info msg="zeroconf server listening on port 34133" Feb 08 04:46:30 volumio systemd[1]: squeezelite.service: Deactivated successfully. Feb 08 04:46:30 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Feb 08 04:46:30 volumio sudo[14882]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:30 volumio go-librespot[14865]: time="2026-02-08T04:46:30-06:00" level=debug msg="obtained new client token: AABswORZ/4hApIs4pdyA2SHOmPy1rnbJ7D5VTdFM7mTOHgrpQ1sV7iZgNI5n0GYbP7GMka2MK/l5wbMpLhfIBmyFsQeenapnDpN+IaFj0xtzwXZtGgxhfP/YaXfkhQPVmASItviIfDxibWH/uy7YJQWJqxu2Tq0X6XVvdts9XF4mem1tf+JqiQ+Jp42uyxHVXMJbeMdrCG2hxi/dAxM8cO9LVY2qkjsr2OqvJIG3zdTWRyPUGS4SpPI=" Feb 08 04:46:30 volumio go-librespot[14865]: time="2026-02-08T04:46:30-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 08 04:46:30 volumio go-librespot[14865]: time="2026-02-08T04:46:30-06:00" level=debug msg="completed keyexchange" Feb 08 04:46:30 volumio go-librespot[14865]: time="2026-02-08T04:46:30-06:00" level=debug msg="completed challenge" Feb 08 04:46:30 volumio go-librespot[14865]: time="2026-02-08T04:46:30-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 " Feb 08 04:46:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 04:46:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 04:46:30 volumio volumio[14476]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 08 04:46:30 volumio sudo[14891]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 08 04:46:30 volumio sudo[14891]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:46:30 volumio sudo[14891]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:30 volumio volumio[14476]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Feb 08 04:46:30 volumio sudo[14895]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Feb 08 04:46:30 volumio sudo[14895]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:46:30 volumio sudo[14895]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:30 volumio volumio[14476]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Feb 08 04:46:30 volumio sudo[14898]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Feb 08 04:46:30 volumio sudo[14898]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:46:30 volumio mpd[14827]: 2026-02-08T04:46:30 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 08 04:46:31 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Feb 08 04:46:31 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Feb 08 04:46:31 volumio sudo[14898]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:31 volumio volumio[14476]: info: Initializing connection to go-librespot Websocket Feb 08 04:46:31 volumio volumio[14476]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 04:46:31 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 08 04:46:31 volumio sudo[14693]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:31 volumio sudo[14703]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:31 volumio sudo[14783]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:31 volumio volumio[14476]: error: MPD error: The expression evaluated to a falsy value: Feb 08 04:46:31 volumio volumio[14476]: assert.ok(self.idling) Feb 08 04:46:31 volumio volumio[14476]: error: The expression evaluated to a falsy value: Feb 08 04:46:31 volumio volumio[14476]: assert.ok(self.idling) Feb 08 04:46:31 volumio volumio[14476]: error: MPD error: The expression evaluated to a falsy value: Feb 08 04:46:31 volumio volumio[14476]: assert.ok(self.idling) Feb 08 04:46:31 volumio volumio[14476]: error: The expression evaluated to a falsy value: Feb 08 04:46:31 volumio volumio[14476]: assert.ok(self.idling) Feb 08 04:46:31 volumio volumio[14476]: error: updateQueue error: null Feb 08 04:46:31 volumio volumio[14476]: info: MPD running with PID14827 Feb 08 04:46:31 volumio volumio[14476]: ,establishing connection Feb 08 04:46:31 volumio volumio[14476]: error: updateQueue error: null Feb 08 04:46:31 volumio volumio[14476]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 08 04:46:31 volumio sudo[14910]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 08 04:46:31 volumio sudo[14910]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:46:31 volumio sudo[14910]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:32 volumio kernel: hwmon hwmon1: Voltage normalised Feb 08 04:46:32 volumio volumio[14476]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 08 04:46:32 volumio sudo[14914]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 08 04:46:32 volumio sudo[14914]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:46:32 volumio sudo[14914]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:32 volumio volumio[14476]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 08 04:46:32 volumio sudo[14917]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 08 04:46:32 volumio sudo[14917]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:46:32 volumio sudo[14917]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:33 volumio volumio[14476]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 08 04:46:33 volumio sudo[14920]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 08 04:46:33 volumio sudo[14920]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:46:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50. Feb 08 04:46:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:46:33 volumio sudo[14920]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:46:33 volumio go-librespot[14922]: go-librespot daemon starting... Feb 08 04:46:33 volumio go-librespot[14923]: time="2026-02-08T04:46:33-06:00" level=info msg="running go-librespot 0.4.0" Feb 08 04:46:33 volumio go-librespot[14923]: time="2026-02-08T04:46:33-06:00" level=debug msg="app state loaded" Feb 08 04:46:33 volumio go-librespot[14923]: time="2026-02-08T04:46:33-06:00" level=debug msg="stored credentials not found" Feb 08 04:46:33 volumio go-librespot[14923]: time="2026-02-08T04:46:33-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 04:46:33 volumio go-librespot[14923]: time="2026-02-08T04:46: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]" Feb 08 04:46:33 volumio go-librespot[14923]: time="2026-02-08T04:46: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]" Feb 08 04:46:33 volumio go-librespot[14923]: time="2026-02-08T04:46: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]" Feb 08 04:46:33 volumio go-librespot[14923]: time="2026-02-08T04:46:33-06:00" level=info msg="zeroconf server listening on port 43407" Feb 08 04:46:33 volumio go-librespot[14923]: time="2026-02-08T04:46:33-06:00" level=debug msg="obtained new client token: AADtbuy/k2+sNuXGX81c7bmA4NZ63AnBK4btq9P6ncMq0jEC6NahFbRHZHKq1atkG0qRk5azVV2okbtd9Hi8OgvXHvHtiz/oB30vsry+sMqAIUkhfATEn5qG9jXq4l09ZmRDrCbpzVFUPkdWk/wXebbzXF5SSE8ySEbjgsh5K4Hh16+RdJ5eTIocZ13ggvQ4eEcbdOSzKTYxzBRkOIsRd//2n0Ed6uNHMw9KaJ6Fj2t/Jeban91VBOEu0A==" Feb 08 04:46:33 volumio go-librespot[14923]: time="2026-02-08T04:46:33-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 08 04:46:33 volumio go-librespot[14923]: time="2026-02-08T04:46:33-06:00" level=debug msg="completed keyexchange" Feb 08 04:46:33 volumio go-librespot[14923]: time="2026-02-08T04:46:33-06:00" level=debug msg="completed challenge" Feb 08 04:46:33 volumio volumio[14476]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 08 04:46:33 volumio sudo[14931]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 08 04:46:33 volumio sudo[14931]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:46:33 volumio go-librespot[14923]: time="2026-02-08T04:46: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 " Feb 08 04:46:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 04:46:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 04:46:34 volumio sudo[14931]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:34 volumio volumio[14476]: info: Completed starting Core Plugins Feb 08 04:46:34 volumio volumio[14476]: info: ------------------------------------------- Feb 08 04:46:34 volumio volumio[14476]: info: ----- MyVolumio plugins startup ---- Feb 08 04:46:34 volumio volumio[14476]: info: ------------------------------------------- Feb 08 04:46:34 volumio volumio[14476]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 08 04:46:34 volumio volumio[14476]: info: Initializing connection to go-librespot Websocket Feb 08 04:46:34 volumio volumio[14476]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 04:46:34 volumio sudo[14934]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 08 04:46:34 volumio sudo[14934]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:46:34 volumio sudo[14936]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 08 04:46:34 volumio sudo[14936]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:46:34 volumio sudo[14938]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 08 04:46:34 volumio sudo[14938]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:46:34 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 08 04:46:34 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 08 04:46:34 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 08 04:46:34 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 08 04:46:34 volumio sudo[14938]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:34 volumio sudo[14934]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:34 volumio sudo[14936]: pam_unix(sudo:session): session closed for user root Feb 08 04:46:34 volumio mpd_monitor.sh[14942]: MPD Monitor Service: Starting MPD Monitor Service Feb 08 04:46:34 volumio volumio[14476]: info: Successfully started MPD Monitor Feb 08 04:46:34 volumio volumio[14476]: info: Successfully started MPD Monitor Feb 08 04:46:34 volumio volumio[14476]: info: Successfully started MPD Monitor Feb 08 04:46:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 51. Feb 08 04:46:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:46:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:46:37 volumio go-librespot[14948]: go-librespot daemon starting... Feb 08 04:46:37 volumio go-librespot[14949]: time="2026-02-08T04:46:37-06:00" level=info msg="running go-librespot 0.4.0" Feb 08 04:46:37 volumio go-librespot[14949]: time="2026-02-08T04:46:37-06:00" level=debug msg="app state loaded" Feb 08 04:46:37 volumio go-librespot[14949]: time="2026-02-08T04:46:37-06:00" level=debug msg="stored credentials not found" Feb 08 04:46:37 volumio go-librespot[14949]: time="2026-02-08T04:46:37-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 04:46:37 volumio volumio[14476]: info: Initializing connection to go-librespot Websocket Feb 08 04:46:37 volumio go-librespot[14949]: time="2026-02-08T04:46: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 04:46:37 volumio go-librespot[14949]: time="2026-02-08T04:46:37-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]" Feb 08 04:46:37 volumio go-librespot[14949]: time="2026-02-08T04:46:37-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]" Feb 08 04:46:37 volumio go-librespot[14949]: time="2026-02-08T04:46:37-06:00" level=info msg="zeroconf server listening on port 36649" Feb 08 04:46:37 volumio go-librespot[14949]: time="2026-02-08T04:46:37-06:00" level=debug msg="new websocket client" Feb 08 04:46:37 volumio go-librespot[14949]: time="2026-02-08T04:46:37-06:00" level=debug msg="obtained new client token: AAAdZlCA0H5IEsb5r8oocfqf620DBFib+uvFcdQKpferPJqNSnSAxl07HzzXrQ18lo9qV8uw1yfgO2W+rnEWFy/Y7iS4qSTbUMBSMBUxSDLX9bJjlM4nK2vYa4OMX4ck7hj99GOiRExjKDwSf0FjwyO3grSpEqTfMEm0QuGsBSqz83CA5uZ1IhwwqY0ocj1KJOIgIhb5gpFXcd5MMZLtVBG8kuxtI8WZ/54MAYskhqzy1YEWfiw/z/gcMg==" Feb 08 04:46:37 volumio go-librespot[14949]: time="2026-02-08T04:46:37-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 08 04:46:37 volumio go-librespot[14949]: time="2026-02-08T04:46:37-06:00" level=debug msg="completed keyexchange" Feb 08 04:46:37 volumio go-librespot[14949]: time="2026-02-08T04:46:37-06:00" level=debug msg="completed challenge" Feb 08 04:46:37 volumio go-librespot[14949]: time="2026-02-08T04:46: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 " Feb 08 04:46:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 04:46:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 04:46:38 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 08 04:46:38 volumio volumio[14476]: info: Connection to go-librespot Websocket established Feb 08 04:46:38 volumio volumio[14476]: info: Connection to go-librespot Websocket closed Feb 08 04:46:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 52. Feb 08 04:46:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:46:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 04:46:41 volumio go-librespot[14971]: go-librespot daemon starting... Feb 08 04:46:41 volumio go-librespot[14972]: time="2026-02-08T04:46:41-06:00" level=info msg="running go-librespot 0.4.0" Feb 08 04:46:41 volumio go-librespot[14972]: time="2026-02-08T04:46:41-06:00" level=debug msg="app state loaded" Feb 08 04:46:41 volumio go-librespot[14972]: time="2026-02-08T04:46:41-06:00" level=debug msg="stored credentials not found" Feb 08 04:46:41 volumio go-librespot[14972]: time="2026-02-08T04:46:41-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 04:46:41 volumio go-librespot[14972]: time="2026-02-08T04:46:41-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]" Feb 08 04:46:41 volumio go-librespot[14972]: time="2026-02-08T04:46:41-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]" Feb 08 04:46:41 volumio go-librespot[14972]: time="2026-02-08T04:46:41-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]" Feb 08 04:46:41 volumio go-librespot[14972]: time="2026-02-08T04:46:41-06:00" level=info msg="zeroconf server listening on port 43425" Feb 08 04:46:41 volumio go-librespot[14972]: time="2026-02-08T04:46:41-06:00" level=debug msg="obtained new client token: AAA/AtlRrSJMBh8+l7xr9Qw0HX9a7fHFwme7Qy8gqYctyqcDLNY7iqyTlLMeNimiybjwIg24SXG0BJ/4AgjbZcSo4+260lna56rm9i/8iEJKu7djsWbSpdFy9FkPF8Q9fkPaxgesvJbo1B48JP/q59Pv/s1XRP9ej4Z4yad0AKvRcKoP9OJm6U5IBFErqspXBseMisW0VlDmehUppiE2RFflRSEPXwlAfwWjqvRP2C0gbqCAA1kDk9rvAA==" Feb 08 04:46:41 volumio go-librespot[14972]: time="2026-02-08T04:46:41-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 08 04:46:41 volumio go-librespot[14972]: time="2026-02-08T04:46:41-06:00" level=debug msg="completed keyexchange" Feb 08 04:46:41 volumio volumio[14476]: info: Getting Spotify volume Feb 08 04:46:41 volumio go-librespot[14972]: time="2026-02-08T04:46:41-06:00" level=debug msg="completed challenge" Feb 08 04:46:41 volumio volumio[14476]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Feb 08 04:46:41 volumio go-librespot[14972]: time="2026-02-08T04:46:41-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 " Feb 08 04:46:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 04:46:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 04:46:41 volumio volumio[14476]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 08 04:46:41 volumio volumio[14476]: Error: socket hang up Feb 08 04:46:41 volumio volumio[14476]: at connResetException (node:internal/errors:720:14) Feb 08 04:46:41 volumio volumio[14476]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 08 04:46:41 volumio volumio[14476]: at Socket.emit (node:events:526:35) Feb 08 04:46:41 volumio volumio[14476]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 08 04:46:41 volumio volumio[14476]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 08 04:46:41 volumio volumio[14476]: code: 'ECONNRESET', Feb 08 04:46:41 volumio volumio[14476]: response: undefined Feb 08 04:46:41 volumio volumio[14476]: } Feb 08 04:46:41 volumio volumio[14476]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 08 04:46:42 volumio sudo[14993]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-08 04:45' Feb 08 04:46:42 volumio sudo[14993]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 04:46:42 volumio kernel: hwmon hwmon1: Voltage normalised 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"