Feb 12 22:54:00 volumio volumio[29285]: info: Loading plugin "spop"... Feb 12 22:54:01 volumio volumio[29285]: info: Loading plugin "squeezelite_mc"... Feb 12 22:54:02 volumio volumio[29285]: info: Loading plugin "youtube2"... Feb 12 22:54:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 159. Feb 12 22:54:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:54:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:54:03 volumio go-librespot[29383]: go-librespot daemon starting... Feb 12 22:54:03 volumio go-librespot[29384]: time="2026-02-12T22:54:03-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 22:54:03 volumio go-librespot[29384]: time="2026-02-12T22:54:03-06:00" level=debug msg="app state loaded" Feb 12 22:54:03 volumio go-librespot[29384]: time="2026-02-12T22:54:03-06:00" level=debug msg="stored credentials not found" Feb 12 22:54:03 volumio go-librespot[29384]: time="2026-02-12T22:54:03-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 22:54:03 volumio go-librespot[29384]: time="2026-02-12T22:54:03-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 12 22:54:03 volumio go-librespot[29384]: time="2026-02-12T22:54:03-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 12 22:54:03 volumio go-librespot[29384]: time="2026-02-12T22:54:03-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 12 22:54:03 volumio go-librespot[29384]: time="2026-02-12T22:54:03-06:00" level=info msg="zeroconf server listening on port 34685" Feb 12 22:54:03 volumio go-librespot[29384]: time="2026-02-12T22:54:03-06:00" level=debug msg="obtained new client token: AACTeQhnUdmdoS9G9gujPBCZ7TsQaXxmKcgzLN2+fYpXxORoFfJq5F5liWC8OzGWhbXHqegFuSJg3nfY6lK1PGEHIGGxr6EXQ5v+2KQWtpHRpo3CjOeyDlVD3f7rFkOFvf0OueZWv451y2pt1hx/E30kV9VdCFxtXcSZ6gtKJyIAqNv9IpdXZEMV5CFo3XF/89+EIjRF4BlSARL0BxMNtxP+ZYZcs7miQEHakPKwA7C8Jl0W87/xvfo+aw==" Feb 12 22:54:03 volumio go-librespot[29384]: time="2026-02-12T22:54:03-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 22:54:03 volumio volumio[29285]: info: Loading plugin "ytcr"... Feb 12 22:54:03 volumio go-librespot[29384]: time="2026-02-12T22:54:03-06:00" level=debug msg="completed keyexchange" Feb 12 22:54:03 volumio go-librespot[29384]: time="2026-02-12T22:54:03-06:00" level=debug msg="completed challenge" Feb 12 22:54:03 volumio go-librespot[29384]: time="2026-02-12T22:54:03-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 22:54:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 22:54:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 22:54:05 volumio volumio[29285]: info: Loading plugin "ytmusic"... Feb 12 22:54:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 160. Feb 12 22:54:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:54:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:54:06 volumio go-librespot[29410]: go-librespot daemon starting... Feb 12 22:54:06 volumio go-librespot[29411]: time="2026-02-12T22:54:06-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 22:54:06 volumio go-librespot[29411]: time="2026-02-12T22:54:06-06:00" level=debug msg="app state loaded" Feb 12 22:54:06 volumio go-librespot[29411]: time="2026-02-12T22:54:06-06:00" level=debug msg="stored credentials not found" Feb 12 22:54:06 volumio go-librespot[29411]: time="2026-02-12T22:54:06-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 22:54:06 volumio volumio[29285]: info: Plugin now_playing is not enabled Feb 12 22:54:06 volumio volumio[29285]: info: Loading plugin "outputs"... Feb 12 22:54:06 volumio volumio[29285]: info: Loading plugin "albumart"... Feb 12 22:54:06 volumio volumio[29285]: info: Plugin example_plugin is not enabled Feb 12 22:54:06 volumio volumio[29285]: info: Loading plugin "inputs"... Feb 12 22:54:06 volumio volumio[29285]: info: Loading plugin "updater_comm"... Feb 12 22:54:06 volumio volumio-remote-updater[2265]: [2026-02-12 22:54:06] [connect] Successful connection Feb 12 22:54:07 volumio volumio[29285]: info: Plugin mpdemulation is not enabled Feb 12 22:54:07 volumio volumio[29285]: info: Loading plugin "rest_api"... Feb 12 22:54:07 volumio volumio[29285]: info: Loading plugin "websocket"... Feb 12 22:54:07 volumio volumio[29285]: info: Starting Socket.io Server version 1.7.4 Feb 12 22:54:07 volumio volumio[29285]: info: Plugin fusiondsp is not enabled Feb 12 22:54:07 volumio volumio[29285]: info: Plugin mpdoutput is not enabled Feb 12 22:54:07 volumio volumio[29285]: info: Plugin RoonBridge is not enabled Feb 12 22:54:07 volumio volumio[29285]: info: Loading plugin "podcast"... Feb 12 22:54:07 volumio go-librespot[29411]: time="2026-02-12T22:54: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 12 22:54:07 volumio go-librespot[29411]: time="2026-02-12T22:54:07-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 12 22:54:07 volumio go-librespot[29411]: time="2026-02-12T22:54:07-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 12 22:54:07 volumio go-librespot[29411]: time="2026-02-12T22:54:07-06:00" level=info msg="zeroconf server listening on port 35647" Feb 12 22:54:07 volumio go-librespot[29411]: time="2026-02-12T22:54:07-06:00" level=debug msg="obtained new client token: AAD9SDUF9uo9HFT8/rlMvAiLtO6JHbFxjl+w9lWmnbDS1s+a9xahn+3+RwtXQG0FwvABZ9WN72Ng+wZu0p9y3Lsrb4pUTbE98uHok8ntl1U0SMMRmiW7fQzdk00z+nxU6J4v0IJcfIc9UGi0BQC4lGW1nR11ItsQ4l9twjx9UHbavL4WoVN0VOhWnRpmhlrOUco+Ny987AD2KD237jhhkjuheEtyjP0G1n35rprlEs+Z08SLUq4Ea7w=" Feb 12 22:54:07 volumio volumio[29285]: info: ControllerPodcast::constructor Feb 12 22:54:07 volumio go-librespot[29411]: time="2026-02-12T22:54:07-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 22:54:07 volumio go-librespot[29411]: time="2026-02-12T22:54:07-06:00" level=debug msg="completed keyexchange" Feb 12 22:54:07 volumio go-librespot[29411]: time="2026-02-12T22:54:07-06:00" level=debug msg="completed challenge" Feb 12 22:54:07 volumio go-librespot[29411]: time="2026-02-12T22:54: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 12 22:54:07 volumio volumio[29285]: info: Loading plugin "volusonic"... Feb 12 22:54:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 22:54:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 22:54:07 volumio volumio[29417]: Forking 3 albumart workers Feb 12 22:54:09 volumio volumio[29285]: info: Applying required configuration parameters for plugin volusonic Feb 12 22:54:09 volumio volumio[29285]: info: Loading plugin "backup_restore"... Feb 12 22:54:10 volumio volumio[29429]: Starting albumart workers Feb 12 22:54:10 volumio volumio[29430]: Starting albumart workers Feb 12 22:54:10 volumio volumio[29428]: Starting albumart workers Feb 12 22:54:10 volumio volumio[29285]: info: Applying required configuration parameters for plugin backup_restore Feb 12 22:54:10 volumio volumio[29285]: info: Plugin rpi_eeprom_config is not enabled Feb 12 22:54:10 volumio volumio[29285]: info: Plugin rpi_eeprom_updater is not enabled Feb 12 22:54:10 volumio volumio[29285]: info: Loading plugin "scheduledrestart"... Feb 12 22:54:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 161. Feb 12 22:54:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:54:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:54:10 volumio go-librespot[29458]: go-librespot daemon starting... Feb 12 22:54:10 volumio go-librespot[29460]: time="2026-02-12T22:54:10-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 22:54:10 volumio go-librespot[29460]: time="2026-02-12T22:54:10-06:00" level=debug msg="app state loaded" Feb 12 22:54:10 volumio go-librespot[29460]: time="2026-02-12T22:54:10-06:00" level=debug msg="stored credentials not found" Feb 12 22:54:10 volumio go-librespot[29460]: time="2026-02-12T22:54:10-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 22:54:10 volumio volumio[29285]: info: Applying required configuration parameters for plugin scheduledrestart Feb 12 22:54:10 volumio volumio[29285]: info: Plugin Bluetoothremote is not enabled Feb 12 22:54:10 volumio volumio[29285]: info: Plugin music_services_shield is not enabled Feb 12 22:54:10 volumio volumio[29285]: info: Loading plugin "Systeminfo"... Feb 12 22:54:11 volumio go-librespot[29460]: time="2026-02-12T22:54:11-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 12 22:54:11 volumio go-librespot[29460]: time="2026-02-12T22:54:11-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 12 22:54:11 volumio go-librespot[29460]: time="2026-02-12T22:54:11-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 12 22:54:11 volumio go-librespot[29460]: time="2026-02-12T22:54:11-06:00" level=info msg="zeroconf server listening on port 37193" Feb 12 22:54:11 volumio go-librespot[29460]: time="2026-02-12T22:54:11-06:00" level=debug msg="obtained new client token: AADvMqU4/BmWa4gdtf4jANk+1mI+xxfSkUDPksA5Fsw46DVomV/d6rrGXC7hIisJ4sUp1w7TxX6pKwGrvYkMiU4IMBSkntdKQROOjIkrqeTHPySwSLD7Bb4/v9B7CfzDJf/d5fMRd/chBWe9SwjGCNt1WJ9//j7wxqwUDHx9Sm9B0afpQJLXN57YqWY+x+8kGw9rrXiKJC6NQsld9NLmuklcuQESbi0xLt79bIgTbE8m8SEiclZeTN0jrg==" Feb 12 22:54:11 volumio go-librespot[29460]: time="2026-02-12T22:54:11-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 22:54:11 volumio go-librespot[29460]: time="2026-02-12T22:54:11-06:00" level=debug msg="completed keyexchange" Feb 12 22:54:11 volumio go-librespot[29460]: time="2026-02-12T22:54:11-06:00" level=debug msg="completed challenge" Feb 12 22:54:11 volumio volumio[29285]: info: Plugin peppymeterbasic is not enabled Feb 12 22:54:11 volumio volumio[29285]: info: Loading plugin "peppyspectrum"... Feb 12 22:54:11 volumio go-librespot[29460]: time="2026-02-12T22:54: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 12 22:54:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 22:54:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 22:54:11 volumio volumio[29285]: info: Loading i18n strings for locale en Feb 12 22:54:11 volumio volumio[29285]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Feb 12 22:54:11 volumio volumio[29285]: Updating browse sources language Feb 12 22:54:11 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 22:54:11 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 22:54:11 volumio volumio[29285]: info: CoreCommandRouter::initPlayerControls Feb 12 22:54:11 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:11 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:11 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:11 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:11 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:11 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:11 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:11 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:12 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 22:54:12 volumio volumio[29285]: Express server listening on port 3000 Feb 12 22:54:12 volumio volumio[29285]: [Metrics] WebUI: 20s 615.28ms Feb 12 22:54:12 volumio volumio[29285]: info: CoreStateMachine::resetVolumioState Feb 12 22:54:12 volumio volumio[29285]: info: CoreStateMachine::getcurrentVolume Feb 12 22:54:12 volumio volumio[29285]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 22:54:12 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 22:54:12 volumio sudo[29491]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 12 22:54:12 volumio sudo[29491]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:12 volumio sudo[29491]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:12 volumio sudo[29493]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 12 22:54:12 volumio sudo[29493]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:12 volumio sudo[29493]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:12 volumio volumio[29285]: info: Volumio Network Manager: Network status updated: 1 Feb 12 22:54:12 volumio volumio[29285]: info: VolumeController:: Volume=100 Mute =false Feb 12 22:54:12 volumio volumio[29285]: info: CoreStateMachine::pushState Feb 12 22:54:12 volumio volumio[29285]: info: CorePlayQueue::getTrack 0 Feb 12 22:54:12 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 22:54:12 volumio volumio[29285]: info: CoreCommandRouter::volumioPushState Feb 12 22:54:12 volumio volumio[29285]: info: CoreStateMachine::updateTrackBlock Feb 12 22:54:12 volumio volumio[29285]: info: CorePlayQueue::getTrackBlock Feb 12 22:54:12 volumio volumio[29285]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 22:54:12 volumio volumio[29285]: info: Reloading queue from file Feb 12 22:54:12 volumio volumio[29285]: info: CoreStateMachine::setRepeat null single undefined Feb 12 22:54:12 volumio volumio[29285]: info: CoreStateMachine::pushState Feb 12 22:54:12 volumio volumio[29285]: info: CorePlayQueue::getTrack 0 Feb 12 22:54:12 volumio volumio[29285]: info: CoreCommandRouter::volumioPushState Feb 12 22:54:12 volumio volumio[29285]: info: CoreStateMachine::setRandom null Feb 12 22:54:12 volumio volumio[29285]: info: CoreStateMachine::pushState Feb 12 22:54:12 volumio volumio[29285]: info: CorePlayQueue::getTrack 0 Feb 12 22:54:12 volumio volumio[29285]: info: CoreCommandRouter::volumioPushState Feb 12 22:54:12 volumio volumio[29285]: info: Setting Device type: Raspberry PI Feb 12 22:54:12 volumio volumio[29285]: info: VolumeController:: Volume=100 Mute =false Feb 12 22:54:12 volumio volumio[29285]: info: CoreStateMachine::pushState Feb 12 22:54:12 volumio volumio[29285]: info: CorePlayQueue::getTrack 0 Feb 12 22:54:12 volumio volumio[29285]: info: CoreCommandRouter::volumioPushState Feb 12 22:54:12 volumio volumio[29285]: info: Completed loading Core Plugins Feb 12 22:54:12 volumio volumio[29285]: info: Preparing to generate the ALSA configuration file Feb 12 22:54:12 volumio sudo[29506]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 12 22:54:12 volumio sudo[29506]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:12 volumio volumio[29285]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Feb 12 22:54:12 volumio volumio[29285]: info: Discovery: Found device Volumio Feb 12 22:54:12 volumio volumio[29285]: info: CoreCommandRouter::volumioGetState Feb 12 22:54:12 volumio volumio[29285]: info: CorePlayQueue::getTrack 0 Feb 12 22:54:12 volumio volumio[29285]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Feb 12 22:54:12 volumio volumio[29285]: info: Discovery: Found device Volumio Feb 12 22:54:12 volumio volumio[29285]: info: CoreCommandRouter::volumioGetState Feb 12 22:54:12 volumio volumio[29285]: info: CorePlayQueue::getTrack 0 Feb 12 22:54:12 volumio volumio[29285]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Feb 12 22:54:12 volumio volumio[29285]: info: Reading ALSA contributions from plugins. Feb 12 22:54:12 volumio sudo[29506]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:12 volumio volumio[29285]: info: Asound.conf file unchanged, so no further update is needed Feb 12 22:54:12 volumio volumio[29285]: info: Output device has changed, restarting MPD Feb 12 22:54:12 volumio volumio[29285]: info: Output device has changed, restarting Shairport Sync Feb 12 22:54:12 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:12 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 22:54:12 volumio sudo[29509]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 22:54:12 volumio sudo[29509]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:12 volumio sudo[29511]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 22:54:12 volumio sudo[29511]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:12 volumio sudo[29509]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:12 volumio volumio[29285]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 22:54:12 volumio volumio[29285]: info: ___________ START PLUGINS ___________ Feb 12 22:54:12 volumio volumio[29285]: info: ControllerMpd::onStart: Initializing MPD Feb 12 22:54:12 volumio volumio[29285]: info: Creating MPD Configuration file Feb 12 22:54:12 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 12 22:54:12 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 22:54:12 volumio volumio[29285]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 22:54:12 volumio volumio[29285]: info: [1770958452580] CoreMusicLibrary::Adding element Media Servers Feb 12 22:54:12 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 22:54:12 volumio sudo[29519]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 22:54:12 volumio sudo[29519]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:12 volumio sudo[29521]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 22:54:12 volumio sudo[29521]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:12 volumio sudo[29519]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:12 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:12 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 22:54:12 volumio volumio[29285]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 22:54:12 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:12 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 22:54:12 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 12 22:54:12 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 12 22:54:12 volumio systemd[1]: mpd.service: Consumed 5.735s CPU time. Feb 12 22:54:12 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 12 22:54:12 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 12 22:54:12 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 12 22:54:12 volumio volumio[29285]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 22:54:12 volumio volumio[29285]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 22:54:12 volumio volumio[29285]: info: [1770958452686] CoreMusicLibrary::Adding element Last_100 Feb 12 22:54:12 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 22:54:12 volumio volumio[29285]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 22:54:12 volumio volumio[29285]: info: [1770958452691] CoreMusicLibrary::Adding element Webradio Feb 12 22:54:12 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 22:54:12 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 22:54:12 volumio volumio[29285]: info: Initializing BBC Radios Feb 12 22:54:12 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 22:54:12 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 12 22:54:12 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 22:54:12 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 12 22:54:12 volumio volumio[29285]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 22:54:12 volumio volumio[29285]: info: [1770958452762] CoreMusicLibrary::Adding element Bandcamp Discover Feb 12 22:54:12 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 22:54:12 volumio volumio[29285]: Cannot find translation for source Bandcamp Discover Feb 12 22:54:12 volumio volumio[29285]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 22:54:12 volumio volumio[29285]: info: [1770958452775] CoreMusicLibrary::Adding element SoundCloud Feb 12 22:54:12 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 22:54:12 volumio volumio[29285]: Cannot find translation for source Bandcamp Discover Feb 12 22:54:12 volumio volumio[29285]: Cannot find translation for source SoundCloud Feb 12 22:54:12 volumio volumio[29285]: info: Creating Spotify config file Feb 12 22:54:12 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:12 volumio sudo[29546]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 12 22:54:12 volumio sudo[29546]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 12 22:54:12 volumio sudo[29546]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:13 volumio volumio[29285]: info: [squeezelite_mc] Starting proxy server... Feb 12 22:54:13 volumio volumio[29285]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 22:54:13 volumio volumio[29285]: info: [1770958453158] CoreMusicLibrary::Adding element YouTube2 Feb 12 22:54:13 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 22:54:13 volumio volumio[29285]: Cannot find translation for source Bandcamp Discover Feb 12 22:54:13 volumio volumio[29285]: Cannot find translation for source SoundCloud Feb 12 22:54:13 volumio volumio[29285]: Cannot find translation for source YouTube2 Feb 12 22:54:13 volumio volumio[29285]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 22:54:13 volumio volumio[29285]: info: [1770958453177] CoreMusicLibrary::Adding element YouTube Music Feb 12 22:54:13 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 22:54:13 volumio volumio[29285]: Cannot find translation for source Bandcamp Discover Feb 12 22:54:13 volumio volumio[29285]: Cannot find translation for source SoundCloud Feb 12 22:54:13 volumio volumio[29285]: Cannot find translation for source YouTube2 Feb 12 22:54:13 volumio volumio[29285]: Cannot find translation for source YouTube Music Feb 12 22:54:13 volumio volumio[29285]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 22:54:13 volumio volumio[29285]: info: [1770958453188] CoreMusicLibrary::Adding element Podcast Feb 12 22:54:13 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 22:54:13 volumio volumio[29285]: Cannot find translation for source Bandcamp Discover Feb 12 22:54:13 volumio volumio[29285]: Cannot find translation for source SoundCloud Feb 12 22:54:13 volumio volumio[29285]: Cannot find translation for source YouTube2 Feb 12 22:54:13 volumio volumio[29285]: Cannot find translation for source YouTube Music Feb 12 22:54:13 volumio volumio[29285]: Cannot find translation for source Podcast Feb 12 22:54:13 volumio volumio[29285]: info: Loading i18n strings for locale en Feb 12 22:54:13 volumio volumio[29285]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Feb 12 22:54:13 volumio volumio[29285]: Updating browse sources language Feb 12 22:54:13 volumio volumio[29285]: Cannot find translation for source Bandcamp Discover Feb 12 22:54:13 volumio volumio[29285]: Cannot find translation for source SoundCloud Feb 12 22:54:13 volumio volumio[29285]: Cannot find translation for source YouTube2 Feb 12 22:54:13 volumio volumio[29285]: Cannot find translation for source YouTube Music Feb 12 22:54:13 volumio volumio[29285]: Cannot find translation for source Podcast Feb 12 22:54:13 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 22:54:13 volumio volumio[29285]: Cannot find translation for source Bandcamp Discover Feb 12 22:54:13 volumio volumio[29285]: Cannot find translation for source SoundCloud Feb 12 22:54:13 volumio volumio[29285]: Cannot find translation for source YouTube2 Feb 12 22:54:13 volumio volumio[29285]: Cannot find translation for source YouTube Music Feb 12 22:54:13 volumio volumio[29285]: Cannot find translation for source Podcast Feb 12 22:54:13 volumio volumio[29285]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 22:54:13 volumio volumio[29285]: info: [1770958453237] CoreMusicLibrary::Adding element Volusonic Feb 12 22:54:13 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 22:54:13 volumio volumio[29285]: Cannot find translation for source Bandcamp Discover Feb 12 22:54:13 volumio volumio[29285]: Cannot find translation for source SoundCloud Feb 12 22:54:13 volumio volumio[29285]: Cannot find translation for source YouTube2 Feb 12 22:54:13 volumio volumio[29285]: Cannot find translation for source YouTube Music Feb 12 22:54:13 volumio volumio[29285]: Cannot find translation for source Podcast Feb 12 22:54:13 volumio volumio[29285]: Cannot find translation for source Volusonic Feb 12 22:54:13 volumio volumio[29285]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Feb 12 22:54:13 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Feb 12 22:54:13 volumio volumio[29285]: info: Volumio Calling Home Feb 12 22:54:13 volumio volumio[29285]: info: [squeezelite_mc] Proxy server started on port 39829 Feb 12 22:54:13 volumio volumio[29285]: info: Preparing to generate the ALSA configuration file Feb 12 22:54:13 volumio volumio[29285]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 22:54:13 volumio volumio[29285]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Feb 12 22:54:13 volumio volumio[29285]: info: Reading ALSA contributions from plugins. Feb 12 22:54:13 volumio volumio[29285]: info: MPD Permissions set Feb 12 22:54:13 volumio volumio[29285]: info: MPD Permissions set Feb 12 22:54:13 volumio volumio[29285]: info: Upmpdcli Daemon Started Feb 12 22:54:13 volumio volumio[29285]: info: Spotify config file written Feb 12 22:54:13 volumio sudo[29556]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 12 22:54:13 volumio sudo[29556]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:13 volumio volumio[29285]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Feb 12 22:54:13 volumio volumio[29285]: info: VolumeController:: Volume=100 Mute =false Feb 12 22:54:13 volumio volumio[29285]: info: CoreStateMachine::pushState Feb 12 22:54:13 volumio volumio[29285]: info: CorePlayQueue::getTrack 0 Feb 12 22:54:13 volumio volumio[29285]: info: CoreCommandRouter::volumioPushState Feb 12 22:54:13 volumio volumio[29285]: info: [squeezelite_mc] Server discovery started Feb 12 22:54:13 volumio volumio[29285]: info: [squeezelite_mc] Player finder started Feb 12 22:54:13 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:13 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:13 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:13 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 22:54:13 volumio volumio[29285]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Feb 12 22:54:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:54:13 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:13 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:13 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:13 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:13 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:13 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:13 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:13 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:13 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 22:54:13 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:13 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:13 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:13 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:13 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:13 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:13 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:13 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:13 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:13 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 22:54:13 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:54:13 volumio go-librespot[29560]: go-librespot daemon starting... Feb 12 22:54:13 volumio volumio[29285]: info: No need to fix Spotify hosts Feb 12 22:54:13 volumio sudo[29556]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:13 volumio go-librespot[29571]: time="2026-02-12T22:54:13-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 22:54:13 volumio go-librespot[29571]: time="2026-02-12T22:54:13-06:00" level=debug msg="app state loaded" Feb 12 22:54:13 volumio go-librespot[29571]: time="2026-02-12T22:54:13-06:00" level=debug msg="stored credentials not found" Feb 12 22:54:13 volumio go-librespot[29571]: time="2026-02-12T22:54:13-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 22:54:13 volumio volumio[29285]: 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 12 22:54:13 volumio volumio[29285]: info: Volumio called home Feb 12 22:54:14 volumio volumio[29285]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Feb 12 22:54:14 volumio volumio[29285]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Feb 12 22:54:14 volumio volumio[29285]: 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 12 22:54:14 volumio go-librespot[29571]: time="2026-02-12T22:54: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-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 12 22:54:14 volumio go-librespot[29571]: time="2026-02-12T22:54:14-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 12 22:54:14 volumio go-librespot[29571]: time="2026-02-12T22:54:14-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 12 22:54:14 volumio volumio[29285]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 22:54:14 volumio volumio[29285]: SPOTIFY: BQDCwAztt_PT89KN1h0Z2JONkYSyyaQqgibNvrTA9k0YDqzLJANtw--5Ij13IWa5souivjZW1gRcijNwVi5VFN7rrCAx-eomnBgwtmZYQU7N-L5B2TBHAYvPsRc7iTCTqtukbZemQi3OCTSqzOFJ6JrYnxiSQlHUpqRCH20DjH00VNfhXGXYgvxXxWWmxt2AITxC1FwiRzxniuMcXGiAw7oO9Q_SA8mk7gtaOeA Feb 12 22:54:14 volumio volumio[29285]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 22:54:14 volumio volumio[29285]: info: New Spotify access token = BQDCwAztt_PT89KN1h0Z2JONkYSyyaQqgibNvrTA9k0YDqzLJANtw--5Ij13IWa5souivjZW1gRcijNwVi5VFN7rrCAx-eomnBgwtmZYQU7N-L5B2TBHAYvPsRc7iTCTqtukbZemQi3OCTSqzOFJ6JrYnxiSQlHUpqRCH20DjH00VNfhXGXYgvxXxWWmxt2AITxC1FwiRzxniuMcXGiAw7oO9Q_SA8mk7gtaOeA Feb 12 22:54:14 volumio volumio[29285]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 12 22:54:14 volumio go-librespot[29571]: time="2026-02-12T22:54:14-06:00" level=info msg="zeroconf server listening on port 35993" Feb 12 22:54:14 volumio sudo[29580]: 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 12 22:54:14 volumio sudo[29580]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:14 volumio volumio[29285]: info: Starting Shairport Sync Feb 12 22:54:14 volumio sudo[29580]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:14 volumio volumio[29285]: info: Starting Shairport Sync Feb 12 22:54:14 volumio volumio[29285]: info: Starting Shairport Sync Feb 12 22:54:14 volumio go-librespot[29571]: time="2026-02-12T22:54:14-06:00" level=debug msg="obtained new client token: AABubHbsyBaseoEGiHWLpdrN00uTiq+Mp1XIFK/eCwiNqngSw2Zy7rV4W6afviGxbfTw5QAjUN0Pqq/9GAgt0m03ZJB4zH5YfEFobM1uucs1pElvu70IqagDlpq86/8UanwGZ0tAGAEs5VtelxV8mDctBUx8qe1tCdcE28XnJhqHy4MQa50eDao8gLwV3Jk6t2+YtZ45WDCtaydTBHlcPe+VuYBBXuioVzRZ1thzGt7waZhyT2CJdfc=" Feb 12 22:54:14 volumio sudo[29591]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 22:54:14 volumio sudo[29591]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:14 volumio sudo[29596]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 22:54:14 volumio sudo[29596]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:14 volumio sudo[29600]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 22:54:14 volumio sudo[29600]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:14 volumio go-librespot[29571]: time="2026-02-12T22:54:14-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 22:54:14 volumio go-librespot[29571]: time="2026-02-12T22:54:14-06:00" level=debug msg="completed keyexchange" Feb 12 22:54:14 volumio go-librespot[29571]: time="2026-02-12T22:54:14-06:00" level=debug msg="completed challenge" Feb 12 22:54:14 volumio volumio[29285]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Feb 12 22:54:14 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 12 22:54:14 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 12 22:54:14 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 22:54:14 volumio go-librespot[29571]: time="2026-02-12T22:54: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 12 22:54:14 volumio systemd[1]: shairport-sync.service: Consumed 2.043s CPU time. Feb 12 22:54:14 volumio volumio[29285]: info: Asound.conf file unchanged, so no further update is needed Feb 12 22:54:14 volumio volumio[29285]: info: Output device has changed, restarting MPD Feb 12 22:54:14 volumio volumio[29285]: info: Output device has changed, restarting Shairport Sync Feb 12 22:54:14 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:14 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 22:54:14 volumio sudo[29609]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Feb 12 22:54:14 volumio sudo[29611]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 22:54:14 volumio sudo[29611]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:14 volumio sudo[29609]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:14 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 22:54:14 volumio sudo[29611]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 22:54:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 22:54:14 volumio sudo[29596]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:14 volumio sudo[29600]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:14 volumio sudo[29591]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:14 volumio sudo[29609]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:14 volumio sudo[29615]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 22:54:14 volumio sudo[29615]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:14 volumio volumio[29285]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 22:54:14 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 12 22:54:14 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 12 22:54:14 volumio systemd[1]: mpd.service: Consumed 1.696s CPU time. Feb 12 22:54:14 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 12 22:54:14 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 12 22:54:14 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 12 22:54:14 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 12 22:54:14 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 12 22:54:14 volumio volumio[29285]: info: MPD Permissions set Feb 12 22:54:14 volumio volumio[29285]: info: Shairport-Sync Started Feb 12 22:54:14 volumio volumio[29285]: Error adding Membership: Error: addMembership EINVAL Feb 12 22:54:14 volumio volumio[29285]: info: Shairport-Sync Started Feb 12 22:54:14 volumio volumio[29285]: 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 12 22:54:14 volumio volumio[29285]: info: Shairport-Sync Started Feb 12 22:54:14 volumio sudo[29642]: 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 12 22:54:14 volumio sudo[29642]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:14 volumio sudo[29642]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:14 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:14 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:14 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:14 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:14 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:14 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:14 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:14 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:14 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 22:54:14 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:14 volumio kernel: hwmon hwmon1: Voltage normalised Feb 12 22:54:14 volumio volumio[29285]: info: CoreCommandRouter::volumioGetState Feb 12 22:54:14 volumio volumio[29285]: info: CorePlayQueue::getTrack 0 Feb 12 22:54:14 volumio volumio[29285]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Feb 12 22:54:14 volumio volumio[29285]: info: Starting Shairport Sync Feb 12 22:54:14 volumio sudo[29651]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Feb 12 22:54:14 volumio sudo[29651]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:14 volumio sudo[29639]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 12 22:54:14 volumio sudo[29639]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 12 22:54:14 volumio sudo[29639]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:14 volumio sudo[29653]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 22:54:14 volumio sudo[29653]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:15 volumio volumio[29285]: 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 12 22:54:15 volumio volumio[29285]: info: Spotify Successfully logged in Feb 12 22:54:15 volumio volumio[29285]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 22:54:15 volumio volumio[29285]: info: [1770958455017] CoreMusicLibrary::Adding element Spotify Feb 12 22:54:15 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 22:54:15 volumio volumio[29285]: Cannot find translation for source Bandcamp Discover Feb 12 22:54:15 volumio volumio[29285]: Cannot find translation for source SoundCloud Feb 12 22:54:15 volumio volumio[29285]: Cannot find translation for source YouTube2 Feb 12 22:54:15 volumio volumio[29285]: Cannot find translation for source YouTube Music Feb 12 22:54:15 volumio volumio[29285]: Cannot find translation for source Podcast Feb 12 22:54:15 volumio volumio[29285]: Cannot find translation for source Volusonic Feb 12 22:54:15 volumio volumio[29285]: Cannot find translation for source Spotify Feb 12 22:54:15 volumio systemd[1]: Reloading. Feb 12 22:54:16 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:16 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:16 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:16 volumio volumio[29285]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 22:54:16 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 12 22:54:17 volumio volumio[29285]: info: go-librespot daemon successfully initialized Feb 12 22:54:17 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 12 22:54:17 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 12 22:54:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 162. Feb 12 22:54:18 volumio sudo[29651]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:18 volumio volumio[29285]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 22:54:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:54:18 volumio sudo[29676]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 22:54:18 volumio sudo[29676]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:54:18 volumio go-librespot[29677]: go-librespot daemon starting... Feb 12 22:54:18 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 12 22:54:18 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 12 22:54:18 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 22:54:18 volumio systemd[1]: shairport-sync.service: Consumed 1.465s CPU time. Feb 12 22:54:18 volumio go-librespot[29679]: time="2026-02-12T22:54:18-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 22:54:18 volumio go-librespot[29679]: time="2026-02-12T22:54:18-06:00" level=debug msg="app state loaded" Feb 12 22:54:18 volumio go-librespot[29679]: time="2026-02-12T22:54:18-06:00" level=debug msg="stored credentials not found" Feb 12 22:54:18 volumio go-librespot[29679]: time="2026-02-12T22:54:18-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 22:54:18 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 22:54:18 volumio sudo[29676]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:18 volumio sudo[29653]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:18 volumio volumio[29285]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Feb 12 22:54:18 volumio volumio[29285]: info: Shairport-Sync Started Feb 12 22:54:18 volumio sudo[29687]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Feb 12 22:54:18 volumio sudo[29687]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:18 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Feb 12 22:54:18 volumio systemd[1]: squeezelite.service: Deactivated successfully. Feb 12 22:54:18 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Feb 12 22:54:18 volumio go-librespot[29679]: time="2026-02-12T22:54: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 12 22:54:18 volumio go-librespot[29679]: time="2026-02-12T22:54:18-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 12 22:54:18 volumio go-librespot[29679]: time="2026-02-12T22:54:18-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 12 22:54:18 volumio sudo[29687]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:18 volumio go-librespot[29679]: time="2026-02-12T22:54:18-06:00" level=info msg="zeroconf server listening on port 37919" Feb 12 22:54:19 volumio go-librespot[29679]: time="2026-02-12T22:54:19-06:00" level=debug msg="obtained new client token: AABlfeIPqz1rTSjSJ6ZyZz3oqKFqUc3Fxcg25eglxOhCudyUB8gf1+/7EP9yQFV4aUpAf+0OyiejjBE8XEJBxni9QAATJVT+jDK2NYQRl0TXhQ/KNxLLMJEZFNoECaNQM3UXLJdT8R70t2Dt/VUZWzrFZG0qot5gFb62WcGZjW8S9SpGS0AVmZo/3492RzFdJhbuGBwwk7waJzHJDFpoAqtflXG0qA65F1tfmubomqprUPRba/jXYWI=" Feb 12 22:54:19 volumio go-librespot[29679]: time="2026-02-12T22:54:19-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 22:54:19 volumio go-librespot[29679]: time="2026-02-12T22:54:19-06:00" level=debug msg="completed keyexchange" Feb 12 22:54:19 volumio go-librespot[29679]: time="2026-02-12T22:54:19-06:00" level=debug msg="completed challenge" Feb 12 22:54:19 volumio go-librespot[29679]: time="2026-02-12T22:54:19-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 12 22:54:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 22:54:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 22:54:19 volumio volumio[29285]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 22:54:19 volumio sudo[29706]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 22:54:19 volumio sudo[29706]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:19 volumio sudo[29706]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:19 volumio volumio[29285]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Feb 12 22:54:19 volumio sudo[29710]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Feb 12 22:54:19 volumio sudo[29710]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:19 volumio sudo[29710]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:19 volumio volumio[29285]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Feb 12 22:54:19 volumio sudo[29713]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Feb 12 22:54:19 volumio sudo[29713]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:19 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Feb 12 22:54:19 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Feb 12 22:54:19 volumio sudo[29713]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:19 volumio mpd[29656]: 2026-02-12T22:54:19 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 12 22:54:20 volumio volumio[29285]: info: Initializing connection to go-librespot Websocket Feb 12 22:54:20 volumio volumio[29285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 22:54:20 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 12 22:54:20 volumio sudo[29521]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:20 volumio sudo[29511]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:20 volumio sudo[29615]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:20 volumio volumio[29285]: error: MPD error: The expression evaluated to a falsy value: Feb 12 22:54:20 volumio volumio[29285]: assert.ok(self.idling) Feb 12 22:54:20 volumio volumio[29285]: error: The expression evaluated to a falsy value: Feb 12 22:54:20 volumio volumio[29285]: assert.ok(self.idling) Feb 12 22:54:20 volumio volumio[29285]: error: MPD error: The expression evaluated to a falsy value: Feb 12 22:54:20 volumio volumio[29285]: assert.ok(self.idling) Feb 12 22:54:20 volumio volumio[29285]: error: The expression evaluated to a falsy value: Feb 12 22:54:20 volumio volumio[29285]: assert.ok(self.idling) Feb 12 22:54:20 volumio volumio[29285]: info: MPD running with PID29656 Feb 12 22:54:20 volumio volumio[29285]: ,establishing connection Feb 12 22:54:20 volumio volumio[29285]: error: updateQueue error: null Feb 12 22:54:20 volumio volumio[29285]: error: updateQueue error: null Feb 12 22:54:20 volumio volumio[29285]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 22:54:20 volumio sudo[29724]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 22:54:20 volumio sudo[29724]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:20 volumio sudo[29724]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:21 volumio volumio[29285]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 22:54:21 volumio sudo[29727]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 22:54:21 volumio sudo[29727]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:21 volumio kernel: hwmon hwmon1: Voltage normalised Feb 12 22:54:21 volumio sudo[29727]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:21 volumio volumio[29285]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 22:54:21 volumio sudo[29731]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 22:54:21 volumio sudo[29731]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:21 volumio sudo[29731]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:21 volumio volumio-remote-updater[2265]: [2026-02-12 22:54:21] [connect] Successful connection Feb 12 22:54:22 volumio volumio-remote-updater[2265]: [2026-02-12 22:54:21] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770958461 101 Feb 12 22:54:22 volumio volumio[29285]: 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: 3 Feb 12 22:54:22 volumio volumio[29285]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 22:54:22 volumio sudo[29734]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 22:54:22 volumio sudo[29734]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:22 volumio sudo[29734]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 163. Feb 12 22:54:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:54:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:54:22 volumio go-librespot[29736]: go-librespot daemon starting... Feb 12 22:54:22 volumio go-librespot[29737]: time="2026-02-12T22:54:22-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 22:54:22 volumio go-librespot[29737]: time="2026-02-12T22:54:22-06:00" level=debug msg="app state loaded" Feb 12 22:54:22 volumio go-librespot[29737]: time="2026-02-12T22:54:22-06:00" level=debug msg="stored credentials not found" Feb 12 22:54:22 volumio go-librespot[29737]: time="2026-02-12T22:54:22-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 22:54:22 volumio go-librespot[29737]: time="2026-02-12T22:54: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 12 22:54:22 volumio go-librespot[29737]: time="2026-02-12T22:54:22-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 12 22:54:22 volumio go-librespot[29737]: time="2026-02-12T22:54:22-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 12 22:54:22 volumio go-librespot[29737]: time="2026-02-12T22:54:22-06:00" level=info msg="zeroconf server listening on port 38803" Feb 12 22:54:22 volumio go-librespot[29737]: time="2026-02-12T22:54:22-06:00" level=debug msg="obtained new client token: AABwuURB+OA56BQPbRfKmxYsU5H9WKqRtEktFb9DnuqykYaABXolKEumwmxMok19jwws3pzJhrf0Zn9NLwyiqdcAxBUolhF0d4FxJkxDpYiDshFEIFAk0bgdkc/Mjb8rv/Q7v7qdprEqvejKpB7OJmAl2ZkM0toZ9oqRPBOD1YrtSSQGyja/vkMLzo1e3d+yi8kB1Bc4LBKwphcK5SM8pB9J1XKtn9OXIgFDp4xqbWDdhwkQhstZFLkZNg==" Feb 12 22:54:22 volumio go-librespot[29737]: time="2026-02-12T22:54:22-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 22:54:22 volumio volumio[29285]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 22:54:22 volumio go-librespot[29737]: time="2026-02-12T22:54:22-06:00" level=debug msg="completed keyexchange" Feb 12 22:54:22 volumio go-librespot[29737]: time="2026-02-12T22:54:22-06:00" level=debug msg="completed challenge" Feb 12 22:54:22 volumio sudo[29745]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 22:54:22 volumio sudo[29745]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:22 volumio go-librespot[29737]: time="2026-02-12T22:54: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 12 22:54:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 22:54:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 22:54:22 volumio sudo[29745]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:22 volumio volumio[29285]: info: Completed starting Core Plugins Feb 12 22:54:22 volumio volumio[29285]: info: ------------------------------------------- Feb 12 22:54:22 volumio volumio[29285]: info: ----- MyVolumio plugins startup ---- Feb 12 22:54:22 volumio volumio[29285]: info: ------------------------------------------- Feb 12 22:54:22 volumio volumio[29285]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 12 22:54:23 volumio volumio[29285]: info: Initializing connection to go-librespot Websocket Feb 12 22:54:23 volumio volumio[29285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 22:54:23 volumio sudo[29748]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 12 22:54:23 volumio sudo[29748]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:23 volumio sudo[29750]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 12 22:54:23 volumio sudo[29750]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:23 volumio sudo[29753]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 12 22:54:23 volumio sudo[29753]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:23 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 12 22:54:23 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 12 22:54:23 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 12 22:54:23 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 12 22:54:23 volumio mpd_monitor.sh[29756]: MPD Monitor Service: Starting MPD Monitor Service Feb 12 22:54:23 volumio sudo[29748]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:23 volumio sudo[29750]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:23 volumio sudo[29753]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:23 volumio volumio[29285]: info: Successfully started MPD Monitor Feb 12 22:54:23 volumio volumio[29285]: info: Successfully started MPD Monitor Feb 12 22:54:23 volumio volumio[29285]: info: Successfully started MPD Monitor Feb 12 22:54:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 164. Feb 12 22:54:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:54:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:54:26 volumio go-librespot[29774]: go-librespot daemon starting... Feb 12 22:54:26 volumio go-librespot[29775]: time="2026-02-12T22:54:26-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 22:54:26 volumio go-librespot[29775]: time="2026-02-12T22:54:26-06:00" level=debug msg="app state loaded" Feb 12 22:54:26 volumio go-librespot[29775]: time="2026-02-12T22:54:26-06:00" level=debug msg="stored credentials not found" Feb 12 22:54:26 volumio go-librespot[29775]: time="2026-02-12T22:54:26-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 22:54:26 volumio volumio[29285]: info: Initializing connection to go-librespot Websocket Feb 12 22:54:26 volumio go-librespot[29775]: time="2026-02-12T22:54:26-06:00" level=debug msg="new websocket client" Feb 12 22:54:26 volumio go-librespot[29775]: time="2026-02-12T22:54: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 12 22:54:26 volumio go-librespot[29775]: time="2026-02-12T22:54: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 12 22:54:26 volumio go-librespot[29775]: time="2026-02-12T22:54: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 12 22:54:26 volumio go-librespot[29775]: time="2026-02-12T22:54:26-06:00" level=info msg="zeroconf server listening on port 35123" Feb 12 22:54:26 volumio go-librespot[29775]: time="2026-02-12T22:54:26-06:00" level=debug msg="obtained new client token: AADSz6gUFNDcmz29skbk8AG/MezHYX2y1ZZmzB8hpO4KnLXiK4nHDxfXZYwWePk0a5nO6YBvZag+zDVvyfBnOizftV9WFNRrFXf5repD/DNK2RRJ7UBpcWz2ThTHuc62vAiptIjcgL8HRSo3XMbwfFX7WCJEEZZSUtVzLS5z5NKyv7qWi72D/idr5VwHfGNpzRNhYH1hxg3j/U/Wnj6/DdveGejvH+AjUMYkFaMf4jv024SHtUMpyGhtAA==" Feb 12 22:54:26 volumio go-librespot[29775]: time="2026-02-12T22:54:26-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 22:54:26 volumio go-librespot[29775]: time="2026-02-12T22:54:26-06:00" level=debug msg="completed keyexchange" Feb 12 22:54:26 volumio go-librespot[29775]: time="2026-02-12T22:54:26-06:00" level=debug msg="completed challenge" Feb 12 22:54:26 volumio go-librespot[29775]: time="2026-02-12T22:54: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 12 22:54:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 22:54:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 22:54:27 volumio volumio[29285]: info: Connection to go-librespot Websocket established Feb 12 22:54:27 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 12 22:54:27 volumio volumio[29285]: info: Connection to go-librespot Websocket closed Feb 12 22:54:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 165. Feb 12 22:54:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:54:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:54:30 volumio go-librespot[29783]: go-librespot daemon starting... Feb 12 22:54:30 volumio go-librespot[29784]: time="2026-02-12T22:54:30-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 22:54:30 volumio go-librespot[29784]: time="2026-02-12T22:54:30-06:00" level=debug msg="app state loaded" Feb 12 22:54:30 volumio go-librespot[29784]: time="2026-02-12T22:54:30-06:00" level=debug msg="stored credentials not found" Feb 12 22:54:30 volumio go-librespot[29784]: time="2026-02-12T22:54:30-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 22:54:30 volumio volumio[29285]: info: Getting Spotify volume Feb 12 22:54:30 volumio volumio[29285]: 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 12 22:54:30 volumio go-librespot[29784]: time="2026-02-12T22:54: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 22:54:30 volumio go-librespot[29784]: time="2026-02-12T22:54:30-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 12 22:54:30 volumio go-librespot[29784]: time="2026-02-12T22:54:30-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 12 22:54:30 volumio go-librespot[29784]: time="2026-02-12T22:54:30-06:00" level=info msg="zeroconf server listening on port 44567" Feb 12 22:54:30 volumio volumio[29285]: info: CoreCommandRouter::volumioGetState Feb 12 22:54:30 volumio volumio[29285]: info: CorePlayQueue::getTrack 0 Feb 12 22:54:30 volumio volumio[29285]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 12 22:54:30 volumio volumio[29285]: SPOTIFY: SPOTIFY VOLUME undefined Feb 12 22:54:30 volumio volumio[29285]: SPOTIFY: VOLUMIO VOLUME 100 Feb 12 22:54:30 volumio volumio[29285]: info: Aligning Spotify Volume to Volumio Volume Feb 12 22:54:30 volumio volumio[29285]: info: CoreCommandRouter::volumioGetState Feb 12 22:54:30 volumio volumio[29285]: info: CorePlayQueue::getTrack 0 Feb 12 22:54:30 volumio volumio[29285]: info: Setting Spotify Volume from Volumio: 100 Feb 12 22:54:30 volumio volumio[29285]: info: Initializing connection to go-librespot Websocket Feb 12 22:54:30 volumio go-librespot[29784]: time="2026-02-12T22:54:30-06:00" level=debug msg="new websocket client" Feb 12 22:54:30 volumio volumio[29285]: info: Connection to go-librespot Websocket established Feb 12 22:54:30 volumio go-librespot[29784]: time="2026-02-12T22:54:30-06:00" level=debug msg="obtained new client token: AADMYJdwA/DwPRkuhrO555Cb4b5zUd1AgKv/ItCaWxdKHxqJxmgKJkHvGnHnJhVSPdDLDIRnE6jSTtY46M9xcqaSXvru2Zq6ryjL+yCwYHK8+rDX2CKOVnHDdu1fNsO66o3HZsskpsxRSUNcA+nGf00PeJpI86ult5xMCp/eyE6XocrA81A7jv9GnDjy9FjOGaXW4QwoFjZoUFMw1lvJVe0qnAM2AtfH+cBI0jeiCN8yXaTJRDH4JyhMhg==" Feb 12 22:54:30 volumio go-librespot[29784]: time="2026-02-12T22:54:30-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 22:54:30 volumio go-librespot[29784]: time="2026-02-12T22:54:30-06:00" level=debug msg="completed keyexchange" Feb 12 22:54:30 volumio go-librespot[29784]: time="2026-02-12T22:54:30-06:00" level=debug msg="completed challenge" Feb 12 22:54:30 volumio go-librespot[29784]: time="2026-02-12T22:54: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 12 22:54:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 22:54:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 22:54:30 volumio volumio[29285]: info: Connection to go-librespot Websocket closed Feb 12 22:54:30 volumio volumio[29285]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 22:54:30 volumio volumio[29285]: Error: socket hang up Feb 12 22:54:30 volumio volumio[29285]: at connResetException (node:internal/errors:720:14) Feb 12 22:54:30 volumio volumio[29285]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 12 22:54:30 volumio volumio[29285]: at Socket.emit (node:events:526:35) Feb 12 22:54:30 volumio volumio[29285]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 12 22:54:30 volumio volumio[29285]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 12 22:54:30 volumio volumio[29285]: code: 'ECONNRESET', Feb 12 22:54:30 volumio volumio[29285]: response: undefined Feb 12 22:54:30 volumio volumio[29285]: } Feb 12 22:54:30 volumio volumio[29285]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 22:54:31 volumio sudo[29806]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-12 22:53' Feb 12 22:54:31 volumio sudo[29806]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:31 volumio kernel: hwmon hwmon1: Voltage normalised Feb 12 22:54:31 volumio sudo[29806]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:32 volumio volumio-remote-updater[2265]: [2026-02-12 22:54:32] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 12 22:54:32 volumio volumio-remote-updater[2265]: [2026-02-12 22:54:32] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 12 22:54:32 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 12 22:54:32 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 12 22:54:32 volumio systemd[1]: volumio.service: Consumed 53.954s CPU time. Feb 12 22:54:32 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 12 22:54:32 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 12 22:54:32 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 7067. Feb 12 22:54:32 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 12 22:54:32 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 12 22:54:32 volumio systemd[1]: volumio.service: Consumed 53.954s CPU time. Feb 12 22:54:32 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 12 22:54:32 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 12 22:54:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 166. Feb 12 22:54:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:54:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:54:33 volumio go-librespot[29843]: go-librespot daemon starting... Feb 12 22:54:33 volumio go-librespot[29844]: time="2026-02-12T22:54:33-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 22:54:33 volumio go-librespot[29844]: time="2026-02-12T22:54:33-06:00" level=debug msg="app state loaded" Feb 12 22:54:33 volumio go-librespot[29844]: time="2026-02-12T22:54:33-06:00" level=debug msg="stored credentials not found" Feb 12 22:54:33 volumio go-librespot[29844]: time="2026-02-12T22:54:33-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 22:54:34 volumio go-librespot[29844]: time="2026-02-12T22:54: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 12 22:54:34 volumio go-librespot[29844]: time="2026-02-12T22:54: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 12 22:54:34 volumio go-librespot[29844]: time="2026-02-12T22:54: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 12 22:54:34 volumio go-librespot[29844]: time="2026-02-12T22:54:34-06:00" level=info msg="zeroconf server listening on port 34263" Feb 12 22:54:34 volumio go-librespot[29844]: time="2026-02-12T22:54:34-06:00" level=debug msg="obtained new client token: AAAfxi+d+wAqySVGehvfXNmkX423XKSsh3Y58OlnH/zhpjgvKFdhTatJvb53Lnu0OYan6XbtsbtR6a8taxRfSP2sPldfIX19MQfw+rO5DB9tQCL5Ksr+9BvP4JzZm701bTmCjvIEdNWyTOZhXPvQB4VD/uHpnk9qzrevVl4a3yyFOduvKU0g5WvwRVmQ2bzoxSsvuKOIBKaC8mAfNt2Z3nxViI5UVFZ4fdbQKnfSmCX6t56rjhtvE4w=" Feb 12 22:54:34 volumio go-librespot[29844]: time="2026-02-12T22:54:34-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 22:54:34 volumio go-librespot[29844]: time="2026-02-12T22:54:34-06:00" level=debug msg="completed keyexchange" Feb 12 22:54:34 volumio go-librespot[29844]: time="2026-02-12T22:54:34-06:00" level=debug msg="completed challenge" Feb 12 22:54:34 volumio go-librespot[29844]: time="2026-02-12T22:54: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 12 22:54:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 22:54:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 22:54:34 volumio volumio[29828]: info: ------------------------------------------- Feb 12 22:54:34 volumio volumio[29828]: info: ----- Volumio3 ---- Feb 12 22:54:34 volumio volumio[29828]: info: ------------------------------------------- Feb 12 22:54:34 volumio volumio[29828]: info: ----- System startup ---- Feb 12 22:54:34 volumio volumio[29828]: info: ------------------------------------------- Feb 12 22:54:35 volumio volumio[29828]: info: MYVOLUMIO Environment detected Feb 12 22:54:35 volumio volumio[29828]: info: Plugin folders cleanup Feb 12 22:54:35 volumio volumio[29828]: info: Scanning into folder /volumio/app/plugins/ Feb 12 22:54:35 volumio volumio[29828]: info: Scanning category audio_interface Feb 12 22:54:35 volumio volumio[29828]: info: Scanning category miscellanea Feb 12 22:54:35 volumio volumio[29828]: info: Scanning category music_service Feb 12 22:54:35 volumio volumio[29828]: info: Scanning category plugins.json Feb 12 22:54:35 volumio volumio[29828]: info: Scanning category system_controller Feb 12 22:54:35 volumio volumio[29828]: info: Scanning category user_interface Feb 12 22:54:35 volumio volumio[29828]: info: Scanning into folder /data/plugins/ Feb 12 22:54:35 volumio volumio[29828]: info: Scanning category audio_interface Feb 12 22:54:35 volumio volumio[29828]: info: Scanning category music_service Feb 12 22:54:35 volumio volumio[29828]: info: Scanning category system_controller Feb 12 22:54:35 volumio volumio[29828]: info: Scanning category system_hardware Feb 12 22:54:35 volumio volumio[29828]: info: Scanning category user_interface Feb 12 22:54:35 volumio volumio[29828]: info: Plugin folders cleanup completed Feb 12 22:54:35 volumio volumio[29828]: info: ------------------------------------------- Feb 12 22:54:35 volumio volumio[29828]: info: ----- Core plugins startup ---- Feb 12 22:54:35 volumio volumio[29828]: info: ------------------------------------------- Feb 12 22:54:35 volumio volumio[29828]: info: Loading plugins from folder /volumio/app/plugins/ Feb 12 22:54:35 volumio volumio[29828]: info: Adding plugin upnp to MyMusic Plugins Feb 12 22:54:35 volumio volumio[29828]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 12 22:54:35 volumio volumio[29828]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 12 22:54:35 volumio volumio[29828]: info: Loading plugins from folder /data/plugins/ Feb 12 22:54:35 volumio volumio[29828]: info: Loading plugin "system"... Feb 12 22:54:35 volumio volumio[29828]: info: Loading plugin "appearance"... Feb 12 22:54:36 volumio volumio[29828]: info: Loading plugin "network"... Feb 12 22:54:36 volumio volumio[29828]: info: Refreshing Cached IP Addresses Feb 12 22:54:36 volumio sudo[29864]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 12 22:54:36 volumio sudo[29864]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:36 volumio sudo[29866]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 12 22:54:36 volumio sudo[29866]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:36 volumio sudo[29864]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:36 volumio volumio[29828]: info: Loading plugin "services"... Feb 12 22:54:36 volumio volumio[29828]: info: Loading plugin "alsa_controller"... Feb 12 22:54:36 volumio sudo[29866]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:36 volumio sudo[29874]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 12 22:54:36 volumio sudo[29874]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:36 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 22:54:36 volumio volumio[29828]: info: Loading plugin "wizard"... Feb 12 22:54:36 volumio volumio[29828]: info: Loading plugin "networkfs"... Feb 12 22:54:36 volumio volumio[29828]: info: Starting Udev Watcher for removable devices Feb 12 22:54:37 volumio volumio[29828]: info: Ignoring mount for partition: boot Feb 12 22:54:37 volumio volumio[29828]: info: Ignoring mount for partition: volumio Feb 12 22:54:37 volumio volumio[29828]: info: Ignoring mount for partition: volumio_data Feb 12 22:54:37 volumio volumio[29828]: info: Mounting Device Wikipedia Feb 12 22:54:37 volumio sudo[29903]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime Feb 12 22:54:37 volumio sudo[29903]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:37 volumio sudo[29903]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:37 volumio volumio[29828]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Feb 12 22:54:37 volumio volumio[29828]: dmesg(1) may have more information after failed mount system call. Feb 12 22:54:37 volumio volumio[29828]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime Feb 12 22:54:37 volumio volumio[29828]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Feb 12 22:54:37 volumio volumio[29828]: dmesg(1) may have more information after failed mount system call. Feb 12 22:54:37 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 22:54:37 volumio volumio[29828]: info: Loading plugin "volumio_command_line_client"... Feb 12 22:54:37 volumio volumio[29828]: info: Loading plugin "upnp"... Feb 12 22:54:37 volumio volumio[29828]: info: [1770958477179] Starting Upmpd Daemon Feb 12 22:54:37 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 22:54:37 volumio volumio[29828]: info: Loading plugin "my_music"... Feb 12 22:54:37 volumio volumio[29828]: info: Loading plugin "mpd"... Feb 12 22:54:37 volumio volumio-remote-updater[2265]: [2026-02-12 22:54:37] [connect] Successful connection Feb 12 22:54:37 volumio sudo[29874]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 167. Feb 12 22:54:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:54:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:54:37 volumio go-librespot[29905]: go-librespot daemon starting... Feb 12 22:54:37 volumio go-librespot[29906]: time="2026-02-12T22:54:37-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 22:54:37 volumio go-librespot[29906]: time="2026-02-12T22:54:37-06:00" level=debug msg="app state loaded" Feb 12 22:54:37 volumio go-librespot[29906]: time="2026-02-12T22:54:37-06:00" level=debug msg="stored credentials not found" Feb 12 22:54:37 volumio go-librespot[29906]: time="2026-02-12T22:54:37-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 22:54:37 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 12 22:54:37 volumio volumio[29828]: info: Loading plugin "upnp_browser"... Feb 12 22:54:38 volumio go-librespot[29906]: time="2026-02-12T22:54:38-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 22:54:38 volumio go-librespot[29906]: time="2026-02-12T22:54:38-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 22:54:38 volumio go-librespot[29906]: time="2026-02-12T22:54:38-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 22:54:38 volumio go-librespot[29906]: time="2026-02-12T22:54:38-06:00" level=info msg="zeroconf server listening on port 39713" Feb 12 22:54:38 volumio go-librespot[29906]: time="2026-02-12T22:54:38-06:00" level=debug msg="obtained new client token: AACmemPQc+AcN8xcSwL+JHOtwaHAhj2KapuU3hW4FinJbqeL6TAOJTuqeCYQGN7OX/HtskZIRG6sYE7hyqLLVp6Lp58SqSJvY2NF1QEATzmj4pFQUPECfZwFpOX2l29d83dFbklx/ZpnM0KpETgsZFqwj+CajvridaIIK8Bh2q0ZnGvEED8rplv2DNcTjqxDioW/At2UNZ113r+E4eDUvNxOLNUiwEu4qa3vnANQH6gDQc/mIlTrgdU=" Feb 12 22:54:38 volumio go-librespot[29906]: time="2026-02-12T22:54:38-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 22:54:38 volumio go-librespot[29906]: time="2026-02-12T22:54:38-06:00" level=debug msg="completed keyexchange" Feb 12 22:54:38 volumio go-librespot[29906]: time="2026-02-12T22:54:38-06:00" level=debug msg="completed challenge" Feb 12 22:54:38 volumio go-librespot[29906]: time="2026-02-12T22:54: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 12 22:54:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 22:54:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 22:54:40 volumio volumio[29828]: info: Loading plugin "alarm-clock"... Feb 12 22:54:40 volumio volumio[29828]: info: Loading plugin "airplay_emulation"... Feb 12 22:54:40 volumio volumio[29828]: info: Starting Shairport Sync Feb 12 22:54:40 volumio volumio[29828]: info: Loading plugin "last_100"... Feb 12 22:54:40 volumio volumio[29828]: info: Loading plugin "webradio"... Feb 12 22:54:40 volumio volumio[29828]: info: Loading plugin "i2s_dacs"... Feb 12 22:54:40 volumio volumio[29828]: info: I2S DAC not set, start Auto-detection Feb 12 22:54:40 volumio volumio[29828]: info: Loading plugin "volumiodiscovery"... Feb 12 22:54:40 volumio volumio[29828]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 12 22:54:40 volumio volumio[29828]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 22:54:40 volumio volumio[29828]: *** WARNING *** For more information see Feb 12 22:54:40 volumio volumio[29828]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 12 22:54:40 volumio volumio[29828]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 22:54:40 volumio volumio[29828]: *** WARNING *** For more information see Feb 12 22:54:40 volumio node[29828]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 12 22:54:40 volumio node[29828]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 22:54:40 volumio node[29828]: *** WARNING *** For more information see Feb 12 22:54:40 volumio node[29828]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 12 22:54:40 volumio node[29828]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 22:54:40 volumio node[29828]: *** WARNING *** For more information see Feb 12 22:54:40 volumio volumio[29828]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 12 22:54:40 volumio volumio[29828]: info: Discovery: Started advertising with name: Volumio Feb 12 22:54:40 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 22:54:40 volumio volumio[29828]: info: Loading plugin "bandcamp"... Feb 12 22:54:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 168. Feb 12 22:54:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:54:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:54:41 volumio go-librespot[29917]: go-librespot daemon starting... Feb 12 22:54:41 volumio go-librespot[29918]: time="2026-02-12T22:54:41-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 22:54:41 volumio go-librespot[29918]: time="2026-02-12T22:54:41-06:00" level=debug msg="app state loaded" Feb 12 22:54:41 volumio go-librespot[29918]: time="2026-02-12T22:54:41-06:00" level=debug msg="stored credentials not found" Feb 12 22:54:41 volumio go-librespot[29918]: time="2026-02-12T22:54:41-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 22:54:41 volumio go-librespot[29918]: time="2026-02-12T22:54: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 12 22:54:41 volumio go-librespot[29918]: time="2026-02-12T22:54: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 12 22:54:41 volumio go-librespot[29918]: time="2026-02-12T22:54: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 12 22:54:41 volumio go-librespot[29918]: time="2026-02-12T22:54:41-06:00" level=info msg="zeroconf server listening on port 43001" Feb 12 22:54:42 volumio go-librespot[29918]: time="2026-02-12T22:54:42-06:00" level=debug msg="obtained new client token: AABRGvbcqupDFEtdhlzPYZBfzrAVRUnhJHZi8JWjaSlBxBwuyG+UA/AD/0n+5XN1TzfyCfcDDMfIkWAmzM8VQbNdikBtt4TdoklIobAGKwVchEInK52nq5hoymVViHyzDgz6DOiP6EqrXxAdPEbEiaJfrxuzz/p1JAvOyZ+VNGNFOgHuOzdBeefvej+QAoTQWAsk0Vx1UjQoYayQtdVolToICsn+hOOoWOpab9gwIct/VFmuqXbybqE=" Feb 12 22:54:42 volumio go-librespot[29918]: time="2026-02-12T22:54:42-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 22:54:42 volumio go-librespot[29918]: time="2026-02-12T22:54:42-06:00" level=debug msg="completed keyexchange" Feb 12 22:54:42 volumio go-librespot[29918]: time="2026-02-12T22:54:42-06:00" level=debug msg="completed challenge" Feb 12 22:54:42 volumio go-librespot[29918]: time="2026-02-12T22:54: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 12 22:54:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 22:54:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 22:54:42 volumio volumio[29828]: info: Plugin calmradio is not enabled Feb 12 22:54:42 volumio volumio[29828]: info: Loading plugin "soundcloud"... Feb 12 22:54:42 volumio volumio[29828]: info: Loading plugin "spop"... Feb 12 22:54:43 volumio volumio[29828]: info: Loading plugin "squeezelite_mc"... Feb 12 22:54:43 volumio kernel: hwmon hwmon1: Voltage normalised Feb 12 22:54:44 volumio volumio[29828]: info: Loading plugin "youtube2"... Feb 12 22:54:44 volumio volumio[29828]: info: Loading plugin "ytcr"... Feb 12 22:54:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 169. Feb 12 22:54:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:54:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:54:45 volumio go-librespot[29930]: go-librespot daemon starting... Feb 12 22:54:45 volumio go-librespot[29931]: time="2026-02-12T22:54:45-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 22:54:45 volumio go-librespot[29931]: time="2026-02-12T22:54:45-06:00" level=debug msg="app state loaded" Feb 12 22:54:45 volumio go-librespot[29931]: time="2026-02-12T22:54:45-06:00" level=debug msg="stored credentials not found" Feb 12 22:54:45 volumio go-librespot[29931]: time="2026-02-12T22:54:45-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 22:54:45 volumio go-librespot[29931]: time="2026-02-12T22:54:45-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 12 22:54:45 volumio go-librespot[29931]: time="2026-02-12T22:54:45-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 12 22:54:45 volumio go-librespot[29931]: time="2026-02-12T22:54:45-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 12 22:54:45 volumio go-librespot[29931]: time="2026-02-12T22:54:45-06:00" level=info msg="zeroconf server listening on port 33263" Feb 12 22:54:45 volumio go-librespot[29931]: time="2026-02-12T22:54:45-06:00" level=debug msg="obtained new client token: AADYsgc5OICLb2hLo5V3WwIAo7nj+Dw5eg8N3jMj7MgB5tfOzL/pVEykNAc/HDfeof1aPa3hUVG0hyo4Ff+z5XrLB22642fOxtN0wdxDekwPPRABQgMK11BcG0ob7Hr/j28ORNhM+E0xQ6Vsn7sTqStzYYcphyhxo7+/FOa3uMaFVeiiEgcImSaUk1Tyfb1hPHK9fjw1tjk0FNo/ahijzXW56ME96pByqqbb0DRv/eDGj3ZTqkJtDnCUug==" Feb 12 22:54:45 volumio go-librespot[29931]: time="2026-02-12T22:54:45-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 22:54:45 volumio go-librespot[29931]: time="2026-02-12T22:54:45-06:00" level=debug msg="completed keyexchange" Feb 12 22:54:45 volumio go-librespot[29931]: time="2026-02-12T22:54:45-06:00" level=debug msg="completed challenge" Feb 12 22:54:45 volumio go-librespot[29931]: time="2026-02-12T22:54:45-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 12 22:54:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 22:54:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 22:54:46 volumio volumio[29828]: info: Loading plugin "ytmusic"... Feb 12 22:54:46 volumio volumio[29828]: info: Plugin now_playing is not enabled Feb 12 22:54:46 volumio volumio[29828]: info: Loading plugin "outputs"... Feb 12 22:54:46 volumio volumio[29828]: info: Loading plugin "albumart"... Feb 12 22:54:46 volumio volumio[29828]: info: Plugin example_plugin is not enabled Feb 12 22:54:46 volumio volumio[29828]: info: Loading plugin "inputs"... Feb 12 22:54:46 volumio volumio[29828]: info: Loading plugin "updater_comm"... Feb 12 22:54:46 volumio volumio[29828]: info: Plugin mpdemulation is not enabled Feb 12 22:54:46 volumio volumio[29828]: info: Loading plugin "rest_api"... Feb 12 22:54:46 volumio volumio[29828]: info: Loading plugin "websocket"... Feb 12 22:54:46 volumio volumio[29828]: info: Starting Socket.io Server version 1.7.4 Feb 12 22:54:46 volumio volumio[29828]: info: Plugin fusiondsp is not enabled Feb 12 22:54:46 volumio volumio[29828]: info: Plugin mpdoutput is not enabled Feb 12 22:54:46 volumio volumio[29828]: info: Plugin RoonBridge is not enabled Feb 12 22:54:46 volumio volumio[29828]: info: Loading plugin "podcast"... Feb 12 22:54:47 volumio volumio[29828]: info: ControllerPodcast::constructor Feb 12 22:54:47 volumio volumio[29828]: info: Loading plugin "volusonic"... Feb 12 22:54:47 volumio volumio[29938]: Forking 3 albumart workers Feb 12 22:54:48 volumio volumio[29828]: info: Applying required configuration parameters for plugin volusonic Feb 12 22:54:48 volumio volumio[29828]: info: Loading plugin "backup_restore"... Feb 12 22:54:48 volumio volumio[29963]: Starting albumart workers Feb 12 22:54:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 170. Feb 12 22:54:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:54:49 volumio volumio[29828]: info: Applying required configuration parameters for plugin backup_restore Feb 12 22:54:49 volumio volumio[29828]: info: Plugin rpi_eeprom_config is not enabled Feb 12 22:54:49 volumio volumio[29828]: info: Plugin rpi_eeprom_updater is not enabled Feb 12 22:54:49 volumio volumio[29828]: info: Loading plugin "scheduledrestart"... Feb 12 22:54:49 volumio volumio[29964]: Starting albumart workers Feb 12 22:54:49 volumio volumio[29962]: Starting albumart workers Feb 12 22:54:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:54:49 volumio go-librespot[29992]: go-librespot daemon starting... Feb 12 22:54:49 volumio go-librespot[29993]: time="2026-02-12T22:54:49-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 22:54:49 volumio go-librespot[29993]: time="2026-02-12T22:54:49-06:00" level=debug msg="app state loaded" Feb 12 22:54:49 volumio go-librespot[29993]: time="2026-02-12T22:54:49-06:00" level=debug msg="stored credentials not found" Feb 12 22:54:49 volumio go-librespot[29993]: time="2026-02-12T22:54:49-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 22:54:49 volumio volumio[29828]: info: Applying required configuration parameters for plugin scheduledrestart Feb 12 22:54:49 volumio volumio[29828]: info: Plugin Bluetoothremote is not enabled Feb 12 22:54:49 volumio volumio[29828]: info: Plugin music_services_shield is not enabled Feb 12 22:54:49 volumio volumio[29828]: info: Loading plugin "Systeminfo"... Feb 12 22:54:49 volumio go-librespot[29993]: time="2026-02-12T22:54:49-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 12 22:54:49 volumio go-librespot[29993]: time="2026-02-12T22:54:49-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 12 22:54:49 volumio go-librespot[29993]: time="2026-02-12T22:54:49-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 12 22:54:49 volumio go-librespot[29993]: time="2026-02-12T22:54:49-06:00" level=info msg="zeroconf server listening on port 46257" Feb 12 22:54:49 volumio go-librespot[29993]: time="2026-02-12T22:54:49-06:00" level=debug msg="obtained new client token: AAB2Qsbv4t1H+76ZeGtxYcEdf3FWzpyTBEDaqqrqcNc5e6PR7L+GBer9FqsiQN2+GNVCa/X3YKBE7G53IBFhlkGDhg2TQaYzjmPviPHpfD4WeWbr68wfeaCf8ZZPhZEoXFOB4ry0KIu3J5L6pHG3r7Eyrv5ALtopUWFR61ft4JoKk7Bv7RtenxhAya5cs5SZ53Uy3zZFTUlYtrBlv9tnUNLPpZoomjyD0yJJG6l1vkq9IkUS2KrzF8e3Ww==" Feb 12 22:54:50 volumio volumio-remote-updater[2265]: [2026-02-12 22:54:49] [connect] Successful connection Feb 12 22:54:50 volumio go-librespot[29993]: time="2026-02-12T22:54:50-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 22:54:50 volumio go-librespot[29993]: time="2026-02-12T22:54:50-06:00" level=debug msg="completed keyexchange" Feb 12 22:54:50 volumio go-librespot[29993]: time="2026-02-12T22:54:50-06:00" level=debug msg="completed challenge" Feb 12 22:54:50 volumio go-librespot[29993]: time="2026-02-12T22:54: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 12 22:54:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 22:54:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 22:54:50 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 12 22:54:50 volumio volumio[29828]: info: Plugin peppymeterbasic is not enabled Feb 12 22:54:50 volumio volumio[29828]: info: Loading plugin "peppyspectrum"... Feb 12 22:54:50 volumio volumio[29828]: info: Loading i18n strings for locale en Feb 12 22:54:50 volumio volumio[29828]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Feb 12 22:54:50 volumio volumio[29828]: Updating browse sources language Feb 12 22:54:50 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 22:54:51 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 22:54:51 volumio volumio[29828]: info: CoreCommandRouter::initPlayerControls Feb 12 22:54:51 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:51 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:51 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:51 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:51 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:51 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:51 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:51 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:51 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 22:54:51 volumio volumio[29828]: Express server listening on port 3000 Feb 12 22:54:51 volumio volumio[29828]: [Metrics] WebUI: 16s 896.23ms Feb 12 22:54:51 volumio volumio[29828]: info: CoreStateMachine::resetVolumioState Feb 12 22:54:51 volumio volumio[29828]: info: CoreStateMachine::getcurrentVolume Feb 12 22:54:51 volumio volumio[29828]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 22:54:51 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 22:54:51 volumio sudo[30025]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 12 22:54:51 volumio sudo[30025]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:51 volumio sudo[30025]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:51 volumio sudo[30027]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 12 22:54:51 volumio sudo[30027]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:51 volumio sudo[30027]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:51 volumio volumio[29828]: info: Volumio Network Manager: Network status updated: 1 Feb 12 22:54:51 volumio volumio[29828]: info: VolumeController:: Volume=100 Mute =false Feb 12 22:54:51 volumio volumio[29828]: info: CoreStateMachine::pushState Feb 12 22:54:51 volumio volumio[29828]: info: CorePlayQueue::getTrack 0 Feb 12 22:54:51 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 22:54:51 volumio volumio[29828]: info: CoreCommandRouter::volumioPushState Feb 12 22:54:51 volumio volumio[29828]: info: CoreStateMachine::updateTrackBlock Feb 12 22:54:51 volumio volumio[29828]: info: CorePlayQueue::getTrackBlock Feb 12 22:54:51 volumio volumio[29828]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 22:54:51 volumio volumio-remote-updater[2265]: [2026-02-12 22:54:51] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770958489 101 Feb 12 22:54:51 volumio volumio[29828]: 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 12 22:54:51 volumio volumio[29828]: info: Reloading queue from file Feb 12 22:54:51 volumio volumio[29828]: info: CoreStateMachine::setRepeat null single undefined Feb 12 22:54:51 volumio volumio[29828]: info: CoreStateMachine::pushState Feb 12 22:54:51 volumio volumio[29828]: info: CorePlayQueue::getTrack 0 Feb 12 22:54:51 volumio volumio[29828]: info: CoreCommandRouter::volumioPushState Feb 12 22:54:51 volumio volumio[29828]: info: CoreStateMachine::setRandom null Feb 12 22:54:51 volumio volumio[29828]: info: CoreStateMachine::pushState Feb 12 22:54:51 volumio volumio[29828]: info: CorePlayQueue::getTrack 0 Feb 12 22:54:51 volumio volumio[29828]: info: CoreCommandRouter::volumioPushState Feb 12 22:54:51 volumio volumio[29828]: info: Setting Device type: Raspberry PI Feb 12 22:54:51 volumio volumio[29828]: info: VolumeController:: Volume=100 Mute =false Feb 12 22:54:51 volumio volumio[29828]: info: CoreStateMachine::pushState Feb 12 22:54:51 volumio volumio[29828]: info: CorePlayQueue::getTrack 0 Feb 12 22:54:51 volumio volumio[29828]: info: CoreCommandRouter::volumioPushState Feb 12 22:54:51 volumio volumio[29828]: info: Completed loading Core Plugins Feb 12 22:54:51 volumio volumio[29828]: info: Preparing to generate the ALSA configuration file Feb 12 22:54:51 volumio sudo[30042]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 12 22:54:51 volumio sudo[30042]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:51 volumio volumio[29828]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Feb 12 22:54:51 volumio volumio[29828]: info: Discovery: Found device Volumio Feb 12 22:54:51 volumio volumio[29828]: info: CoreCommandRouter::volumioGetState Feb 12 22:54:51 volumio volumio[29828]: info: CorePlayQueue::getTrack 0 Feb 12 22:54:52 volumio volumio[29828]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Feb 12 22:54:52 volumio volumio[29828]: info: Discovery: Found device Volumio Feb 12 22:54:52 volumio volumio[29828]: info: CoreCommandRouter::volumioGetState Feb 12 22:54:52 volumio volumio[29828]: info: CorePlayQueue::getTrack 0 Feb 12 22:54:52 volumio volumio[29828]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Feb 12 22:54:52 volumio volumio[29828]: info: Reading ALSA contributions from plugins. Feb 12 22:54:52 volumio sudo[30042]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:52 volumio volumio[29828]: info: Asound.conf file unchanged, so no further update is needed Feb 12 22:54:52 volumio volumio[29828]: info: Output device has changed, restarting MPD Feb 12 22:54:52 volumio volumio[29828]: info: Output device has changed, restarting Shairport Sync Feb 12 22:54:52 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:52 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 22:54:52 volumio sudo[30045]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 22:54:52 volumio sudo[30045]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:52 volumio sudo[30045]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:52 volumio sudo[30047]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 22:54:52 volumio sudo[30047]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:52 volumio volumio[29828]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 22:54:52 volumio volumio[29828]: info: ___________ START PLUGINS ___________ Feb 12 22:54:52 volumio volumio[29828]: info: ControllerMpd::onStart: Initializing MPD Feb 12 22:54:52 volumio volumio[29828]: info: Creating MPD Configuration file Feb 12 22:54:52 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 22:54:52 volumio volumio[29828]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 22:54:52 volumio volumio[29828]: info: [1770958492198] CoreMusicLibrary::Adding element Media Servers Feb 12 22:54:52 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 22:54:52 volumio sudo[30055]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 22:54:52 volumio sudo[30055]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:52 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 12 22:54:52 volumio sudo[30055]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:52 volumio sudo[30057]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 22:54:52 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:52 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 22:54:52 volumio sudo[30057]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:52 volumio volumio[29828]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 22:54:52 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:52 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 22:54:52 volumio volumio[29828]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 22:54:52 volumio volumio[29828]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 22:54:52 volumio volumio[29828]: info: [1770958492381] CoreMusicLibrary::Adding element Last_100 Feb 12 22:54:52 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 22:54:52 volumio volumio[29828]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 22:54:52 volumio volumio[29828]: info: [1770958492398] CoreMusicLibrary::Adding element Webradio Feb 12 22:54:52 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 22:54:52 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 22:54:52 volumio volumio[29828]: info: Initializing BBC Radios Feb 12 22:54:52 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 12 22:54:52 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 12 22:54:52 volumio systemd[1]: mpd.service: Consumed 5.697s CPU time. Feb 12 22:54:52 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 12 22:54:52 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 12 22:54:52 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 12 22:54:52 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 12 22:54:52 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 22:54:52 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 22:54:52 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 12 22:54:52 volumio volumio[29828]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 22:54:52 volumio volumio[29828]: info: [1770958492527] CoreMusicLibrary::Adding element Bandcamp Discover Feb 12 22:54:52 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 22:54:52 volumio volumio[29828]: Cannot find translation for source Bandcamp Discover Feb 12 22:54:52 volumio volumio[29828]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 22:54:52 volumio volumio[29828]: info: [1770958492540] CoreMusicLibrary::Adding element SoundCloud Feb 12 22:54:52 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 22:54:52 volumio volumio[29828]: Cannot find translation for source Bandcamp Discover Feb 12 22:54:52 volumio volumio[29828]: Cannot find translation for source SoundCloud Feb 12 22:54:52 volumio volumio[29828]: info: Creating Spotify config file Feb 12 22:54:52 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:52 volumio sudo[30082]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 12 22:54:52 volumio sudo[30082]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 12 22:54:52 volumio sudo[30082]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:52 volumio volumio[29828]: info: [squeezelite_mc] Starting proxy server... Feb 12 22:54:52 volumio volumio[29828]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 22:54:52 volumio volumio[29828]: info: [1770958492901] CoreMusicLibrary::Adding element YouTube2 Feb 12 22:54:52 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 22:54:52 volumio volumio[29828]: Cannot find translation for source Bandcamp Discover Feb 12 22:54:52 volumio volumio[29828]: Cannot find translation for source SoundCloud Feb 12 22:54:52 volumio volumio[29828]: Cannot find translation for source YouTube2 Feb 12 22:54:52 volumio volumio[29828]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 22:54:52 volumio volumio[29828]: info: [1770958492919] CoreMusicLibrary::Adding element YouTube Music Feb 12 22:54:52 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 22:54:52 volumio volumio[29828]: Cannot find translation for source Bandcamp Discover Feb 12 22:54:52 volumio volumio[29828]: Cannot find translation for source SoundCloud Feb 12 22:54:52 volumio volumio[29828]: Cannot find translation for source YouTube2 Feb 12 22:54:52 volumio volumio[29828]: Cannot find translation for source YouTube Music Feb 12 22:54:52 volumio volumio[29828]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 22:54:52 volumio volumio[29828]: info: [1770958492931] CoreMusicLibrary::Adding element Podcast Feb 12 22:54:52 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 22:54:52 volumio volumio[29828]: Cannot find translation for source Bandcamp Discover Feb 12 22:54:52 volumio volumio[29828]: Cannot find translation for source SoundCloud Feb 12 22:54:52 volumio volumio[29828]: Cannot find translation for source YouTube2 Feb 12 22:54:52 volumio volumio[29828]: Cannot find translation for source YouTube Music Feb 12 22:54:52 volumio volumio[29828]: Cannot find translation for source Podcast Feb 12 22:54:52 volumio volumio[29828]: info: Loading i18n strings for locale en Feb 12 22:54:52 volumio volumio[29828]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Feb 12 22:54:52 volumio volumio[29828]: Updating browse sources language Feb 12 22:54:52 volumio volumio[29828]: Cannot find translation for source Bandcamp Discover Feb 12 22:54:52 volumio volumio[29828]: Cannot find translation for source SoundCloud Feb 12 22:54:52 volumio volumio[29828]: Cannot find translation for source YouTube2 Feb 12 22:54:52 volumio volumio[29828]: Cannot find translation for source YouTube Music Feb 12 22:54:52 volumio volumio[29828]: Cannot find translation for source Podcast Feb 12 22:54:52 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 22:54:52 volumio volumio[29828]: Cannot find translation for source Bandcamp Discover Feb 12 22:54:52 volumio volumio[29828]: Cannot find translation for source SoundCloud Feb 12 22:54:52 volumio volumio[29828]: Cannot find translation for source YouTube2 Feb 12 22:54:52 volumio volumio[29828]: Cannot find translation for source YouTube Music Feb 12 22:54:52 volumio volumio[29828]: Cannot find translation for source Podcast Feb 12 22:54:52 volumio volumio[29828]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 22:54:52 volumio volumio[29828]: info: [1770958492987] CoreMusicLibrary::Adding element Volusonic Feb 12 22:54:52 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 22:54:52 volumio volumio[29828]: Cannot find translation for source Bandcamp Discover Feb 12 22:54:52 volumio volumio[29828]: Cannot find translation for source SoundCloud Feb 12 22:54:52 volumio volumio[29828]: Cannot find translation for source YouTube2 Feb 12 22:54:52 volumio volumio[29828]: Cannot find translation for source YouTube Music Feb 12 22:54:52 volumio volumio[29828]: Cannot find translation for source Podcast Feb 12 22:54:52 volumio volumio[29828]: Cannot find translation for source Volusonic Feb 12 22:54:53 volumio volumio[29828]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Feb 12 22:54:53 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Feb 12 22:54:53 volumio volumio[29828]: info: Volumio Calling Home Feb 12 22:54:53 volumio volumio[29828]: info: [squeezelite_mc] Proxy server started on port 38363 Feb 12 22:54:53 volumio volumio[29828]: info: Preparing to generate the ALSA configuration file Feb 12 22:54:53 volumio volumio[29828]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 22:54:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 171. Feb 12 22:54:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:54:53 volumio volumio[29828]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Feb 12 22:54:53 volumio volumio[29828]: info: Reading ALSA contributions from plugins. Feb 12 22:54:53 volumio volumio[29828]: info: MPD Permissions set Feb 12 22:54:53 volumio volumio[29828]: info: MPD Permissions set Feb 12 22:54:53 volumio volumio[29828]: info: Upmpdcli Daemon Started Feb 12 22:54:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:54:53 volumio volumio[29828]: info: Spotify config file written Feb 12 22:54:53 volumio go-librespot[30089]: go-librespot daemon starting... Feb 12 22:54:53 volumio go-librespot[30093]: time="2026-02-12T22:54:53-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 22:54:53 volumio go-librespot[30093]: time="2026-02-12T22:54:53-06:00" level=debug msg="app state loaded" Feb 12 22:54:53 volumio go-librespot[30093]: time="2026-02-12T22:54:53-06:00" level=debug msg="stored credentials not found" Feb 12 22:54:53 volumio go-librespot[30093]: time="2026-02-12T22:54:53-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 22:54:53 volumio sudo[30094]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 12 22:54:53 volumio sudo[30094]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:53 volumio volumio[29828]: 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 12 22:54:53 volumio volumio[29828]: info: VolumeController:: Volume=100 Mute =false Feb 12 22:54:53 volumio volumio[29828]: info: CoreStateMachine::pushState Feb 12 22:54:53 volumio volumio[29828]: info: CorePlayQueue::getTrack 0 Feb 12 22:54:53 volumio volumio[29828]: info: CoreCommandRouter::volumioPushState Feb 12 22:54:53 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 12 22:54:53 volumio volumio[29828]: info: [squeezelite_mc] Server discovery started Feb 12 22:54:53 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 12 22:54:53 volumio volumio[29828]: info: [squeezelite_mc] Player finder started Feb 12 22:54:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:54:53 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:53 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:53 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:53 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 22:54:53 volumio volumio[29828]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Feb 12 22:54:53 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:53 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:53 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:53 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:53 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:53 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:53 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:53 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:53 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 22:54:53 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:53 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:53 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:53 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:53 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:53 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:53 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:53 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:53 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:54:53 volumio go-librespot[30101]: go-librespot daemon starting... Feb 12 22:54:53 volumio sudo[30094]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:53 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 22:54:53 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:53 volumio go-librespot[30111]: time="2026-02-12T22:54:53-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 22:54:53 volumio go-librespot[30111]: time="2026-02-12T22:54:53-06:00" level=debug msg="app state loaded" Feb 12 22:54:53 volumio go-librespot[30111]: time="2026-02-12T22:54:53-06:00" level=debug msg="stored credentials not found" Feb 12 22:54:53 volumio volumio[29828]: info: No need to fix Spotify hosts Feb 12 22:54:53 volumio go-librespot[30111]: time="2026-02-12T22:54:53-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 22:54:53 volumio volumio[29828]: 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 12 22:54:53 volumio volumio[29828]: info: Volumio called home Feb 12 22:54:53 volumio volumio[29828]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Feb 12 22:54:53 volumio volumio[29828]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Feb 12 22:54:53 volumio volumio[29828]: 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 12 22:54:53 volumio go-librespot[30111]: time="2026-02-12T22:54:53-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 12 22:54:53 volumio go-librespot[30111]: time="2026-02-12T22:54:53-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 12 22:54:53 volumio go-librespot[30111]: time="2026-02-12T22:54:53-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 12 22:54:53 volumio volumio[29828]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 22:54:53 volumio volumio[29828]: SPOTIFY: BQC_LhgKj5ihUeN2bSWiNII-IE2lheSnbMNUOdNc9R1I9rGUVVOTRW9hz_pfqtgxPLuaNc5pw3M4ueOOmDi8T5V01OnY4JtzSE-g5MLaB8c_ybCAqHN1T3qZ8ipb5aclvXnyx8xO3xMR6pDOgLraHkrfxOb1zwpi-RFWGzldeXytj7FoJY1CrZ_k1uJFpwTN8HYKaVZYxz5IlFTxbUggwXrGYuvPc_j4lgQ_K5U Feb 12 22:54:53 volumio volumio[29828]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 22:54:53 volumio volumio[29828]: info: New Spotify access token = BQC_LhgKj5ihUeN2bSWiNII-IE2lheSnbMNUOdNc9R1I9rGUVVOTRW9hz_pfqtgxPLuaNc5pw3M4ueOOmDi8T5V01OnY4JtzSE-g5MLaB8c_ybCAqHN1T3qZ8ipb5aclvXnyx8xO3xMR6pDOgLraHkrfxOb1zwpi-RFWGzldeXytj7FoJY1CrZ_k1uJFpwTN8HYKaVZYxz5IlFTxbUggwXrGYuvPc_j4lgQ_K5U Feb 12 22:54:53 volumio volumio[29828]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 12 22:54:53 volumio go-librespot[30111]: time="2026-02-12T22:54:53-06:00" level=info msg="zeroconf server listening on port 42317" Feb 12 22:54:53 volumio volumio[29828]: info: Starting Shairport Sync Feb 12 22:54:53 volumio volumio[29828]: info: Starting Shairport Sync Feb 12 22:54:53 volumio volumio[29828]: info: Starting Shairport Sync Feb 12 22:54:53 volumio sudo[30128]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 22:54:53 volumio sudo[30128]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:54 volumio go-librespot[30111]: time="2026-02-12T22:54:54-06:00" level=debug msg="obtained new client token: AADuhzhkvRLtESbgqxrPKAd+OrHDLV6yWK2Tfz5RfLSJm/bqPRXeGvoKGbZ01dMgVoRHFFHBjF71eQu0I6Tr91FLW7K36AhisEWjE4Gi1S1y4kNpY1XC4OM/LCh2+eFxGXbRtCPRQ4qyULg+R951eiRhHPqfOsmAitfWtj2EbXXduDshwPUWK+YjQWARSmwWlOidCI6ftT0eL9GYgiDcRDwrwF5BrEZ3JUcy67xOBBiywLk1p5FMM3fsAA==" Feb 12 22:54:54 volumio sudo[30124]: 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 12 22:54:54 volumio sudo[30124]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:54 volumio sudo[30131]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 22:54:54 volumio sudo[30131]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:54 volumio sudo[30129]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 22:54:54 volumio sudo[30129]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:54 volumio sudo[30124]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:54 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 12 22:54:54 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 12 22:54:54 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 22:54:54 volumio systemd[1]: shairport-sync.service: Consumed 2.010s CPU time. Feb 12 22:54:54 volumio go-librespot[30111]: time="2026-02-12T22:54:54-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 22:54:54 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 22:54:54 volumio volumio[29828]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Feb 12 22:54:54 volumio go-librespot[30111]: time="2026-02-12T22:54:54-06:00" level=debug msg="completed keyexchange" Feb 12 22:54:54 volumio go-librespot[30111]: time="2026-02-12T22:54:54-06:00" level=debug msg="completed challenge" Feb 12 22:54:54 volumio volumio[29828]: info: Asound.conf file unchanged, so no further update is needed Feb 12 22:54:54 volumio volumio[29828]: info: Output device has changed, restarting MPD Feb 12 22:54:54 volumio sudo[30139]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Feb 12 22:54:54 volumio sudo[30139]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:54 volumio go-librespot[30111]: time="2026-02-12T22:54: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 12 22:54:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 22:54:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 22:54:54 volumio sudo[30139]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:54 volumio sudo[30128]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:54 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 12 22:54:54 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 12 22:54:54 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 22:54:54 volumio sudo[30142]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 22:54:54 volumio volumio[29828]: info: Output device has changed, restarting Shairport Sync Feb 12 22:54:54 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:54 volumio sudo[30142]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:54 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 22:54:54 volumio sudo[30142]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:54 volumio sudo[30157]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 22:54:54 volumio sudo[30157]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:54 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 22:54:54 volumio volumio[29828]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 22:54:54 volumio sudo[30131]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:54 volumio sudo[30129]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:54 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 12 22:54:54 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 12 22:54:54 volumio systemd[1]: mpd.service: Consumed 1.721s CPU time. Feb 12 22:54:54 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 12 22:54:54 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 12 22:54:54 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 12 22:54:54 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 12 22:54:54 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 12 22:54:54 volumio volumio[29828]: info: MPD Permissions set Feb 12 22:54:54 volumio volumio[29828]: info: Shairport-Sync Started Feb 12 22:54:54 volumio volumio[29828]: Error adding Membership: Error: addMembership EINVAL Feb 12 22:54:54 volumio volumio[29828]: info: Shairport-Sync Started Feb 12 22:54:54 volumio volumio[29828]: info: Shairport-Sync Started Feb 12 22:54:54 volumio volumio[29828]: 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 12 22:54:54 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:54 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:54 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:54 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:54 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:54 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:54 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:54 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:54 volumio sudo[30187]: 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 12 22:54:54 volumio sudo[30187]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:54 volumio sudo[30187]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:54 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 22:54:54 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:54 volumio volumio[29828]: info: CoreCommandRouter::volumioGetState Feb 12 22:54:54 volumio volumio[29828]: info: CorePlayQueue::getTrack 0 Feb 12 22:54:54 volumio volumio[29828]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Feb 12 22:54:54 volumio sudo[30184]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 12 22:54:54 volumio sudo[30184]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 12 22:54:54 volumio sudo[30184]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:54 volumio volumio[29828]: info: Starting Shairport Sync Feb 12 22:54:54 volumio sudo[30195]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Feb 12 22:54:54 volumio sudo[30195]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:54 volumio sudo[30200]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 22:54:54 volumio sudo[30200]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:54 volumio volumio[29828]: 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 12 22:54:54 volumio volumio[29828]: info: Spotify Successfully logged in Feb 12 22:54:54 volumio volumio[29828]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 22:54:54 volumio volumio[29828]: info: [1770958494846] CoreMusicLibrary::Adding element Spotify Feb 12 22:54:54 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 22:54:54 volumio volumio[29828]: Cannot find translation for source Bandcamp Discover Feb 12 22:54:54 volumio volumio[29828]: Cannot find translation for source SoundCloud Feb 12 22:54:54 volumio volumio[29828]: Cannot find translation for source YouTube2 Feb 12 22:54:54 volumio volumio[29828]: Cannot find translation for source YouTube Music Feb 12 22:54:54 volumio volumio[29828]: Cannot find translation for source Podcast Feb 12 22:54:54 volumio volumio[29828]: Cannot find translation for source Volusonic Feb 12 22:54:54 volumio volumio[29828]: Cannot find translation for source Spotify Feb 12 22:54:54 volumio systemd[1]: Reloading. Feb 12 22:54:55 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:55 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:55 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:54:55 volumio volumio[29828]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 22:54:56 volumio volumio[29828]: info: go-librespot daemon successfully initialized Feb 12 22:54:57 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 12 22:54:57 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 12 22:54:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 12 22:54:58 volumio sudo[30195]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:58 volumio volumio[29828]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 22:54:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:54:58 volumio sudo[30234]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 22:54:58 volumio sudo[30234]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:54:58 volumio go-librespot[30235]: go-librespot daemon starting... Feb 12 22:54:58 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 12 22:54:58 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 12 22:54:58 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 22:54:58 volumio systemd[1]: shairport-sync.service: Consumed 1.584s CPU time. Feb 12 22:54:58 volumio go-librespot[30237]: time="2026-02-12T22:54:58-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 22:54:58 volumio go-librespot[30237]: time="2026-02-12T22:54:58-06:00" level=debug msg="app state loaded" Feb 12 22:54:58 volumio go-librespot[30237]: time="2026-02-12T22:54:58-06:00" level=debug msg="stored credentials not found" Feb 12 22:54:58 volumio go-librespot[30237]: time="2026-02-12T22:54:58-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 22:54:58 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 22:54:58 volumio sudo[30200]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:58 volumio volumio[29828]: info: Shairport-Sync Started Feb 12 22:54:58 volumio sudo[30234]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:58 volumio volumio[29828]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Feb 12 22:54:58 volumio sudo[30246]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Feb 12 22:54:58 volumio sudo[30246]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:58 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Feb 12 22:54:58 volumio go-librespot[30237]: time="2026-02-12T22:54:58-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 12 22:54:58 volumio go-librespot[30237]: time="2026-02-12T22:54:58-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 12 22:54:58 volumio go-librespot[30237]: time="2026-02-12T22:54:58-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 12 22:54:58 volumio systemd[1]: squeezelite.service: Deactivated successfully. Feb 12 22:54:58 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Feb 12 22:54:58 volumio go-librespot[30237]: time="2026-02-12T22:54:58-06:00" level=info msg="zeroconf server listening on port 33077" Feb 12 22:54:58 volumio sudo[30246]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:58 volumio go-librespot[30237]: time="2026-02-12T22:54:58-06:00" level=debug msg="obtained new client token: AACX47xIA+gHi8nlBzBMHaLexNj9uFoZP2O3Vm1gvBVsRZKRM7MPPI4uIlzpUhYnJSzTdSujA//D2LkLfcAI0JzwgLR+Q1offGY+HUM1qKGqN3BW7dLxP6qM8GWiwAwMWpTvJC8GlkrA0VhJ/9xlJkMKruLitwbGacxuSFSqifCj24WFFxTyU2o1P2KbM8kpsDHbSbXFjFFBu7ubKAgHVV0HU0+m/X6BWea7tLOJ05hhK7t8Um2J5FZsRA==" Feb 12 22:54:58 volumio go-librespot[30237]: time="2026-02-12T22:54:58-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 22:54:59 volumio go-librespot[30237]: time="2026-02-12T22:54:59-06:00" level=debug msg="completed keyexchange" Feb 12 22:54:59 volumio go-librespot[30237]: time="2026-02-12T22:54:59-06:00" level=debug msg="completed challenge" Feb 12 22:54:59 volumio go-librespot[30237]: time="2026-02-12T22:54:59-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 22:54:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 22:54:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 22:54:59 volumio volumio[29828]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 22:54:59 volumio sudo[30265]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 22:54:59 volumio sudo[30265]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:59 volumio sudo[30265]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:59 volumio volumio[29828]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Feb 12 22:54:59 volumio sudo[30269]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Feb 12 22:54:59 volumio sudo[30269]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:59 volumio sudo[30269]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:59 volumio volumio[29828]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Feb 12 22:54:59 volumio sudo[30272]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Feb 12 22:54:59 volumio sudo[30272]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:54:59 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Feb 12 22:54:59 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Feb 12 22:54:59 volumio sudo[30272]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:59 volumio mpd[30199]: 2026-02-12T22:54:59 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 12 22:54:59 volumio volumio[29828]: info: Initializing connection to go-librespot Websocket Feb 12 22:54:59 volumio volumio[29828]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 22:54:59 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 12 22:54:59 volumio sudo[30047]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:59 volumio sudo[30057]: pam_unix(sudo:session): session closed for user root Feb 12 22:54:59 volumio sudo[30157]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:00 volumio volumio[29828]: error: MPD error: The expression evaluated to a falsy value: Feb 12 22:55:00 volumio volumio[29828]: assert.ok(self.idling) Feb 12 22:55:00 volumio volumio[29828]: error: The expression evaluated to a falsy value: Feb 12 22:55:00 volumio volumio[29828]: assert.ok(self.idling) Feb 12 22:55:00 volumio volumio[29828]: error: MPD error: The expression evaluated to a falsy value: Feb 12 22:55:00 volumio volumio[29828]: assert.ok(self.idling) Feb 12 22:55:00 volumio volumio[29828]: error: The expression evaluated to a falsy value: Feb 12 22:55:00 volumio volumio[29828]: assert.ok(self.idling) Feb 12 22:55:00 volumio volumio[29828]: info: MPD running with PID30199 Feb 12 22:55:00 volumio volumio[29828]: ,establishing connection Feb 12 22:55:00 volumio volumio[29828]: error: updateQueue error: null Feb 12 22:55:00 volumio volumio[29828]: error: updateQueue error: null Feb 12 22:55:00 volumio volumio[29828]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 22:55:00 volumio sudo[30283]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 22:55:00 volumio sudo[30283]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:00 volumio sudo[30283]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:00 volumio volumio[29828]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 22:55:00 volumio sudo[30286]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 22:55:00 volumio sudo[30286]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:00 volumio sudo[30286]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:01 volumio volumio[29828]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 22:55:01 volumio sudo[30289]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 22:55:01 volumio sudo[30289]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:01 volumio sudo[30289]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:01 volumio volumio[29828]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 22:55:02 volumio sudo[30292]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 22:55:02 volumio sudo[30292]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:02 volumio sudo[30292]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 12 22:55:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:55:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:55:02 volumio go-librespot[30294]: go-librespot daemon starting... Feb 12 22:55:02 volumio go-librespot[30295]: time="2026-02-12T22:55:02-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 22:55:02 volumio go-librespot[30295]: time="2026-02-12T22:55:02-06:00" level=debug msg="app state loaded" Feb 12 22:55:02 volumio go-librespot[30295]: time="2026-02-12T22:55:02-06:00" level=debug msg="stored credentials not found" Feb 12 22:55:02 volumio go-librespot[30295]: time="2026-02-12T22:55:02-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 22:55:02 volumio go-librespot[30295]: time="2026-02-12T22:55:02-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 22:55:02 volumio go-librespot[30295]: time="2026-02-12T22:55:02-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 12 22:55:02 volumio go-librespot[30295]: time="2026-02-12T22:55:02-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 12 22:55:02 volumio go-librespot[30295]: time="2026-02-12T22:55:02-06:00" level=info msg="zeroconf server listening on port 35145" Feb 12 22:55:02 volumio go-librespot[30295]: time="2026-02-12T22:55:02-06:00" level=debug msg="obtained new client token: AADfcQQuKHy0BZawQ3EB2750g9wMM0AEXMLNVntdYieFmSe9ZoamU9uFUfhRBVbrl0ZHddEqAAuLdtZSD3vHtf3913JbKQMSSD5tK6H6kzSIEVirjAU8ID1Lb3kqk1IHo5r4P2AyWzP2eiImgljLm7YCwlSTi5Q5Sa2jcYL246OZHIMl7HBYLT5CetOr2eshjCfrKhoPJvRz8Ay90rC9L0RP/roUCkj4fSNfPnQXiqy75C95Yuw35Lzs/g==" Feb 12 22:55:02 volumio volumio[29828]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 22:55:02 volumio go-librespot[30295]: time="2026-02-12T22:55:02-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 22:55:02 volumio sudo[30303]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 22:55:02 volumio sudo[30303]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:02 volumio go-librespot[30295]: time="2026-02-12T22:55:02-06:00" level=debug msg="completed keyexchange" Feb 12 22:55:02 volumio go-librespot[30295]: time="2026-02-12T22:55:02-06:00" level=debug msg="completed challenge" Feb 12 22:55:02 volumio sudo[30303]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:02 volumio volumio[29828]: info: Completed starting Core Plugins Feb 12 22:55:02 volumio volumio[29828]: info: ------------------------------------------- Feb 12 22:55:02 volumio volumio[29828]: info: ----- MyVolumio plugins startup ---- Feb 12 22:55:02 volumio volumio[29828]: info: ------------------------------------------- Feb 12 22:55:02 volumio volumio[29828]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 12 22:55:02 volumio kernel: hwmon hwmon1: Voltage normalised Feb 12 22:55:02 volumio go-librespot[30295]: time="2026-02-12T22:55: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 12 22:55:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 22:55:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 22:55:02 volumio volumio[29828]: info: Initializing connection to go-librespot Websocket Feb 12 22:55:02 volumio volumio[29828]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 22:55:03 volumio sudo[30307]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 12 22:55:03 volumio sudo[30307]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:03 volumio sudo[30309]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 12 22:55:03 volumio sudo[30309]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:03 volumio sudo[30312]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 12 22:55:03 volumio sudo[30312]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:03 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 12 22:55:03 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 12 22:55:03 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 12 22:55:03 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 12 22:55:03 volumio sudo[30312]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:03 volumio sudo[30307]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:03 volumio sudo[30309]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:03 volumio mpd_monitor.sh[30315]: MPD Monitor Service: Starting MPD Monitor Service Feb 12 22:55:03 volumio volumio[29828]: info: Successfully started MPD Monitor Feb 12 22:55:03 volumio volumio[29828]: info: Successfully started MPD Monitor Feb 12 22:55:03 volumio volumio[29828]: info: Successfully started MPD Monitor Feb 12 22:55:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 12 22:55:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:55:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:55:05 volumio go-librespot[30319]: go-librespot daemon starting... Feb 12 22:55:05 volumio go-librespot[30320]: time="2026-02-12T22:55:05-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 22:55:05 volumio go-librespot[30320]: time="2026-02-12T22:55:05-06:00" level=debug msg="app state loaded" Feb 12 22:55:05 volumio go-librespot[30320]: time="2026-02-12T22:55:05-06:00" level=debug msg="stored credentials not found" Feb 12 22:55:05 volumio go-librespot[30320]: time="2026-02-12T22:55:05-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 22:55:05 volumio volumio[29828]: info: Initializing connection to go-librespot Websocket Feb 12 22:55:06 volumio go-librespot[30320]: time="2026-02-12T22:55:06-06:00" level=debug msg="new websocket client" Feb 12 22:55:06 volumio go-librespot[30320]: time="2026-02-12T22:55:06-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 22:55:06 volumio go-librespot[30320]: time="2026-02-12T22:55:06-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 12 22:55:06 volumio go-librespot[30320]: time="2026-02-12T22:55:06-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 12 22:55:06 volumio go-librespot[30320]: time="2026-02-12T22:55:06-06:00" level=info msg="zeroconf server listening on port 41623" Feb 12 22:55:06 volumio go-librespot[30320]: time="2026-02-12T22:55:06-06:00" level=debug msg="obtained new client token: AADX3AKUTtJMvDf0TrGpsO0o0wZCXkfd+hr0vjYhlaoH0EEXTrHnjrMLD5pTiZCkXZ6D6skBbz5AluSEqLhPTKofEStvgmPPC8K8XLrKChjd9Vq9KG4CGe1fYJuxRn/nVrzwmrf42cDJpCOgxnTHEYW59t2Fq9o1FjnqZVwyOlHQzZigbvYpXNnQEPfmg5GPjfHWWNoZevLiALlkdRFiaYMbkrItPEXFiQC3Fx5iPYCjhLeOyhtMP9R0ig==" Feb 12 22:55:06 volumio go-librespot[30320]: time="2026-02-12T22:55:06-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 22:55:06 volumio go-librespot[30320]: time="2026-02-12T22:55:06-06:00" level=debug msg="completed keyexchange" Feb 12 22:55:06 volumio go-librespot[30320]: time="2026-02-12T22:55:06-06:00" level=debug msg="completed challenge" Feb 12 22:55:06 volumio go-librespot[30320]: time="2026-02-12T22:55:06-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 22:55:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 22:55:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 22:55:06 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Feb 12 22:55:06 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 12 22:55:07 volumio volumio[29828]: info: Connection to go-librespot Websocket established Feb 12 22:55:07 volumio volumio[29828]: info: Connection to go-librespot Websocket closed Feb 12 22:55:08 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Feb 12 22:55:08 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Feb 12 22:55:08 volumio systemd[1]: setdatetime-helper.service: Consumed 1.947s CPU time. Feb 12 22:55:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 12 22:55:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:55:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:55:09 volumio go-librespot[30368]: go-librespot daemon starting... Feb 12 22:55:09 volumio go-librespot[30369]: time="2026-02-12T22:55:09-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 22:55:09 volumio go-librespot[30369]: time="2026-02-12T22:55:09-06:00" level=debug msg="app state loaded" Feb 12 22:55:09 volumio go-librespot[30369]: time="2026-02-12T22:55:09-06:00" level=debug msg="stored credentials not found" Feb 12 22:55:09 volumio go-librespot[30369]: time="2026-02-12T22:55:09-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 22:55:10 volumio go-librespot[30369]: time="2026-02-12T22:55:10-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 22:55:10 volumio go-librespot[30369]: time="2026-02-12T22:55:10-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 22:55:10 volumio go-librespot[30369]: time="2026-02-12T22:55:10-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 22:55:10 volumio go-librespot[30369]: time="2026-02-12T22:55:10-06:00" level=info msg="zeroconf server listening on port 33307" Feb 12 22:55:10 volumio volumio[29828]: info: Getting Spotify volume Feb 12 22:55:10 volumio volumio[29828]: 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 12 22:55:10 volumio go-librespot[30369]: time="2026-02-12T22:55:10-06:00" level=debug msg="obtained new client token: AACtfEMKEcB4loBoyzv2vscaArauXlSowMWxA37QM+npoHClttZcHp/SWCvgY+A2BjP/z6Wpaa1W+Lkz+NWDK37LwVHQo9QLs+L7bxJr8+cX+cg8kVLTyo2nz5Fwc5Eh1HWW3gJg9/GJTEC+Hwac/ZEgLr7dh99OEEoXa2YhMZXC58cVyXcymCgQBZ4P3bdLHSF+LeBwWBsI3eYtt6umHdGtAH2QAwcyl151JCToooTHn70N6oXKIwY=" Feb 12 22:55:10 volumio volumio[29828]: info: CoreCommandRouter::volumioGetState Feb 12 22:55:10 volumio volumio[29828]: info: CorePlayQueue::getTrack 0 Feb 12 22:55:10 volumio volumio[29828]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 12 22:55:10 volumio volumio[29828]: SPOTIFY: SPOTIFY VOLUME undefined Feb 12 22:55:10 volumio volumio[29828]: SPOTIFY: VOLUMIO VOLUME 100 Feb 12 22:55:10 volumio volumio[29828]: info: Aligning Spotify Volume to Volumio Volume Feb 12 22:55:10 volumio volumio[29828]: info: CoreCommandRouter::volumioGetState Feb 12 22:55:10 volumio volumio[29828]: info: CorePlayQueue::getTrack 0 Feb 12 22:55:10 volumio volumio[29828]: info: Setting Spotify Volume from Volumio: 100 Feb 12 22:55:10 volumio go-librespot[30369]: time="2026-02-12T22:55:10-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 22:55:10 volumio volumio[29828]: info: Initializing connection to go-librespot Websocket Feb 12 22:55:10 volumio go-librespot[30369]: time="2026-02-12T22:55:10-06:00" level=debug msg="new websocket client" Feb 12 22:55:10 volumio volumio[29828]: info: Connection to go-librespot Websocket established Feb 12 22:55:10 volumio go-librespot[30369]: time="2026-02-12T22:55:10-06:00" level=debug msg="completed keyexchange" Feb 12 22:55:10 volumio go-librespot[30369]: time="2026-02-12T22:55:10-06:00" level=debug msg="completed challenge" Feb 12 22:55:10 volumio go-librespot[30369]: time="2026-02-12T22:55:10-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 12 22:55:10 volumio volumio[29828]: info: Connection to go-librespot Websocket closed Feb 12 22:55:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 22:55:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 22:55:10 volumio volumio[29828]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 22:55:10 volumio volumio[29828]: Error: socket hang up Feb 12 22:55:10 volumio volumio[29828]: at connResetException (node:internal/errors:720:14) Feb 12 22:55:10 volumio volumio[29828]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 12 22:55:10 volumio volumio[29828]: at Socket.emit (node:events:526:35) Feb 12 22:55:10 volumio volumio[29828]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 12 22:55:10 volumio volumio[29828]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 12 22:55:10 volumio volumio[29828]: code: 'ECONNRESET', Feb 12 22:55:10 volumio volumio[29828]: response: undefined Feb 12 22:55:10 volumio volumio[29828]: } Feb 12 22:55:10 volumio volumio[29828]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 22:55:11 volumio sudo[30390]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-12 22:54' Feb 12 22:55:11 volumio sudo[30390]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:11 volumio sudo[30390]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:11 volumio volumio-remote-updater[2265]: [2026-02-12 22:55:11] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 12 22:55:11 volumio volumio-remote-updater[2265]: [2026-02-12 22:55:11] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 12 22:55:11 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 12 22:55:11 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 12 22:55:11 volumio systemd[1]: volumio.service: Consumed 48.173s CPU time. Feb 12 22:55:11 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 12 22:55:11 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 12 22:55:11 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 7068. Feb 12 22:55:11 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 12 22:55:11 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 12 22:55:11 volumio systemd[1]: volumio.service: Consumed 48.173s CPU time. Feb 12 22:55:11 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 12 22:55:11 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 12 22:55:13 volumio kernel: hwmon hwmon1: Voltage normalised Feb 12 22:55:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 12 22:55:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:55:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:55:13 volumio go-librespot[30422]: go-librespot daemon starting... Feb 12 22:55:13 volumio go-librespot[30423]: time="2026-02-12T22:55:13-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 22:55:13 volumio go-librespot[30423]: time="2026-02-12T22:55:13-06:00" level=debug msg="app state loaded" Feb 12 22:55:13 volumio go-librespot[30423]: time="2026-02-12T22:55:13-06:00" level=debug msg="stored credentials not found" Feb 12 22:55:13 volumio go-librespot[30423]: time="2026-02-12T22:55:13-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 22:55:13 volumio volumio[30406]: info: ------------------------------------------- Feb 12 22:55:13 volumio volumio[30406]: info: ----- Volumio3 ---- Feb 12 22:55:13 volumio volumio[30406]: info: ------------------------------------------- Feb 12 22:55:13 volumio volumio[30406]: info: ----- System startup ---- Feb 12 22:55:13 volumio volumio[30406]: info: ------------------------------------------- Feb 12 22:55:13 volumio go-librespot[30423]: time="2026-02-12T22:55: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 22:55:13 volumio go-librespot[30423]: time="2026-02-12T22:55:13-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 12 22:55:13 volumio go-librespot[30423]: time="2026-02-12T22:55:13-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 12 22:55:13 volumio go-librespot[30423]: time="2026-02-12T22:55:13-06:00" level=info msg="zeroconf server listening on port 43163" Feb 12 22:55:13 volumio go-librespot[30423]: time="2026-02-12T22:55:13-06:00" level=debug msg="obtained new client token: AADTgfKroRSN5GYzmcKPf0N5lKpiG5wwrM+1dlsx2nSUKYLzbvq6e+l9q4JmjYd6SjDjsoIScwu06z9ke9TFaKqN7t+IKWaA8JoiY+txu0fkjngncIrXIxm7o0lafNMx4zXSG8OqJw0i3zAIuOUlzVu4RtHUdkhpUB6M7ceE43YYjwCqDaMGY0kHN9rGyeyNhbxoNeb5PA/+zmzLaDLLuhbCuMXbOlRJ+5UEmKBeZkVz9suq+AjVvqA5pA==" Feb 12 22:55:14 volumio go-librespot[30423]: time="2026-02-12T22:55:14-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 22:55:14 volumio go-librespot[30423]: time="2026-02-12T22:55:14-06:00" level=debug msg="completed keyexchange" Feb 12 22:55:14 volumio go-librespot[30423]: time="2026-02-12T22:55:14-06:00" level=debug msg="completed challenge" Feb 12 22:55:14 volumio go-librespot[30423]: time="2026-02-12T22:55: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 12 22:55:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 22:55:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 22:55:14 volumio volumio[30406]: info: MYVOLUMIO Environment detected Feb 12 22:55:14 volumio volumio[30406]: info: Plugin folders cleanup Feb 12 22:55:14 volumio volumio[30406]: info: Scanning into folder /volumio/app/plugins/ Feb 12 22:55:14 volumio volumio[30406]: info: Scanning category audio_interface Feb 12 22:55:14 volumio volumio[30406]: info: Scanning category miscellanea Feb 12 22:55:14 volumio volumio[30406]: info: Scanning category music_service Feb 12 22:55:14 volumio volumio[30406]: info: Scanning category plugins.json Feb 12 22:55:14 volumio volumio[30406]: info: Scanning category system_controller Feb 12 22:55:14 volumio volumio[30406]: info: Scanning category user_interface Feb 12 22:55:14 volumio volumio[30406]: info: Scanning into folder /data/plugins/ Feb 12 22:55:14 volumio volumio[30406]: info: Scanning category audio_interface Feb 12 22:55:14 volumio volumio[30406]: info: Scanning category music_service Feb 12 22:55:14 volumio volumio[30406]: info: Scanning category system_controller Feb 12 22:55:14 volumio volumio[30406]: info: Scanning category system_hardware Feb 12 22:55:14 volumio volumio[30406]: info: Scanning category user_interface Feb 12 22:55:14 volumio volumio[30406]: info: Plugin folders cleanup completed Feb 12 22:55:14 volumio volumio[30406]: info: ------------------------------------------- Feb 12 22:55:14 volumio volumio[30406]: info: ----- Core plugins startup ---- Feb 12 22:55:14 volumio volumio[30406]: info: ------------------------------------------- Feb 12 22:55:14 volumio volumio[30406]: info: Loading plugins from folder /volumio/app/plugins/ Feb 12 22:55:14 volumio volumio[30406]: info: Adding plugin upnp to MyMusic Plugins Feb 12 22:55:14 volumio volumio[30406]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 12 22:55:14 volumio volumio[30406]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 12 22:55:14 volumio volumio[30406]: info: Loading plugins from folder /data/plugins/ Feb 12 22:55:14 volumio volumio[30406]: info: Loading plugin "system"... Feb 12 22:55:14 volumio volumio[30406]: info: Loading plugin "appearance"... Feb 12 22:55:15 volumio volumio[30406]: info: Loading plugin "network"... Feb 12 22:55:15 volumio volumio[30406]: info: Refreshing Cached IP Addresses Feb 12 22:55:15 volumio sudo[30443]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 12 22:55:15 volumio sudo[30443]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:15 volumio sudo[30443]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:15 volumio sudo[30445]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 12 22:55:15 volumio volumio[30406]: info: Loading plugin "services"... Feb 12 22:55:15 volumio sudo[30445]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:15 volumio volumio[30406]: info: Loading plugin "alsa_controller"... Feb 12 22:55:15 volumio sudo[30445]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:15 volumio sudo[30453]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 12 22:55:15 volumio sudo[30453]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:15 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 22:55:15 volumio volumio[30406]: info: Loading plugin "wizard"... Feb 12 22:55:15 volumio volumio[30406]: info: Loading plugin "networkfs"... Feb 12 22:55:15 volumio volumio[30406]: info: Starting Udev Watcher for removable devices Feb 12 22:55:16 volumio volumio[30406]: info: Ignoring mount for partition: boot Feb 12 22:55:16 volumio volumio[30406]: info: Ignoring mount for partition: volumio Feb 12 22:55:16 volumio volumio[30406]: info: Ignoring mount for partition: volumio_data Feb 12 22:55:16 volumio volumio[30406]: info: Mounting Device Wikipedia Feb 12 22:55:16 volumio sudo[30482]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime Feb 12 22:55:16 volumio sudo[30482]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:16 volumio sudo[30482]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:16 volumio volumio[30406]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Feb 12 22:55:16 volumio volumio[30406]: dmesg(1) may have more information after failed mount system call. Feb 12 22:55:16 volumio volumio[30406]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime Feb 12 22:55:16 volumio volumio[30406]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Feb 12 22:55:16 volumio volumio[30406]: dmesg(1) may have more information after failed mount system call. Feb 12 22:55:16 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 22:55:16 volumio volumio[30406]: info: Loading plugin "volumio_command_line_client"... Feb 12 22:55:16 volumio volumio[30406]: info: Loading plugin "upnp"... Feb 12 22:55:16 volumio volumio[30406]: info: [1770958516208] Starting Upmpd Daemon Feb 12 22:55:16 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 22:55:16 volumio volumio[30406]: info: Loading plugin "my_music"... Feb 12 22:55:16 volumio volumio[30406]: info: Loading plugin "mpd"... Feb 12 22:55:16 volumio volumio-remote-updater[2265]: [2026-02-12 22:55:16] [connect] Successful connection Feb 12 22:55:16 volumio sudo[30453]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:16 volumio volumio[30406]: info: Loading plugin "upnp_browser"... Feb 12 22:55:17 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 12 22:55:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 12 22:55:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:55:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:55:17 volumio go-librespot[30485]: go-librespot daemon starting... Feb 12 22:55:17 volumio go-librespot[30486]: time="2026-02-12T22:55:17-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 22:55:17 volumio go-librespot[30486]: time="2026-02-12T22:55:17-06:00" level=debug msg="app state loaded" Feb 12 22:55:17 volumio go-librespot[30486]: time="2026-02-12T22:55:17-06:00" level=debug msg="stored credentials not found" Feb 12 22:55:17 volumio go-librespot[30486]: time="2026-02-12T22:55:17-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 22:55:17 volumio go-librespot[30486]: time="2026-02-12T22:55: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 12 22:55:17 volumio go-librespot[30486]: time="2026-02-12T22:55: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 12 22:55:17 volumio go-librespot[30486]: time="2026-02-12T22:55: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 12 22:55:17 volumio go-librespot[30486]: time="2026-02-12T22:55:17-06:00" level=info msg="zeroconf server listening on port 40237" Feb 12 22:55:17 volumio go-librespot[30486]: time="2026-02-12T22:55:17-06:00" level=debug msg="obtained new client token: AACRuA5l0LHDt6B/9vh+VIRSFfIdE/i7cQ155wizpY3fHt/dv+QhESwpIlL0DVfCWvDkbBc0hjMGE817bnPMIvW4gAAJnsSk6SsGEkzEoIlGXzEmf0OMRRZ8iMrAVIh/NK9j9mdAhthjUY5WR4zAfo+Cx4Kg5QkO6FR0hjF8y/1fgF6xCHMCGQkpZ0FRK0/ZzxDHzYdbeSTOH5sQdhZ2ejaBZViYG7SMW7zYoQ2pzlyqMcnljNceceb/hQ==" Feb 12 22:55:18 volumio go-librespot[30486]: time="2026-02-12T22:55:18-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 22:55:18 volumio go-librespot[30486]: time="2026-02-12T22:55:18-06:00" level=debug msg="completed keyexchange" Feb 12 22:55:18 volumio go-librespot[30486]: time="2026-02-12T22:55:18-06:00" level=debug msg="completed challenge" Feb 12 22:55:18 volumio go-librespot[30486]: time="2026-02-12T22:55: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 12 22:55:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 22:55:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 22:55:19 volumio volumio[30406]: info: Loading plugin "alarm-clock"... Feb 12 22:55:19 volumio volumio[30406]: info: Loading plugin "airplay_emulation"... Feb 12 22:55:19 volumio volumio[30406]: info: Starting Shairport Sync Feb 12 22:55:19 volumio volumio[30406]: info: Loading plugin "last_100"... Feb 12 22:55:19 volumio volumio[30406]: info: Loading plugin "webradio"... Feb 12 22:55:19 volumio volumio[30406]: info: Loading plugin "i2s_dacs"... Feb 12 22:55:19 volumio volumio[30406]: info: I2S DAC not set, start Auto-detection Feb 12 22:55:19 volumio volumio[30406]: info: Loading plugin "volumiodiscovery"... Feb 12 22:55:19 volumio volumio[30406]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 12 22:55:19 volumio volumio[30406]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 22:55:19 volumio volumio[30406]: *** WARNING *** For more information see Feb 12 22:55:19 volumio volumio[30406]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 12 22:55:19 volumio volumio[30406]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 22:55:19 volumio volumio[30406]: *** WARNING *** For more information see Feb 12 22:55:19 volumio node[30406]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 12 22:55:19 volumio node[30406]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 22:55:19 volumio node[30406]: *** WARNING *** For more information see Feb 12 22:55:19 volumio node[30406]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 12 22:55:19 volumio node[30406]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 22:55:19 volumio node[30406]: *** WARNING *** For more information see Feb 12 22:55:19 volumio volumio[30406]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 12 22:55:19 volumio volumio[30406]: info: Discovery: Started advertising with name: Volumio Feb 12 22:55:19 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 22:55:19 volumio volumio[30406]: info: Loading plugin "bandcamp"... Feb 12 22:55:21 volumio volumio[30406]: info: Plugin calmradio is not enabled Feb 12 22:55:21 volumio volumio[30406]: info: Loading plugin "soundcloud"... Feb 12 22:55:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 12 22:55:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:55:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:55:21 volumio go-librespot[30495]: go-librespot daemon starting... Feb 12 22:55:21 volumio go-librespot[30496]: time="2026-02-12T22:55:21-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 22:55:21 volumio go-librespot[30496]: time="2026-02-12T22:55:21-06:00" level=debug msg="app state loaded" Feb 12 22:55:21 volumio go-librespot[30496]: time="2026-02-12T22:55:21-06:00" level=debug msg="stored credentials not found" Feb 12 22:55:21 volumio go-librespot[30496]: time="2026-02-12T22:55:21-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 22:55:21 volumio kernel: hwmon hwmon1: Voltage normalised Feb 12 22:55:21 volumio volumio[30406]: info: Loading plugin "spop"... Feb 12 22:55:21 volumio go-librespot[30496]: time="2026-02-12T22:55: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 22:55:21 volumio go-librespot[30496]: time="2026-02-12T22:55:21-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 12 22:55:21 volumio go-librespot[30496]: time="2026-02-12T22:55:21-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 12 22:55:21 volumio go-librespot[30496]: time="2026-02-12T22:55:21-06:00" level=info msg="zeroconf server listening on port 41055" Feb 12 22:55:21 volumio go-librespot[30496]: time="2026-02-12T22:55:21-06:00" level=debug msg="obtained new client token: AACKi5gpXcxiMkMbfcEK86EB4vBf+Zq4zbcK4pnOPEFkNGG2jdjUc4EtzC5SnyyAZY3QbUO2EKOGBzHtS5pli3VJP+xKSlSOAKJGzKiVRMqsAQ+w+pM7Dx2S+Zn3TCSExvD5Up40lrPV0I7S2ckEh2TWv89OxQxTZ0cjlM928LjgmwPEoDSgLu5AaSw4qW/T0aQ2H5NoExPLPWbV8JXPV7LLZXoSNoE86nkvU26nPUBgLvJXsStQpfcP5A==" Feb 12 22:55:21 volumio go-librespot[30496]: time="2026-02-12T22:55:21-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 12 22:55:21 volumio go-librespot[30496]: time="2026-02-12T22:55:21-06:00" level=debug msg="connected to ap-guc3.spotify.com:443" Feb 12 22:55:21 volumio go-librespot[30496]: time="2026-02-12T22:55:21-06:00" level=debug msg="completed keyexchange" Feb 12 22:55:21 volumio go-librespot[30496]: time="2026-02-12T22:55:21-06:00" level=debug msg="completed challenge" Feb 12 22:55:21 volumio go-librespot[30496]: time="2026-02-12T22:55: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 12 22:55:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 22:55:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 22:55:22 volumio volumio[30406]: info: Loading plugin "squeezelite_mc"... Feb 12 22:55:23 volumio volumio[30406]: info: Loading plugin "youtube2"... Feb 12 22:55:23 volumio volumio[30406]: info: Loading plugin "ytcr"... Feb 12 22:55:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 12 22:55:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:55:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:55:25 volumio go-librespot[30507]: go-librespot daemon starting... Feb 12 22:55:25 volumio go-librespot[30508]: time="2026-02-12T22:55:25-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 22:55:25 volumio go-librespot[30508]: time="2026-02-12T22:55:25-06:00" level=debug msg="app state loaded" Feb 12 22:55:25 volumio go-librespot[30508]: time="2026-02-12T22:55:25-06:00" level=debug msg="stored credentials not found" Feb 12 22:55:25 volumio go-librespot[30508]: time="2026-02-12T22:55:25-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 22:55:25 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 12 22:55:25 volumio go-librespot[30508]: time="2026-02-12T22:55: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 22:55:25 volumio go-librespot[30508]: time="2026-02-12T22:55:25-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 12 22:55:25 volumio go-librespot[30508]: time="2026-02-12T22:55:25-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 12 22:55:25 volumio go-librespot[30508]: time="2026-02-12T22:55:25-06:00" level=info msg="zeroconf server listening on port 36295" Feb 12 22:55:25 volumio go-librespot[30508]: time="2026-02-12T22:55:25-06:00" level=debug msg="obtained new client token: AABf59pRwg2i1viUf17jgUS72OWuSLMBGdfCA22aXiyShvStruvqqA0UhrQ15OMm3ejaCTJRXC8/TRUeaCrByxtzXIXIbnD76xN+6OgB8vfJ78tlw2Dbg29IQf/yK32s09nk8o25UPJ7I1AhSMOH17RhrvrGqnUbaWeg2s0QgxjdAuGuObba0zNKmNbEa5Cv35pIT7pHcb+jFxDY7Ok9+9wWyx+nxorcXyNG9cT2GPyRAoI/O9Od+Kk84g==" Feb 12 22:55:25 volumio go-librespot[30508]: time="2026-02-12T22:55:25-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 22:55:25 volumio go-librespot[30508]: time="2026-02-12T22:55:25-06:00" level=debug msg="completed keyexchange" Feb 12 22:55:25 volumio go-librespot[30508]: time="2026-02-12T22:55:25-06:00" level=debug msg="completed challenge" Feb 12 22:55:25 volumio go-librespot[30508]: time="2026-02-12T22:55: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 12 22:55:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 22:55:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 22:55:26 volumio volumio[30406]: info: Loading plugin "ytmusic"... Feb 12 22:55:27 volumio volumio[30406]: info: Plugin now_playing is not enabled Feb 12 22:55:27 volumio volumio[30406]: info: Loading plugin "outputs"... Feb 12 22:55:27 volumio volumio[30406]: info: Loading plugin "albumart"... Feb 12 22:55:27 volumio volumio[30406]: info: Plugin example_plugin is not enabled Feb 12 22:55:27 volumio volumio[30406]: info: Loading plugin "inputs"... Feb 12 22:55:27 volumio volumio[30406]: info: Loading plugin "updater_comm"... Feb 12 22:55:27 volumio volumio[30406]: info: Plugin mpdemulation is not enabled Feb 12 22:55:27 volumio volumio[30406]: info: Loading plugin "rest_api"... Feb 12 22:55:27 volumio volumio[30406]: info: Loading plugin "websocket"... Feb 12 22:55:27 volumio volumio[30406]: info: Starting Socket.io Server version 1.7.4 Feb 12 22:55:27 volumio volumio[30406]: info: Plugin fusiondsp is not enabled Feb 12 22:55:27 volumio volumio[30406]: info: Plugin mpdoutput is not enabled Feb 12 22:55:27 volumio volumio[30406]: info: Plugin RoonBridge is not enabled Feb 12 22:55:27 volumio volumio[30406]: info: Loading plugin "podcast"... Feb 12 22:55:27 volumio volumio[30406]: info: ControllerPodcast::constructor Feb 12 22:55:27 volumio volumio[30406]: info: Loading plugin "volusonic"... Feb 12 22:55:27 volumio volumio[30530]: Forking 3 albumart workers Feb 12 22:55:28 volumio volumio-remote-updater[2265]: [2026-02-12 22:55:28] [connect] Successful connection Feb 12 22:55:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 12 22:55:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:55:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:55:29 volumio go-librespot[30570]: go-librespot daemon starting... Feb 12 22:55:29 volumio go-librespot[30571]: time="2026-02-12T22:55:29-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 22:55:29 volumio go-librespot[30571]: time="2026-02-12T22:55:29-06:00" level=debug msg="app state loaded" Feb 12 22:55:29 volumio go-librespot[30571]: time="2026-02-12T22:55:29-06:00" level=debug msg="stored credentials not found" Feb 12 22:55:29 volumio go-librespot[30571]: time="2026-02-12T22:55:29-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 22:55:29 volumio volumio[30406]: info: Applying required configuration parameters for plugin volusonic Feb 12 22:55:29 volumio volumio[30406]: info: Loading plugin "backup_restore"... Feb 12 22:55:29 volumio volumio[30540]: Starting albumart workers Feb 12 22:55:29 volumio go-librespot[30571]: time="2026-02-12T22:55:29-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 12 22:55:29 volumio go-librespot[30571]: time="2026-02-12T22:55:29-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 12 22:55:29 volumio go-librespot[30571]: time="2026-02-12T22:55:29-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 12 22:55:29 volumio go-librespot[30571]: time="2026-02-12T22:55:29-06:00" level=info msg="zeroconf server listening on port 34491" Feb 12 22:55:29 volumio volumio[30542]: Starting albumart workers Feb 12 22:55:29 volumio volumio[30541]: Starting albumart workers Feb 12 22:55:29 volumio go-librespot[30571]: time="2026-02-12T22:55:29-06:00" level=debug msg="obtained new client token: AAA+PtQqkMy5Xn3Mf+WUxb90DQRCSKRIfFuYxfVCZvgauyr6Rg7uyDv4dr+KsGi68FWl3Wp8qw+AI1Fx2YhZB+q7TZOSe2pA5FaKtZVvk9aizfEGXUjGe3IfkonuR0sXVC11el0MuXRmFwioKr83bOgXuBM6MCfyF2GZUL/c7pmUI0a7/tnyyCtKjgOfGUIgx2hlwWV/TiAPH2UE2eQLH81ZGp8LWyY1ZHp0SBaA+yPBVlmaXJtUE7octg==" Feb 12 22:55:29 volumio kernel: hwmon hwmon1: Voltage normalised Feb 12 22:55:29 volumio volumio[30406]: info: Applying required configuration parameters for plugin backup_restore Feb 12 22:55:29 volumio volumio[30406]: info: Plugin rpi_eeprom_config is not enabled Feb 12 22:55:29 volumio go-librespot[30571]: time="2026-02-12T22:55:29-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 12 22:55:29 volumio volumio[30406]: info: Plugin rpi_eeprom_updater is not enabled Feb 12 22:55:29 volumio volumio[30406]: info: Loading plugin "scheduledrestart"... Feb 12 22:55:29 volumio go-librespot[30571]: time="2026-02-12T22:55:29-06:00" level=debug msg="connected to ap-guc3.spotify.com:443" Feb 12 22:55:29 volumio go-librespot[30571]: time="2026-02-12T22:55:29-06:00" level=debug msg="completed keyexchange" Feb 12 22:55:29 volumio go-librespot[30571]: time="2026-02-12T22:55:29-06:00" level=debug msg="completed challenge" Feb 12 22:55:29 volumio go-librespot[30571]: time="2026-02-12T22:55:29-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 22:55:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 22:55:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 22:55:29 volumio volumio[30406]: info: Applying required configuration parameters for plugin scheduledrestart Feb 12 22:55:29 volumio volumio[30406]: info: Plugin Bluetoothremote is not enabled Feb 12 22:55:29 volumio volumio[30406]: info: Plugin music_services_shield is not enabled Feb 12 22:55:29 volumio volumio[30406]: info: Loading plugin "Systeminfo"... Feb 12 22:55:30 volumio volumio[30406]: info: Plugin peppymeterbasic is not enabled Feb 12 22:55:30 volumio volumio[30406]: info: Loading plugin "peppyspectrum"... Feb 12 22:55:30 volumio volumio[30406]: info: Loading i18n strings for locale en Feb 12 22:55:30 volumio volumio[30406]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Feb 12 22:55:30 volumio volumio[30406]: Updating browse sources language Feb 12 22:55:30 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 22:55:30 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 22:55:30 volumio volumio[30406]: info: CoreCommandRouter::initPlayerControls Feb 12 22:55:30 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:30 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:30 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:30 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:30 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:30 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:30 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:30 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:30 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 22:55:30 volumio volumio[30406]: Express server listening on port 3000 Feb 12 22:55:30 volumio volumio[30406]: [Metrics] WebUI: 17s 732.23ms Feb 12 22:55:30 volumio volumio[30406]: info: CoreStateMachine::resetVolumioState Feb 12 22:55:30 volumio volumio[30406]: info: CoreStateMachine::getcurrentVolume Feb 12 22:55:30 volumio volumio[30406]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 22:55:31 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 22:55:31 volumio sudo[30603]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 12 22:55:31 volumio sudo[30603]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:31 volumio sudo[30605]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 12 22:55:31 volumio sudo[30605]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:31 volumio sudo[30603]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:31 volumio sudo[30605]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:31 volumio volumio[30406]: info: Volumio Network Manager: Network status updated: 1 Feb 12 22:55:31 volumio volumio[30406]: info: VolumeController:: Volume=100 Mute =false Feb 12 22:55:31 volumio volumio[30406]: info: CoreStateMachine::pushState Feb 12 22:55:31 volumio volumio[30406]: info: CorePlayQueue::getTrack 0 Feb 12 22:55:31 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 22:55:31 volumio volumio[30406]: info: CoreCommandRouter::volumioPushState Feb 12 22:55:31 volumio volumio[30406]: info: CoreStateMachine::updateTrackBlock Feb 12 22:55:31 volumio volumio[30406]: info: CorePlayQueue::getTrackBlock Feb 12 22:55:31 volumio volumio[30406]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 22:55:31 volumio volumio-remote-updater[2265]: [2026-02-12 22:55:31] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770958528 101 Feb 12 22:55:31 volumio volumio[30406]: 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 12 22:55:31 volumio volumio[30406]: info: Reloading queue from file Feb 12 22:55:31 volumio volumio[30406]: info: CoreStateMachine::setRepeat null single undefined Feb 12 22:55:31 volumio volumio[30406]: info: CoreStateMachine::pushState Feb 12 22:55:31 volumio volumio[30406]: info: CorePlayQueue::getTrack 0 Feb 12 22:55:31 volumio volumio[30406]: info: CoreCommandRouter::volumioPushState Feb 12 22:55:31 volumio volumio[30406]: info: CoreStateMachine::setRandom null Feb 12 22:55:31 volumio volumio[30406]: info: CoreStateMachine::pushState Feb 12 22:55:31 volumio volumio[30406]: info: CorePlayQueue::getTrack 0 Feb 12 22:55:31 volumio volumio[30406]: info: CoreCommandRouter::volumioPushState Feb 12 22:55:31 volumio volumio[30406]: info: Setting Device type: Raspberry PI Feb 12 22:55:31 volumio volumio[30406]: info: VolumeController:: Volume=100 Mute =false Feb 12 22:55:31 volumio volumio[30406]: info: CoreStateMachine::pushState Feb 12 22:55:31 volumio volumio[30406]: info: CorePlayQueue::getTrack 0 Feb 12 22:55:31 volumio volumio[30406]: info: CoreCommandRouter::volumioPushState Feb 12 22:55:31 volumio volumio[30406]: info: Completed loading Core Plugins Feb 12 22:55:31 volumio volumio[30406]: info: Preparing to generate the ALSA configuration file Feb 12 22:55:31 volumio sudo[30618]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 12 22:55:31 volumio sudo[30618]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:31 volumio volumio[30406]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Feb 12 22:55:31 volumio volumio[30406]: info: Discovery: Found device Volumio Feb 12 22:55:31 volumio volumio[30406]: info: CoreCommandRouter::volumioGetState Feb 12 22:55:31 volumio volumio[30406]: info: CorePlayQueue::getTrack 0 Feb 12 22:55:31 volumio volumio[30406]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Feb 12 22:55:31 volumio volumio[30406]: info: Discovery: Found device Volumio Feb 12 22:55:31 volumio volumio[30406]: info: CoreCommandRouter::volumioGetState Feb 12 22:55:31 volumio volumio[30406]: info: CorePlayQueue::getTrack 0 Feb 12 22:55:31 volumio volumio[30406]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Feb 12 22:55:31 volumio volumio[30406]: info: Reading ALSA contributions from plugins. Feb 12 22:55:31 volumio volumio[30406]: info: Asound.conf file unchanged, so no further update is needed Feb 12 22:55:31 volumio sudo[30618]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:31 volumio volumio[30406]: info: Output device has changed, restarting MPD Feb 12 22:55:31 volumio volumio[30406]: info: Output device has changed, restarting Shairport Sync Feb 12 22:55:31 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:31 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 22:55:31 volumio sudo[30621]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 22:55:31 volumio sudo[30621]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:31 volumio sudo[30621]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:31 volumio sudo[30623]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 22:55:31 volumio sudo[30623]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:31 volumio volumio[30406]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 22:55:31 volumio volumio[30406]: info: ___________ START PLUGINS ___________ Feb 12 22:55:31 volumio volumio[30406]: info: ControllerMpd::onStart: Initializing MPD Feb 12 22:55:31 volumio volumio[30406]: info: Creating MPD Configuration file Feb 12 22:55:31 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 22:55:31 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 12 22:55:31 volumio volumio[30406]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 22:55:31 volumio volumio[30406]: info: [1770958531556] CoreMusicLibrary::Adding element Media Servers Feb 12 22:55:31 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 22:55:31 volumio sudo[30633]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 22:55:31 volumio sudo[30633]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:31 volumio sudo[30631]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 22:55:31 volumio sudo[30631]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:31 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:31 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 22:55:31 volumio sudo[30631]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:31 volumio volumio[30406]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 22:55:31 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:31 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 22:55:31 volumio volumio[30406]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 22:55:31 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 12 22:55:31 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 12 22:55:31 volumio systemd[1]: mpd.service: Consumed 5.652s CPU time. Feb 12 22:55:31 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 12 22:55:31 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 12 22:55:31 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 12 22:55:31 volumio volumio[30406]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 22:55:31 volumio volumio[30406]: info: [1770958531683] CoreMusicLibrary::Adding element Last_100 Feb 12 22:55:31 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 22:55:31 volumio volumio[30406]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 22:55:31 volumio volumio[30406]: info: [1770958531688] CoreMusicLibrary::Adding element Webradio Feb 12 22:55:31 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 22:55:31 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 22:55:31 volumio volumio[30406]: info: Initializing BBC Radios Feb 12 22:55:31 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 12 22:55:31 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 22:55:31 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 22:55:31 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 12 22:55:31 volumio volumio[30406]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 22:55:31 volumio volumio[30406]: info: [1770958531766] CoreMusicLibrary::Adding element Bandcamp Discover Feb 12 22:55:31 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 22:55:31 volumio volumio[30406]: Cannot find translation for source Bandcamp Discover Feb 12 22:55:31 volumio volumio[30406]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 22:55:31 volumio volumio[30406]: info: [1770958531778] CoreMusicLibrary::Adding element SoundCloud Feb 12 22:55:31 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 22:55:31 volumio volumio[30406]: Cannot find translation for source Bandcamp Discover Feb 12 22:55:31 volumio volumio[30406]: Cannot find translation for source SoundCloud Feb 12 22:55:31 volumio volumio[30406]: info: Creating Spotify config file Feb 12 22:55:31 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:31 volumio sudo[30659]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 12 22:55:31 volumio sudo[30659]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 12 22:55:31 volumio sudo[30659]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:32 volumio volumio[30406]: info: [squeezelite_mc] Starting proxy server... Feb 12 22:55:32 volumio volumio[30406]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 22:55:32 volumio volumio[30406]: info: [1770958532138] CoreMusicLibrary::Adding element YouTube2 Feb 12 22:55:32 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 22:55:32 volumio volumio[30406]: Cannot find translation for source Bandcamp Discover Feb 12 22:55:32 volumio volumio[30406]: Cannot find translation for source SoundCloud Feb 12 22:55:32 volumio volumio[30406]: Cannot find translation for source YouTube2 Feb 12 22:55:32 volumio volumio[30406]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 22:55:32 volumio volumio[30406]: info: [1770958532156] CoreMusicLibrary::Adding element YouTube Music Feb 12 22:55:32 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 22:55:32 volumio volumio[30406]: Cannot find translation for source Bandcamp Discover Feb 12 22:55:32 volumio volumio[30406]: Cannot find translation for source SoundCloud Feb 12 22:55:32 volumio volumio[30406]: Cannot find translation for source YouTube2 Feb 12 22:55:32 volumio volumio[30406]: Cannot find translation for source YouTube Music Feb 12 22:55:32 volumio volumio[30406]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 22:55:32 volumio volumio[30406]: info: [1770958532168] CoreMusicLibrary::Adding element Podcast Feb 12 22:55:32 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 22:55:32 volumio volumio[30406]: Cannot find translation for source Bandcamp Discover Feb 12 22:55:32 volumio volumio[30406]: Cannot find translation for source SoundCloud Feb 12 22:55:32 volumio volumio[30406]: Cannot find translation for source YouTube2 Feb 12 22:55:32 volumio volumio[30406]: Cannot find translation for source YouTube Music Feb 12 22:55:32 volumio volumio[30406]: Cannot find translation for source Podcast Feb 12 22:55:32 volumio volumio[30406]: info: Loading i18n strings for locale en Feb 12 22:55:32 volumio volumio[30406]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Feb 12 22:55:32 volumio volumio[30406]: Updating browse sources language Feb 12 22:55:32 volumio volumio[30406]: Cannot find translation for source Bandcamp Discover Feb 12 22:55:32 volumio volumio[30406]: Cannot find translation for source SoundCloud Feb 12 22:55:32 volumio volumio[30406]: Cannot find translation for source YouTube2 Feb 12 22:55:32 volumio volumio[30406]: Cannot find translation for source YouTube Music Feb 12 22:55:32 volumio volumio[30406]: Cannot find translation for source Podcast Feb 12 22:55:32 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 22:55:32 volumio volumio[30406]: Cannot find translation for source Bandcamp Discover Feb 12 22:55:32 volumio volumio[30406]: Cannot find translation for source SoundCloud Feb 12 22:55:32 volumio volumio[30406]: Cannot find translation for source YouTube2 Feb 12 22:55:32 volumio volumio[30406]: Cannot find translation for source YouTube Music Feb 12 22:55:32 volumio volumio[30406]: Cannot find translation for source Podcast Feb 12 22:55:32 volumio volumio[30406]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 22:55:32 volumio volumio[30406]: info: [1770958532226] CoreMusicLibrary::Adding element Volusonic Feb 12 22:55:32 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 22:55:32 volumio volumio[30406]: Cannot find translation for source Bandcamp Discover Feb 12 22:55:32 volumio volumio[30406]: Cannot find translation for source SoundCloud Feb 12 22:55:32 volumio volumio[30406]: Cannot find translation for source YouTube2 Feb 12 22:55:32 volumio volumio[30406]: Cannot find translation for source YouTube Music Feb 12 22:55:32 volumio volumio[30406]: Cannot find translation for source Podcast Feb 12 22:55:32 volumio volumio[30406]: Cannot find translation for source Volusonic Feb 12 22:55:32 volumio volumio[30406]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Feb 12 22:55:32 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Feb 12 22:55:32 volumio volumio[30406]: info: Volumio Calling Home Feb 12 22:55:32 volumio volumio[30406]: info: [squeezelite_mc] Proxy server started on port 42445 Feb 12 22:55:32 volumio volumio[30406]: info: Preparing to generate the ALSA configuration file Feb 12 22:55:32 volumio volumio[30406]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 22:55:32 volumio volumio[30406]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Feb 12 22:55:32 volumio volumio[30406]: info: Reading ALSA contributions from plugins. Feb 12 22:55:32 volumio volumio[30406]: info: MPD Permissions set Feb 12 22:55:32 volumio volumio[30406]: info: MPD Permissions set Feb 12 22:55:32 volumio volumio[30406]: info: Upmpdcli Daemon Started Feb 12 22:55:32 volumio volumio[30406]: info: Spotify config file written Feb 12 22:55:32 volumio sudo[30670]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 12 22:55:32 volumio sudo[30670]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:32 volumio volumio[30406]: 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 12 22:55:32 volumio volumio[30406]: info: VolumeController:: Volume=100 Mute =false Feb 12 22:55:32 volumio volumio[30406]: info: CoreStateMachine::pushState Feb 12 22:55:32 volumio volumio[30406]: info: CorePlayQueue::getTrack 0 Feb 12 22:55:32 volumio volumio[30406]: info: CoreCommandRouter::volumioPushState Feb 12 22:55:32 volumio volumio[30406]: info: [squeezelite_mc] Server discovery started Feb 12 22:55:32 volumio volumio[30406]: info: [squeezelite_mc] Player finder started Feb 12 22:55:32 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:32 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:32 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:32 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 22:55:32 volumio volumio[30406]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Feb 12 22:55:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:55:32 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:32 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:32 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:32 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:32 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:32 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:32 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:32 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:32 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 22:55:32 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:32 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:32 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:32 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:32 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:32 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:32 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:32 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:32 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:32 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 22:55:32 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:32 volumio volumio[30406]: info: No need to fix Spotify hosts Feb 12 22:55:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:55:32 volumio go-librespot[30675]: go-librespot daemon starting... Feb 12 22:55:32 volumio sudo[30670]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:32 volumio go-librespot[30685]: time="2026-02-12T22:55:32-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 22:55:32 volumio go-librespot[30685]: time="2026-02-12T22:55:32-06:00" level=debug msg="app state loaded" Feb 12 22:55:32 volumio go-librespot[30685]: time="2026-02-12T22:55:32-06:00" level=debug msg="stored credentials not found" Feb 12 22:55:32 volumio go-librespot[30685]: time="2026-02-12T22:55:32-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 22:55:32 volumio volumio[30406]: 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 12 22:55:32 volumio volumio[30406]: info: Volumio called home Feb 12 22:55:33 volumio volumio[30406]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Feb 12 22:55:33 volumio volumio[30406]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Feb 12 22:55:33 volumio volumio[30406]: 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 12 22:55:33 volumio go-librespot[30685]: time="2026-02-12T22:55: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 12 22:55:33 volumio go-librespot[30685]: time="2026-02-12T22:55:33-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 12 22:55:33 volumio go-librespot[30685]: time="2026-02-12T22:55:33-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 12 22:55:33 volumio volumio[30406]: info: Starting Shairport Sync Feb 12 22:55:33 volumio go-librespot[30685]: time="2026-02-12T22:55:33-06:00" level=info msg="zeroconf server listening on port 43491" Feb 12 22:55:33 volumio sudo[30695]: 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 12 22:55:33 volumio sudo[30695]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:33 volumio volumio[30406]: info: Starting Shairport Sync Feb 12 22:55:33 volumio sudo[30695]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:33 volumio volumio[30406]: info: Starting Shairport Sync Feb 12 22:55:33 volumio sudo[30699]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 22:55:33 volumio sudo[30699]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:33 volumio sudo[30701]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 22:55:33 volumio sudo[30701]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:33 volumio volumio[30406]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 22:55:33 volumio volumio[30406]: SPOTIFY: BQAx7TN0krdazjw0vaNfBGJdpN0DuQ_ymyO7JaVX2_7Qgka0ad5T2-C_W-nEgQmZ-LV9OE_O16dmiZvjIWxo9wDTB7gWCHZzW_sdSBwAF484JwQWE0fWOPl8-UvkXQW564ElEJ4GOmnwLfDc0KQ_Ys4XwQfqwKPOfuRxu-b82hrlmg9U-soAqkYySCw3B05ss5iEuvf9d6t3wlhPmg2Wyk4IZI4JJqRVrwWaQnk Feb 12 22:55:33 volumio volumio[30406]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 22:55:33 volumio volumio[30406]: info: New Spotify access token = BQAx7TN0krdazjw0vaNfBGJdpN0DuQ_ymyO7JaVX2_7Qgka0ad5T2-C_W-nEgQmZ-LV9OE_O16dmiZvjIWxo9wDTB7gWCHZzW_sdSBwAF484JwQWE0fWOPl8-UvkXQW564ElEJ4GOmnwLfDc0KQ_Ys4XwQfqwKPOfuRxu-b82hrlmg9U-soAqkYySCw3B05ss5iEuvf9d6t3wlhPmg2Wyk4IZI4JJqRVrwWaQnk Feb 12 22:55:33 volumio volumio[30406]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 12 22:55:33 volumio go-librespot[30685]: time="2026-02-12T22:55:33-06:00" level=debug msg="obtained new client token: AACqsDa0gKT1H0sMnBPzaNSa2FxRSIuzTbJ51Uqp+lt/SwjYKEMNxdKMHa2by9zo7D1omtll6n0hQ6qfZsiznmSfkonyeLpSBx/IEhGF527KiPzInuME/hqeJnJlA+wAb63VtsUvugBiAnG9nGKBSxJ8TWXDgGjB2Y8izlrZMpgZd6s5JxDjB1VoTuGwrdZTnug9UJ5bPT1u4kT3XJxMen2aBoMO4ibF+tnmbPU7ziL8qPxsgR/Riw4=" Feb 12 22:55:33 volumio sudo[30705]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 22:55:33 volumio sudo[30705]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:33 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 12 22:55:33 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 12 22:55:33 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 22:55:33 volumio systemd[1]: shairport-sync.service: Consumed 2.070s CPU time. Feb 12 22:55:33 volumio go-librespot[30685]: time="2026-02-12T22:55:33-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 22:55:33 volumio volumio[30406]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Feb 12 22:55:33 volumio volumio[30406]: info: Asound.conf file unchanged, so no further update is needed Feb 12 22:55:33 volumio volumio[30406]: info: Output device has changed, restarting MPD Feb 12 22:55:33 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 22:55:33 volumio sudo[30699]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:33 volumio go-librespot[30685]: time="2026-02-12T22:55:33-06:00" level=debug msg="completed keyexchange" Feb 12 22:55:33 volumio go-librespot[30685]: time="2026-02-12T22:55:33-06:00" level=debug msg="completed challenge" Feb 12 22:55:33 volumio volumio[30406]: info: Output device has changed, restarting Shairport Sync Feb 12 22:55:33 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:33 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 22:55:33 volumio sudo[30701]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:33 volumio go-librespot[30685]: time="2026-02-12T22:55: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 12 22:55:33 volumio sudo[30716]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 22:55:33 volumio sudo[30716]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 22:55:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 22:55:33 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 12 22:55:33 volumio volumio[30406]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 22:55:33 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 12 22:55:33 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 22:55:33 volumio sudo[30713]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 22:55:33 volumio sudo[30713]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:33 volumio sudo[30711]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Feb 12 22:55:33 volumio sudo[30711]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:33 volumio sudo[30713]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:33 volumio sudo[30711]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:33 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 22:55:33 volumio sudo[30705]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:33 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 12 22:55:33 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 12 22:55:33 volumio systemd[1]: mpd.service: Consumed 1.669s CPU time. Feb 12 22:55:33 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 12 22:55:33 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 12 22:55:33 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 12 22:55:33 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 12 22:55:33 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 12 22:55:33 volumio volumio[30406]: info: MPD Permissions set Feb 12 22:55:33 volumio volumio[30406]: info: Shairport-Sync Started Feb 12 22:55:33 volumio volumio[30406]: Error adding Membership: Error: addMembership EINVAL Feb 12 22:55:33 volumio volumio[30406]: 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 12 22:55:33 volumio volumio[30406]: info: Shairport-Sync Started Feb 12 22:55:33 volumio volumio[30406]: info: Shairport-Sync Started Feb 12 22:55:33 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:33 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:33 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:33 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:33 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:33 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:33 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:33 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:33 volumio sudo[30745]: 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 12 22:55:33 volumio sudo[30745]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:33 volumio sudo[30745]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:33 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 22:55:33 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:33 volumio volumio[30406]: info: CoreCommandRouter::volumioGetState Feb 12 22:55:33 volumio volumio[30406]: info: CorePlayQueue::getTrack 0 Feb 12 22:55:33 volumio volumio[30406]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Feb 12 22:55:33 volumio volumio[30406]: info: Starting Shairport Sync Feb 12 22:55:33 volumio sudo[30741]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 12 22:55:33 volumio sudo[30741]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 12 22:55:33 volumio sudo[30741]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:33 volumio sudo[30753]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Feb 12 22:55:33 volumio sudo[30753]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:33 volumio sudo[30756]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 22:55:33 volumio sudo[30756]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:33 volumio systemd[1]: Reloading. Feb 12 22:55:34 volumio volumio[30406]: 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 12 22:55:34 volumio volumio[30406]: info: Spotify Successfully logged in Feb 12 22:55:34 volumio volumio[30406]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 22:55:34 volumio volumio[30406]: info: [1770958534032] CoreMusicLibrary::Adding element Spotify Feb 12 22:55:34 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 22:55:34 volumio volumio[30406]: Cannot find translation for source Bandcamp Discover Feb 12 22:55:34 volumio volumio[30406]: Cannot find translation for source SoundCloud Feb 12 22:55:34 volumio volumio[30406]: Cannot find translation for source YouTube2 Feb 12 22:55:34 volumio volumio[30406]: Cannot find translation for source YouTube Music Feb 12 22:55:34 volumio volumio[30406]: Cannot find translation for source Podcast Feb 12 22:55:34 volumio volumio[30406]: Cannot find translation for source Volusonic Feb 12 22:55:34 volumio volumio[30406]: Cannot find translation for source Spotify Feb 12 22:55:34 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:34 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:34 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 22:55:35 volumio volumio[30406]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 22:55:35 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 12 22:55:36 volumio volumio[30406]: info: go-librespot daemon successfully initialized Feb 12 22:55:36 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 12 22:55:36 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 12 22:55:37 volumio sudo[30753]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:37 volumio volumio[30406]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 22:55:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 12 22:55:37 volumio sudo[30793]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 22:55:37 volumio sudo[30793]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:55:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:55:37 volumio go-librespot[30795]: go-librespot daemon starting... Feb 12 22:55:37 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 12 22:55:37 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 12 22:55:37 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 22:55:37 volumio systemd[1]: shairport-sync.service: Consumed 1.498s CPU time. Feb 12 22:55:37 volumio go-librespot[30796]: time="2026-02-12T22:55:37-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 22:55:37 volumio go-librespot[30796]: time="2026-02-12T22:55:37-06:00" level=debug msg="app state loaded" Feb 12 22:55:37 volumio go-librespot[30796]: time="2026-02-12T22:55:37-06:00" level=debug msg="stored credentials not found" Feb 12 22:55:37 volumio go-librespot[30796]: time="2026-02-12T22:55:37-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 22:55:37 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 22:55:37 volumio sudo[30756]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:37 volumio volumio[30406]: info: Shairport-Sync Started Feb 12 22:55:37 volumio sudo[30793]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:37 volumio volumio[30406]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Feb 12 22:55:37 volumio sudo[30817]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Feb 12 22:55:37 volumio sudo[30817]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:37 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Feb 12 22:55:37 volumio go-librespot[30796]: time="2026-02-12T22:55: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 12 22:55:37 volumio go-librespot[30796]: time="2026-02-12T22:55: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 12 22:55:37 volumio go-librespot[30796]: time="2026-02-12T22:55: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 12 22:55:37 volumio systemd[1]: squeezelite.service: Deactivated successfully. Feb 12 22:55:37 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Feb 12 22:55:37 volumio go-librespot[30796]: time="2026-02-12T22:55:37-06:00" level=info msg="zeroconf server listening on port 44141" Feb 12 22:55:38 volumio sudo[30817]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:38 volumio go-librespot[30796]: time="2026-02-12T22:55:38-06:00" level=debug msg="obtained new client token: AAAj4KQXKfWq0Huu4n0vPS2/M9W7UbgZ8JYliv1CBkD/zp+GHjsYmY95Fqbbx3+6WH22ZoMYqSeQ58lDVLJO6HjHnw02Cr2TxdOEEE1jlai4EZp5+F9Wi7k2019gdiWMC1GDzmQOhJ/deHlCLX1WtEargEQWoZuKL+1smiUt8H2dQEUDY7APQdjloi560YQHs7fMmxopAKERA702Fwhn/jPWPRbevQ0uICuhDnwHCV5RV7zVbt3qwx4=" Feb 12 22:55:38 volumio go-librespot[30796]: time="2026-02-12T22:55:38-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 22:55:38 volumio go-librespot[30796]: time="2026-02-12T22:55:38-06:00" level=debug msg="completed keyexchange" Feb 12 22:55:38 volumio go-librespot[30796]: time="2026-02-12T22:55:38-06:00" level=debug msg="completed challenge" Feb 12 22:55:38 volumio go-librespot[30796]: time="2026-02-12T22:55: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 12 22:55:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 22:55:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 22:55:38 volumio volumio[30406]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 22:55:38 volumio sudo[30822]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 22:55:38 volumio sudo[30822]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:38 volumio sudo[30822]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:38 volumio volumio[30406]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Feb 12 22:55:38 volumio sudo[30826]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Feb 12 22:55:38 volumio sudo[30826]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:38 volumio sudo[30826]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:38 volumio volumio[30406]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Feb 12 22:55:38 volumio sudo[30829]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Feb 12 22:55:38 volumio sudo[30829]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:38 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Feb 12 22:55:38 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Feb 12 22:55:38 volumio mpd[30758]: 2026-02-12T22:55:38 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 12 22:55:38 volumio sudo[30829]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:39 volumio volumio[30406]: info: Initializing connection to go-librespot Websocket Feb 12 22:55:39 volumio volumio[30406]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 22:55:39 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 12 22:55:39 volumio sudo[30633]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:39 volumio sudo[30716]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:39 volumio sudo[30623]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:39 volumio volumio[30406]: error: MPD error: The expression evaluated to a falsy value: Feb 12 22:55:39 volumio volumio[30406]: assert.ok(self.idling) Feb 12 22:55:39 volumio volumio[30406]: error: The expression evaluated to a falsy value: Feb 12 22:55:39 volumio volumio[30406]: assert.ok(self.idling) Feb 12 22:55:39 volumio volumio[30406]: error: MPD error: The expression evaluated to a falsy value: Feb 12 22:55:39 volumio volumio[30406]: assert.ok(self.idling) Feb 12 22:55:39 volumio volumio[30406]: error: The expression evaluated to a falsy value: Feb 12 22:55:39 volumio volumio[30406]: assert.ok(self.idling) Feb 12 22:55:39 volumio volumio[30406]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 22:55:39 volumio volumio[30406]: info: MPD running with PID30758 Feb 12 22:55:39 volumio volumio[30406]: ,establishing connection Feb 12 22:55:39 volumio volumio[30406]: error: updateQueue error: null Feb 12 22:55:39 volumio volumio[30406]: error: updateQueue error: null Feb 12 22:55:39 volumio sudo[30840]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 22:55:39 volumio sudo[30840]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:39 volumio sudo[30840]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:40 volumio volumio[30406]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 22:55:40 volumio sudo[30843]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 22:55:40 volumio sudo[30843]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:40 volumio sudo[30843]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:40 volumio volumio[30406]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 22:55:40 volumio sudo[30846]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 22:55:40 volumio sudo[30846]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:40 volumio sudo[30846]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 12 22:55:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:55:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:55:41 volumio go-librespot[30848]: go-librespot daemon starting... Feb 12 22:55:41 volumio go-librespot[30849]: time="2026-02-12T22:55:41-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 22:55:41 volumio go-librespot[30849]: time="2026-02-12T22:55:41-06:00" level=debug msg="app state loaded" Feb 12 22:55:41 volumio go-librespot[30849]: time="2026-02-12T22:55:41-06:00" level=debug msg="stored credentials not found" Feb 12 22:55:41 volumio go-librespot[30849]: time="2026-02-12T22:55:41-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 22:55:41 volumio volumio[30406]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 22:55:41 volumio sudo[30856]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 22:55:41 volumio sudo[30856]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:41 volumio sudo[30856]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:41 volumio go-librespot[30849]: time="2026-02-12T22:55: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-gew4.spotify.com:80]" Feb 12 22:55:41 volumio go-librespot[30849]: time="2026-02-12T22:55:41-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 12 22:55:41 volumio go-librespot[30849]: time="2026-02-12T22:55:41-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 12 22:55:41 volumio go-librespot[30849]: time="2026-02-12T22:55:41-06:00" level=info msg="zeroconf server listening on port 38591" Feb 12 22:55:41 volumio go-librespot[30849]: time="2026-02-12T22:55:41-06:00" level=debug msg="obtained new client token: AACeTJcn5UsoSD6/JEzlxR+ROFnz8GFa6jmzJS/z9A/1K1xweFJvWkHnmFyKNDhFh6kz3HNSTAOnYA9WoXCOVUZhsZf7tct7YribRaPsgnZYqacjrmfqMLt6nyMbhpNkj7l/ztTRAULksQ8HAyGcxDURdieY7XZuvvGYghn4Rcw1K7XLTlPAw9RusYDFFH5YYnJWJlGopuU9WpbC2LTzCyz9/OsNkbLgL49+2jK8/AFOI34Zpi/Xhp3jjA==" Feb 12 22:55:41 volumio go-librespot[30849]: time="2026-02-12T22:55:41-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 12 22:55:42 volumio go-librespot[30849]: time="2026-02-12T22:55:42-06:00" level=debug msg="completed keyexchange" Feb 12 22:55:42 volumio go-librespot[30849]: time="2026-02-12T22:55:42-06:00" level=debug msg="completed challenge" Feb 12 22:55:42 volumio volumio[30406]: info: Initializing connection to go-librespot Websocket Feb 12 22:55:42 volumio go-librespot[30849]: time="2026-02-12T22:55:42-06:00" level=debug msg="new websocket client" Feb 12 22:55:42 volumio volumio[30406]: info: Connection to go-librespot Websocket established Feb 12 22:55:42 volumio go-librespot[30849]: time="2026-02-12T22:55: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 12 22:55:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 22:55:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 22:55:42 volumio volumio[30406]: info: Connection to go-librespot Websocket closed Feb 12 22:55:42 volumio volumio[30406]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 12 22:55:42 volumio sudo[30861]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 12 22:55:42 volumio sudo[30861]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:42 volumio sudo[30861]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:42 volumio volumio[30406]: info: Completed starting Core Plugins Feb 12 22:55:42 volumio volumio[30406]: info: ------------------------------------------- Feb 12 22:55:42 volumio volumio[30406]: info: ----- MyVolumio plugins startup ---- Feb 12 22:55:42 volumio volumio[30406]: info: ------------------------------------------- Feb 12 22:55:42 volumio sudo[30864]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 12 22:55:42 volumio volumio[30406]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 12 22:55:42 volumio sudo[30864]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:42 volumio sudo[30866]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 12 22:55:42 volumio sudo[30866]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:42 volumio sudo[30870]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 12 22:55:42 volumio sudo[30870]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 22:55:42 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 12 22:55:42 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 12 22:55:42 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 12 22:55:42 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 12 22:55:42 volumio sudo[30864]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:42 volumio mpd_monitor.sh[30872]: MPD Monitor Service: Starting MPD Monitor Service Feb 12 22:55:42 volumio sudo[30866]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:42 volumio volumio[30406]: info: Successfully started MPD Monitor Feb 12 22:55:42 volumio volumio[30406]: info: Successfully started MPD Monitor Feb 12 22:55:42 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 12 22:55:42 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 12 22:55:42 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 12 22:55:42 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 12 22:55:42 volumio mpd_monitor.sh[30875]: MPD Monitor Service: Starting MPD Monitor Service Feb 12 22:55:42 volumio sudo[30870]: pam_unix(sudo:session): session closed for user root Feb 12 22:55:42 volumio volumio[30406]: info: Successfully started MPD Monitor Feb 12 22:55:44 volumio kernel: hwmon hwmon1: Voltage normalised Feb 12 22:55:45 volumio volumio[30406]: info: Getting Spotify volume Feb 12 22:55:45 volumio volumio[30406]: info: Initializing connection to go-librespot Websocket Feb 12 22:55:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 12 22:55:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:55:45 volumio volumio[30406]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 22:55:45 volumio volumio[30406]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 22:55:45 volumio volumio[30406]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 12 22:55:45 volumio volumio[30406]: errno: -111, Feb 12 22:55:45 volumio volumio[30406]: code: 'ECONNREFUSED', Feb 12 22:55:45 volumio volumio[30406]: syscall: 'connect', Feb 12 22:55:45 volumio volumio[30406]: address: '127.0.0.1', Feb 12 22:55:45 volumio volumio[30406]: port: 9879, Feb 12 22:55:45 volumio volumio[30406]: response: undefined Feb 12 22:55:45 volumio volumio[30406]: } Feb 12 22:55:45 volumio volumio[30406]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 22:55:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 22:55:45 volumio go-librespot[30880]: go-librespot daemon starting... Feb 12 22:55:45 volumio go-librespot[30884]: time="2026-02-12T22:55:45-06:00" level=info msg="running go-librespot 0.4.0" Feb 12 22:55:45 volumio go-librespot[30884]: time="2026-02-12T22:55:45-06:00" level=debug msg="app state loaded" Feb 12 22:55:45 volumio go-librespot[30884]: time="2026-02-12T22:55:45-06:00" level=debug msg="stored credentials not found" Feb 12 22:55:45 volumio go-librespot[30884]: time="2026-02-12T22:55:45-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 22:55:45 volumio go-librespot[30884]: time="2026-02-12T22:55:45-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 12 22:55:45 volumio go-librespot[30884]: time="2026-02-12T22:55:45-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 12 22:55:45 volumio go-librespot[30884]: time="2026-02-12T22:55:45-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 12 22:55:45 volumio go-librespot[30884]: time="2026-02-12T22:55:45-06:00" level=info msg="zeroconf server listening on port 42843" Feb 12 22:55:45 volumio go-librespot[30884]: time="2026-02-12T22:55:45-06:00" level=debug msg="obtained new client token: AADA7uIZ+PMhIAXL9hKXfprosKv3efGpNECfLZoxUfJwANPBRlhLf1YZEThV4GapGKS9PI9zVjX9Clq12Sh69wqy4yDJaYNomWA2y53m2jDMTEUSo6GmjK5Qf90Yok0YKbgZyBOnTSixPOFUHBECOKQIKRZnhL7kG4GhJnrCMbzFq4+byWlx0k1jH5f46tLSoZGoq/YfABsYa3Y+2S4m88kISTtdUmZzea7RVXXv91cTLprCXOp/f00zMQ==" Feb 12 22:55:46 volumio go-librespot[30884]: time="2026-02-12T22:55: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 12 22:55:46 volumio go-librespot[30884]: time="2026-02-12T22:55:46-06:00" level=debug msg="connected to ap-guc3.spotify.com:443" Feb 12 22:55:46 volumio go-librespot[30884]: time="2026-02-12T22:55:46-06:00" level=debug msg="completed keyexchange" Feb 12 22:55:46 volumio go-librespot[30884]: time="2026-02-12T22:55:46-06:00" level=debug msg="completed challenge" Feb 12 22:55:46 volumio go-librespot[30884]: time="2026-02-12T22:55: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 12 22:55:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 22:55:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 22:55:46 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 12 22:55:46 volumio sudo[30916]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-12 22:54' Feb 12 22:55:46 volumio sudo[30916]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) 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"