Feb 18 20:48:00 volumio volumio-remote-updater[25144]: [2026-02-18 20:48:00] [connect] Successful connection Feb 18 20:48:00 volumio volumio[21128]: info: Loading plugin "outputs"... Feb 18 20:48:00 volumio volumio[21128]: info: Loading plugin "albumart"... Feb 18 20:48:01 volumio volumio[21128]: info: Plugin example_plugin is not enabled Feb 18 20:48:01 volumio volumio[21128]: info: Loading plugin "inputs"... Feb 18 20:48:01 volumio volumio[21128]: info: Loading plugin "updater_comm"... Feb 18 20:48:01 volumio volumio[21128]: info: Plugin mpdemulation is not enabled Feb 18 20:48:01 volumio volumio[21128]: info: Loading plugin "rest_api"... Feb 18 20:48:01 volumio volumio[21128]: info: Loading plugin "websocket"... Feb 18 20:48:01 volumio volumio[21128]: info: Starting Socket.io Server version 1.7.4 Feb 18 20:48:01 volumio volumio[21128]: info: Loading plugin "RoonBridge"... Feb 18 20:48:01 volumio volumio[21128]: info: Applying required configuration parameters for plugin RoonBridge Feb 18 20:48:01 volumio volumio[21128]: info: Loading i18n strings for locale en Feb 18 20:48:01 volumio volumio[21128]: Updating browse sources language Feb 18 20:48:01 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:48:02 volumio volumio[21244]: Forking 3 albumart workers Feb 18 20:48:02 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 20:48:02 volumio volumio[21128]: info: CoreCommandRouter::initPlayerControls Feb 18 20:48:02 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:02 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:02 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:02 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:02 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:02 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:02 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:02 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:02 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 20:48:02 volumio volumio[21128]: Express server listening on port 3000 Feb 18 20:48:02 volumio volumio[21128]: [Metrics] WebUI: 16s 155.87ms Feb 18 20:48:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 18 20:48:02 volumio volumio[21128]: info: CoreStateMachine::resetVolumioState Feb 18 20:48:02 volumio volumio[21128]: info: CoreStateMachine::getcurrentVolume Feb 18 20:48:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:02 volumio volumio[21128]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 20:48:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:02 volumio go-librespot[21286]: go-librespot daemon starting... Feb 18 20:48:02 volumio sudo[21298]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 20:48:02 volumio sudo[21298]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:48:02 volumio go-librespot[21290]: time="2026-02-18T20:48:02+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:48:02 volumio sudo[21298]: pam_unix(sudo:session): session closed for user root Feb 18 20:48:02 volumio go-librespot[21290]: time="2026-02-18T20:48:02+07:00" level=debug msg="app state loaded" Feb 18 20:48:02 volumio sudo[21295]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 20:48:02 volumio sudo[21295]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:48:02 volumio go-librespot[21290]: time="2026-02-18T20:48:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:48:02 volumio sudo[21295]: pam_unix(sudo:session): session closed for user root Feb 18 20:48:02 volumio volumio[21128]: info: Volumio Network Manager: Network status updated: 1 Feb 18 20:48:03 volumio volumio[21128]: info: VolumeController:: Volume=100 Mute =false Feb 18 20:48:03 volumio volumio[21128]: info: CoreStateMachine::pushState Feb 18 20:48:03 volumio volumio[21128]: info: CorePlayQueue::getTrack 0 Feb 18 20:48:03 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 20:48:03 volumio volumio[21128]: info: CoreCommandRouter::volumioPushState Feb 18 20:48:03 volumio volumio[21128]: info: CoreStateMachine::updateTrackBlock Feb 18 20:48:03 volumio volumio[21128]: info: CorePlayQueue::getTrackBlock Feb 18 20:48:03 volumio volumio[21128]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 20:48:03 volumio go-librespot[21290]: time="2026-02-18T20:48:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 20:48:03 volumio go-librespot[21290]: time="2026-02-18T20:48:03+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 20:48:03 volumio go-librespot[21290]: time="2026-02-18T20:48:03+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 20:48:03 volumio go-librespot[21290]: time="2026-02-18T20:48:03+07:00" level=info msg="zeroconf server listening on port 43397" Feb 18 20:48:03 volumio volumio-remote-updater[25144]: [2026-02-18 20:48:03] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771422480 101 Feb 18 20:48:03 volumio volumio[21128]: 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 18 20:48:03 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:48:03 volumio volumio[21128]: info: Reloading queue from file Feb 18 20:48:03 volumio volumio[21128]: info: CoreStateMachine::setRepeat null single undefined Feb 18 20:48:03 volumio volumio[21128]: info: CoreStateMachine::pushState Feb 18 20:48:03 volumio volumio[21128]: info: CorePlayQueue::getTrack 0 Feb 18 20:48:03 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 20:48:03 volumio volumio[21128]: info: CoreCommandRouter::volumioPushState Feb 18 20:48:03 volumio volumio[21128]: info: CoreStateMachine::setRandom null Feb 18 20:48:03 volumio volumio[21128]: info: CoreStateMachine::pushState Feb 18 20:48:03 volumio go-librespot[21290]: time="2026-02-18T20:48:03+07:00" level=debug msg="obtained new client token: AACJc1HQWhyJ301OuGdtrX6WnJ0kcrWtKQcvS5Bm49aNGHnUsKSStwAaqk6ovUCGlYyt+wJWvs9i1JSSDd2WY1hsyyJxKCr3/OG8+XEdbVG697CYowLhiVq0kif2qVu0ym1KEdKN4ZlFnuI/goU/UX2i759TccaqGqGM0XAxco3PV11Nq4+z23jsYUpGGhiUOOevwKnbhd8pWJOYPtkYTQ8gvXvlQ07cSf4bb06aQwPUzQk0aEyQ09VSVg==" Feb 18 20:48:03 volumio volumio[21128]: info: CorePlayQueue::getTrack 0 Feb 18 20:48:03 volumio volumio[21128]: info: CoreCommandRouter::volumioPushState Feb 18 20:48:03 volumio volumio[21128]: info: Setting Device type: Raspberry PI Feb 18 20:48:03 volumio volumio[21128]: info: Completed loading Core Plugins Feb 18 20:48:03 volumio volumio[21128]: info: Preparing to generate the ALSA configuration file Feb 18 20:48:03 volumio go-librespot[21290]: time="2026-02-18T20:48:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:48:03 volumio volumio[21128]: info: VolumeController:: Volume=100 Mute =false Feb 18 20:48:03 volumio volumio[21128]: info: CoreStateMachine::pushState Feb 18 20:48:03 volumio volumio[21128]: info: CorePlayQueue::getTrack 0 Feb 18 20:48:03 volumio volumio[21128]: info: CoreCommandRouter::volumioPushState Feb 18 20:48:03 volumio go-librespot[21290]: time="2026-02-18T20:48:03+07:00" level=debug msg="completed keyexchange" Feb 18 20:48:03 volumio go-librespot[21290]: time="2026-02-18T20:48:03+07:00" level=debug msg="completed challenge" Feb 18 20:48:03 volumio volumio[21128]: info: Asound.conf file unchanged, so no further update is needed Feb 18 20:48:03 volumio volumio[21128]: info: Output device has changed, restarting MPD Feb 18 20:48:03 volumio go-librespot[21290]: time="2026-02-18T20:48:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 20:48:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:48:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:48:03 volumio volumio[21128]: info: Output device has changed, restarting Shairport Sync Feb 18 20:48:03 volumio sudo[21315]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 18 20:48:03 volumio sudo[21317]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 20:48:03 volumio sudo[21317]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:48:03 volumio sudo[21315]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:48:03 volumio sudo[21317]: pam_unix(sudo:session): session closed for user root Feb 18 20:48:03 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:03 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:48:03 volumio sudo[21319]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 20:48:03 volumio sudo[21319]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:48:03 volumio volumio[21128]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 20:48:03 volumio volumio[21128]: info: ___________ START PLUGINS ___________ Feb 18 20:48:03 volumio volumio[21128]: info: ControllerMpd::onStart: Initializing MPD Feb 18 20:48:03 volumio volumio[21128]: info: Creating MPD Configuration file Feb 18 20:48:03 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 18 20:48:03 volumio sudo[21315]: pam_unix(sudo:session): session closed for user root Feb 18 20:48:03 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 20:48:04 volumio volumio[21128]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 20:48:04 volumio volumio[21128]: info: [1771422484014] CoreMusicLibrary::Adding element Media Servers Feb 18 20:48:04 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:48:04 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 20:48:04 volumio sudo[21328]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 20:48:04 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 20:48:04 volumio systemd[1]: mpd.service: Consumed 7.336s CPU time. Feb 18 20:48:04 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 20:48:04 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 20:48:04 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 20:48:04 volumio volumio[21128]: info: UPNP Browser: Client initialized successfully Feb 18 20:48:04 volumio sudo[21328]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:48:04 volumio sudo[21328]: pam_unix(sudo:session): session closed for user root Feb 18 20:48:04 volumio sudo[21330]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 20:48:04 volumio sudo[21330]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:48:04 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 20:48:04 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 20:48:04 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:04 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:48:04 volumio volumio[21128]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 20:48:04 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:04 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:48:04 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 20:48:04 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 20:48:04 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 20:48:04 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 20:48:04 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 20:48:04 volumio volumio[21128]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 20:48:04 volumio volumio[21128]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 20:48:04 volumio volumio[21128]: info: [1771422484342] CoreMusicLibrary::Adding element Last_100 Feb 18 20:48:04 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:48:04 volumio volumio[21128]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 20:48:04 volumio volumio[21128]: info: [1771422484351] CoreMusicLibrary::Adding element Webradio Feb 18 20:48:04 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:48:04 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 20:48:04 volumio volumio[21128]: info: Initializing BBC Radios Feb 18 20:48:04 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 20:48:04 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 20:48:04 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 20:48:04 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:48:04 volumio volumio[21128]: info: Creating Spotify config file Feb 18 20:48:04 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:04 volumio sudo[21344]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 20:48:04 volumio sudo[21344]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 20:48:04 volumio sudo[21344]: pam_unix(sudo:session): session closed for user root Feb 18 20:48:05 volumio volumio[21256]: Starting albumart workers Feb 18 20:48:05 volumio volumio[21254]: Starting albumart workers Feb 18 20:48:05 volumio volumio[21128]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 20:48:05 volumio volumio[21128]: info: [1771422485687] CoreMusicLibrary::Adding element YouTube Music Feb 18 20:48:05 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:48:05 volumio volumio[21128]: Cannot find translation for source YouTube Music Feb 18 20:48:05 volumio volumio[21128]: info: Volumio Calling Home Feb 18 20:48:05 volumio volumio[21255]: Starting albumart workers Feb 18 20:48:05 volumio sudo[21361]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 20:48:05 volumio sudo[21361]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:48:05 volumio sudo[21361]: pam_unix(sudo:session): session closed for user root Feb 18 20:48:06 volumio volumio[21128]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 20:48:06 volumio volumio[21128]: info: Discovery: Found device Volumio Feb 18 20:48:06 volumio volumio[21128]: info: CoreCommandRouter::volumioGetState Feb 18 20:48:06 volumio volumio[21128]: info: CorePlayQueue::getTrack 0 Feb 18 20:48:06 volumio volumio[21128]: info: MPD Permissions set Feb 18 20:48:06 volumio volumio[21128]: info: MPD Permissions set Feb 18 20:48:06 volumio volumio[21128]: info: Upmpdcli Daemon Started Feb 18 20:48:06 volumio volumio[21128]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 20:48:06 volumio volumio[21128]: info: Discovery: Found device Volumio Feb 18 20:48:06 volumio volumio[21128]: info: CoreCommandRouter::volumioGetState Feb 18 20:48:06 volumio volumio[21128]: info: CorePlayQueue::getTrack 0 Feb 18 20:48:06 volumio volumio[21128]: info: Spotify config file written Feb 18 20:48:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 18 20:48:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:06 volumio go-librespot[21367]: go-librespot daemon starting... Feb 18 20:48:06 volumio volumio[21128]: 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 18 20:48:06 volumio sudo[21368]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 20:48:06 volumio sudo[21368]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:48:06 volumio volumio[21128]: info: Volumio called home Feb 18 20:48:06 volumio go-librespot[21369]: time="2026-02-18T20:48:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:48:06 volumio go-librespot[21369]: time="2026-02-18T20:48:06+07:00" level=debug msg="app state loaded" Feb 18 20:48:06 volumio go-librespot[21369]: time="2026-02-18T20:48:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:48:06 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:06 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:06 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:07 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:07 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:07 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:07 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:07 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:07 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:48:07 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:07 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 18 20:48:07 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 18 20:48:07 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:07 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:07 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:07 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:07 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:07 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:07 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:07 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:07 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:48:07 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:07 volumio volumio[21128]: info: No need to fix Spotify hosts Feb 18 20:48:07 volumio go-librespot[21383]: go-librespot daemon starting... Feb 18 20:48:07 volumio sudo[21368]: pam_unix(sudo:session): session closed for user root Feb 18 20:48:07 volumio go-librespot[21387]: time="2026-02-18T20:48:07+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:48:07 volumio go-librespot[21387]: time="2026-02-18T20:48:07+07:00" level=debug msg="app state loaded" Feb 18 20:48:07 volumio go-librespot[21387]: time="2026-02-18T20:48:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:48:08 volumio go-librespot[21387]: time="2026-02-18T20:48:08+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 20:48:08 volumio go-librespot[21387]: time="2026-02-18T20:48:08+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 20:48:08 volumio go-librespot[21387]: time="2026-02-18T20:48:08+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 20:48:08 volumio go-librespot[21387]: time="2026-02-18T20:48:08+07:00" level=info msg="zeroconf server listening on port 41465" Feb 18 20:48:08 volumio volumio[21128]: info: Starting Shairport Sync Feb 18 20:48:08 volumio volumio[21128]: info: Starting Shairport Sync Feb 18 20:48:08 volumio volumio[21128]: info: Starting Shairport Sync Feb 18 20:48:08 volumio go-librespot[21387]: time="2026-02-18T20:48:08+07:00" level=debug msg="obtained new client token: AAAxNJgVY5a1pW0YFqciGoL7HafNta0D2fNAwhG3c9a/W9McWk204d2u9IqfiqKlzaZyf7IfF8FK5knjPJX0N+ABW/BF8lEHPuktJhmPC9uoTmxBdBt1K9kdD9esLQzaIMJNwSA777KSqEI+YfKVaMaIGtfV8CBvWJhVXucoGPxte5HYZltItBMlhC7CeIRWWfNhbekcsc0PCgseyt71Db3CzlTkSnIf7SkRHAf/n/cWuvZrqVHF+HYRrQ==" Feb 18 20:48:08 volumio sudo[21414]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 20:48:08 volumio sudo[21414]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:48:08 volumio sudo[21419]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 20:48:08 volumio sudo[21419]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:48:08 volumio sudo[21417]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 20:48:08 volumio sudo[21417]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:48:08 volumio go-librespot[21387]: time="2026-02-18T20:48:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:48:08 volumio volumio[21128]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 20:48:08 volumio volumio[21128]: SPOTIFY: BQCSJm1QFE8-OWRUwYgk7aPlbGL-sBoxqgW36JytGiE-BFlKhuF_1nDE5qOSnD3P4TB-mFNoRsX65jSCjAZdsb2IJRx7htPbg9gNn-rrxVXejbYRhDuVK6vJVng2xCQs5UK7xcbwLiRsfGrMFGCcTU_NnwE2yl8NRr_o25YQ5C14mse41iONN_C2MbEev5Ndhgq92lBdDMRk6V55acOaFEp_JNWwIFlUSiczmUels7PUaMMfxk6fXm0ELrH-tzEUXm0Gg85MyrtXwOtvwIr7Raz4sXxp9ywJpr24RhqYc9sZfQV_JQG_02Sf Feb 18 20:48:08 volumio volumio[21128]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 20:48:08 volumio volumio[21128]: info: New Spotify access token = BQCSJm1QFE8-OWRUwYgk7aPlbGL-sBoxqgW36JytGiE-BFlKhuF_1nDE5qOSnD3P4TB-mFNoRsX65jSCjAZdsb2IJRx7htPbg9gNn-rrxVXejbYRhDuVK6vJVng2xCQs5UK7xcbwLiRsfGrMFGCcTU_NnwE2yl8NRr_o25YQ5C14mse41iONN_C2MbEev5Ndhgq92lBdDMRk6V55acOaFEp_JNWwIFlUSiczmUels7PUaMMfxk6fXm0ELrH-tzEUXm0Gg85MyrtXwOtvwIr7Raz4sXxp9ywJpr24RhqYc9sZfQV_JQG_02Sf Feb 18 20:48:08 volumio volumio[21128]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 20:48:08 volumio go-librespot[21387]: time="2026-02-18T20:48:08+07:00" level=debug msg="completed keyexchange" Feb 18 20:48:08 volumio go-librespot[21387]: time="2026-02-18T20:48:08+07:00" level=debug msg="completed challenge" Feb 18 20:48:08 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 20:48:08 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 20:48:08 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 20:48:08 volumio systemd[1]: shairport-sync.service: Consumed 2.280s CPU time. Feb 18 20:48:08 volumio volumio[21128]: info: CoreCommandRouter::volumioGetState Feb 18 20:48:08 volumio volumio[21128]: info: CorePlayQueue::getTrack 0 Feb 18 20:48:08 volumio go-librespot[21387]: time="2026-02-18T20:48:08+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 20:48:08 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 20:48:08 volumio sudo[21417]: pam_unix(sudo:session): session closed for user root Feb 18 20:48:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:48:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:48:08 volumio sudo[21419]: pam_unix(sudo:session): session closed for user root Feb 18 20:48:08 volumio sudo[21414]: pam_unix(sudo:session): session closed for user root Feb 18 20:48:09 volumio volumio[21128]: info: Shairport-Sync Started Feb 18 20:48:09 volumio volumio[21128]: Error adding Membership: Error: addMembership EINVAL Feb 18 20:48:09 volumio volumio[21128]: info: Shairport-Sync Started Feb 18 20:48:09 volumio volumio[21128]: info: Shairport-Sync Started Feb 18 20:48:09 volumio volumio[21128]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 18 20:48:09 volumio volumio[21128]: info: Spotify Successfully logged in Feb 18 20:48:09 volumio volumio[21128]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 20:48:09 volumio volumio[21128]: info: [1771422489389] CoreMusicLibrary::Adding element Spotify Feb 18 20:48:09 volumio volumio[21128]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:48:09 volumio volumio[21128]: Cannot find translation for source YouTube Music Feb 18 20:48:09 volumio volumio[21128]: Cannot find translation for source Spotify Feb 18 20:48:09 volumio volumio[21128]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 20:48:09 volumio volumio[21128]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 20:48:10 volumio volumio[21128]: info: VolumeController:: Volume=100 Mute =false Feb 18 20:48:10 volumio volumio[21128]: info: CoreCommandRouter::volumioGetState Feb 18 20:48:10 volumio volumio[21128]: info: CorePlayQueue::getTrack 0 Feb 18 20:48:10 volumio volumio[21128]: info: CoreStateMachine::pushState Feb 18 20:48:10 volumio volumio[21128]: info: CorePlayQueue::getTrack 0 Feb 18 20:48:10 volumio volumio[21128]: info: CoreCommandRouter::volumioPushState Feb 18 20:48:11 volumio volumio[21128]: info: go-librespot daemon successfully initialized Feb 18 20:48:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 18 20:48:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:11 volumio go-librespot[21455]: go-librespot daemon starting... Feb 18 20:48:11 volumio go-librespot[21456]: time="2026-02-18T20:48:11+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:48:11 volumio go-librespot[21456]: time="2026-02-18T20:48:11+07:00" level=debug msg="app state loaded" Feb 18 20:48:11 volumio go-librespot[21456]: time="2026-02-18T20:48:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:48:11 volumio mpd[21359]: 2026-02-18T20:48:11 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 20:48:11 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 20:48:11 volumio sudo[21330]: pam_unix(sudo:session): session closed for user root Feb 18 20:48:11 volumio sudo[21319]: pam_unix(sudo:session): session closed for user root Feb 18 20:48:12 volumio volumio[21128]: error: MPD error: The expression evaluated to a falsy value: Feb 18 20:48:12 volumio volumio[21128]: assert.ok(self.idling) Feb 18 20:48:12 volumio volumio[21128]: error: The expression evaluated to a falsy value: Feb 18 20:48:12 volumio volumio[21128]: assert.ok(self.idling) Feb 18 20:48:12 volumio volumio[21128]: error: updateQueue error: null Feb 18 20:48:12 volumio volumio[21128]: info: MPD running with PID21359 Feb 18 20:48:12 volumio volumio[21128]: ,establishing connection Feb 18 20:48:12 volumio volumio[21128]: info: Completed starting Core Plugins Feb 18 20:48:12 volumio volumio[21128]: info: ------------------------------------------- Feb 18 20:48:12 volumio volumio[21128]: info: ----- MyVolumio plugins startup ---- Feb 18 20:48:12 volumio volumio[21128]: info: ------------------------------------------- Feb 18 20:48:12 volumio volumio[21128]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 20:48:12 volumio volumio[21128]: error: updateQueue error: null Feb 18 20:48:12 volumio go-librespot[21456]: time="2026-02-18T20:48:12+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 20:48:12 volumio go-librespot[21456]: time="2026-02-18T20:48:12+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 20:48:12 volumio go-librespot[21456]: time="2026-02-18T20:48:12+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 20:48:12 volumio go-librespot[21456]: time="2026-02-18T20:48:12+07:00" level=info msg="zeroconf server listening on port 33513" Feb 18 20:48:12 volumio go-librespot[21456]: time="2026-02-18T20:48:12+07:00" level=debug msg="obtained new client token: AADIgMu9EcRolykyCOUKVN4dYzelti0vWiOnvOFPC3VXoIDDtIta/wUXWj54bvLM53SX+UoDf6jDOpq4fd5+QZZreyP7gdIh5yx/6E/0RxkXnYjtdX++47fs/PR0H12Wj6Xg90/8zrUwQYl0p05vATtbgpNgvWcV7caP8xP31FyRKd//KSsz0yVv05Hhb2tCaSvr/XzGgMsnCW0VXLbnHL/Z9l0sabCVMRu9aMCDHnu07CPwuR9tv6Vm0A==" Feb 18 20:48:12 volumio go-librespot[21456]: time="2026-02-18T20:48:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:48:12 volumio go-librespot[21456]: time="2026-02-18T20:48:12+07:00" level=debug msg="completed keyexchange" Feb 18 20:48:12 volumio go-librespot[21456]: time="2026-02-18T20:48:12+07:00" level=debug msg="completed challenge" Feb 18 20:48:13 volumio go-librespot[21456]: time="2026-02-18T20:48:13+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 20:48:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:48:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:48:14 volumio volumio[21128]: info: Initializing connection to go-librespot Websocket Feb 18 20:48:14 volumio volumio[21128]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 20:48:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 18 20:48:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:16 volumio go-librespot[21468]: go-librespot daemon starting... Feb 18 20:48:16 volumio go-librespot[21469]: time="2026-02-18T20:48:16+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:48:16 volumio go-librespot[21469]: time="2026-02-18T20:48:16+07:00" level=debug msg="app state loaded" Feb 18 20:48:16 volumio go-librespot[21469]: time="2026-02-18T20:48:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:48:16 volumio go-librespot[21469]: time="2026-02-18T20:48:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 20:48:16 volumio go-librespot[21469]: time="2026-02-18T20:48:16+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 20:48:16 volumio go-librespot[21469]: time="2026-02-18T20:48:16+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 20:48:16 volumio go-librespot[21469]: time="2026-02-18T20:48:16+07:00" level=info msg="zeroconf server listening on port 33025" Feb 18 20:48:17 volumio volumio[21128]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 20:48:17 volumio volumio[21128]: info: Initializing connection to go-librespot Websocket Feb 18 20:48:17 volumio go-librespot[21469]: time="2026-02-18T20:48:17+07:00" level=debug msg="new websocket client" Feb 18 20:48:17 volumio go-librespot[21469]: time="2026-02-18T20:48:17+07:00" level=debug msg="obtained new client token: AABl0+eVj1WOyI6HTRon8pnyxtHPrHsHF+oMRNlB3M6DckXqvf3uttA2LAegvEYcTr5dWJO16inmMP3eaiCjMVRpUP8FBQbEZXAzS7ePecR0TEUJ56+sNrMmDuVBE1INrLYUgH8kMDXwRB1BsfKpvtGBwkG27sXb+Ag2+9NwckSPPcVRyirINywN6sZqNsx4YiCHNearcaqddsZ/mXLHMeozTlB4cqkQzB+zwPtlnRDoy/IJDCL7uWc=" Feb 18 20:48:17 volumio volumio[21128]: info: Connection to go-librespot Websocket established Feb 18 20:48:17 volumio go-librespot[21469]: time="2026-02-18T20:48:17+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 18 20:48:17 volumio go-librespot[21469]: time="2026-02-18T20:48:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 18 20:48:17 volumio go-librespot[21469]: time="2026-02-18T20:48:17+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 20:48:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:48:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:48:17 volumio volumio[21128]: info: Connection to go-librespot Websocket closed Feb 18 20:48:20 volumio volumio[21128]: info: Getting Spotify volume Feb 18 20:48:20 volumio volumio[21128]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 20:48:20 volumio volumio[21128]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 20:48:20 volumio volumio[21128]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 18 20:48:20 volumio volumio[21128]: errno: -111, Feb 18 20:48:20 volumio volumio[21128]: code: 'ECONNREFUSED', Feb 18 20:48:20 volumio volumio[21128]: syscall: 'connect', Feb 18 20:48:20 volumio volumio[21128]: address: '127.0.0.1', Feb 18 20:48:20 volumio volumio[21128]: port: 9879, Feb 18 20:48:20 volumio volumio[21128]: response: undefined Feb 18 20:48:20 volumio volumio[21128]: } Feb 18 20:48:20 volumio volumio[21128]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 20:48:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 18 20:48:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:20 volumio go-librespot[21487]: go-librespot daemon starting... Feb 18 20:48:20 volumio go-librespot[21489]: time="2026-02-18T20:48:20+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:48:20 volumio go-librespot[21489]: time="2026-02-18T20:48:20+07:00" level=debug msg="app state loaded" Feb 18 20:48:20 volumio go-librespot[21489]: time="2026-02-18T20:48:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:48:21 volumio go-librespot[21489]: time="2026-02-18T20:48:21+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 20:48:21 volumio go-librespot[21489]: time="2026-02-18T20:48:21+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 20:48:21 volumio go-librespot[21489]: time="2026-02-18T20:48:21+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 20:48:21 volumio go-librespot[21489]: time="2026-02-18T20:48:21+07:00" level=info msg="zeroconf server listening on port 43459" Feb 18 20:48:21 volumio go-librespot[21489]: time="2026-02-18T20:48:21+07:00" level=debug msg="obtained new client token: AACwWqLZ8HN+F15ruVmI85tA308kAmL3Ub6KV9BOHvr1fhZY7/bqHVt4Bs6BKRPh9N9ARkl6S4MZSq0ZqPy/l6GLFOlhILoBakYsQNsN1zeHuEx5+UgV43BsRBY1Ttg0xk2dvDS5oZ8tiGtz4yQTNg3Hk0AGe367qiPlflvWd/6u+BaCqkH9w5qIvvf5BIts6KuD1t4VnU+lfiZv9TPjXBJgfHH97+l7vhyjf9VUifNOuormLjkZpMxRtQ==" Feb 18 20:48:21 volumio go-librespot[21489]: time="2026-02-18T20:48:21+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 18 20:48:21 volumio go-librespot[21489]: time="2026-02-18T20:48:21+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.241.202:443: connect: connection refused" Feb 18 20:48:21 volumio go-librespot[21489]: time="2026-02-18T20:48:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 18 20:48:21 volumio go-librespot[21489]: time="2026-02-18T20:48:21+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 20:48:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:48:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:48:21 volumio sudo[21512]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 20:47' Feb 18 20:48:21 volumio sudo[21512]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:48:22 volumio sudo[21512]: pam_unix(sudo:session): session closed for user root Feb 18 20:48:22 volumio volumio-remote-updater[25144]: [2026-02-18 20:48:22] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 18 20:48:22 volumio volumio-remote-updater[25144]: [2026-02-18 20:48:22] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 18 20:48:22 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:48:22 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 18 20:48:22 volumio systemd[1]: volumio.service: Consumed 53.578s CPU time. Feb 18 20:48:22 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 20:48:22 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 20:48:22 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 22415. Feb 18 20:48:22 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 20:48:22 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 18 20:48:22 volumio systemd[1]: volumio.service: Consumed 53.578s CPU time. Feb 18 20:48:22 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 18 20:48:22 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 20:48:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 18 20:48:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:24 volumio go-librespot[21539]: go-librespot daemon starting... Feb 18 20:48:24 volumio go-librespot[21540]: time="2026-02-18T20:48:24+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:48:24 volumio go-librespot[21540]: time="2026-02-18T20:48:24+07:00" level=debug msg="app state loaded" Feb 18 20:48:24 volumio go-librespot[21540]: time="2026-02-18T20:48:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:48:25 volumio go-librespot[21540]: time="2026-02-18T20:48:25+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 20:48:25 volumio go-librespot[21540]: time="2026-02-18T20:48:25+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 20:48:25 volumio go-librespot[21540]: time="2026-02-18T20:48:25+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 20:48:25 volumio go-librespot[21540]: time="2026-02-18T20:48:25+07:00" level=info msg="zeroconf server listening on port 43051" Feb 18 20:48:25 volumio go-librespot[21540]: time="2026-02-18T20:48:25+07:00" level=debug msg="obtained new client token: AAA9LGkV17q4u30u1Rdz4CoRmv7PJ8Cv17KIUi7AcjGrysBBdMS7d8tj7p5H5h+2eJM1ZHecCD5olC3ErSh+SL8i6sD7di0SFNyJ1aryf5TSKrZx0LuI47hsTfVOFXcWLEBHaULkrHXUzJ/30xl/oT260Nilc1QfnK9FgTZcjxQW8zlFoF9IspSOq/fQKxea5ycXptd40XLZVgDBWzdXwTNhnivGN6F9k2x6JcNviikfTqFDes9KR3ZV2Q==" Feb 18 20:48:25 volumio go-librespot[21540]: time="2026-02-18T20:48:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:48:25 volumio go-librespot[21540]: time="2026-02-18T20:48:25+07:00" level=debug msg="completed keyexchange" Feb 18 20:48:25 volumio go-librespot[21540]: time="2026-02-18T20:48:25+07:00" level=debug msg="completed challenge" Feb 18 20:48:26 volumio go-librespot[21540]: time="2026-02-18T20:48:26+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 20:48:26 volumio volumio[21524]: info: ------------------------------------------- Feb 18 20:48:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:48:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:48:26 volumio volumio[21524]: info: ----- Volumio3 ---- Feb 18 20:48:26 volumio volumio[21524]: info: ------------------------------------------- Feb 18 20:48:26 volumio volumio[21524]: info: ----- System startup ---- Feb 18 20:48:26 volumio volumio[21524]: info: ------------------------------------------- Feb 18 20:48:27 volumio volumio-remote-updater[25144]: [2026-02-18 20:48:27] [connect] Successful connection Feb 18 20:48:27 volumio volumio[21524]: info: MYVOLUMIO Environment detected Feb 18 20:48:27 volumio volumio[21524]: info: Plugin folders cleanup Feb 18 20:48:27 volumio volumio[21524]: info: Scanning into folder /volumio/app/plugins/ Feb 18 20:48:27 volumio volumio[21524]: info: Scanning category audio_interface Feb 18 20:48:27 volumio volumio[21524]: info: Scanning category miscellanea Feb 18 20:48:27 volumio volumio[21524]: info: Scanning category music_service Feb 18 20:48:27 volumio volumio[21524]: info: Scanning category plugins.json Feb 18 20:48:27 volumio volumio[21524]: info: Scanning category system_controller Feb 18 20:48:27 volumio volumio[21524]: info: Scanning category user_interface Feb 18 20:48:27 volumio volumio[21524]: info: Scanning into folder /data/plugins/ Feb 18 20:48:27 volumio volumio[21524]: info: Scanning category music_service Feb 18 20:48:27 volumio volumio[21524]: info: Plugin folders cleanup completed Feb 18 20:48:27 volumio volumio[21524]: info: ------------------------------------------- Feb 18 20:48:27 volumio volumio[21524]: info: ----- Core plugins startup ---- Feb 18 20:48:27 volumio volumio[21524]: info: ------------------------------------------- Feb 18 20:48:27 volumio volumio[21524]: info: Loading plugins from folder /volumio/app/plugins/ Feb 18 20:48:27 volumio volumio[21524]: info: Adding plugin upnp to MyMusic Plugins Feb 18 20:48:27 volumio volumio[21524]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 18 20:48:27 volumio volumio[21524]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 18 20:48:27 volumio volumio[21524]: info: Loading plugins from folder /data/plugins/ Feb 18 20:48:27 volumio volumio[21524]: info: Loading plugin "system"... Feb 18 20:48:27 volumio volumio[21524]: info: Loading plugin "appearance"... Feb 18 20:48:28 volumio nmbd[966]: [2026/02/18 20:48:28.353045, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) Feb 18 20:48:28 volumio nmbd[966]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.1.23 for name WORKGROUP<1d>. Feb 18 20:48:28 volumio nmbd[966]: This response was from IP 192.168.1.237, reporting an IP address of 192.168.1.237. Feb 18 20:48:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 18 20:48:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:29 volumio go-librespot[21560]: go-librespot daemon starting... Feb 18 20:48:29 volumio go-librespot[21561]: time="2026-02-18T20:48:29+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:48:29 volumio go-librespot[21561]: time="2026-02-18T20:48:29+07:00" level=debug msg="app state loaded" Feb 18 20:48:29 volumio go-librespot[21561]: time="2026-02-18T20:48:29+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:48:29 volumio volumio[21524]: info: Loading plugin "network"... Feb 18 20:48:29 volumio volumio[21524]: info: Refreshing Cached IP Addresses Feb 18 20:48:29 volumio sudo[21568]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 20:48:29 volumio sudo[21568]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:48:29 volumio sudo[21570]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 20:48:29 volumio sudo[21570]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:48:29 volumio sudo[21568]: pam_unix(sudo:session): session closed for user root Feb 18 20:48:29 volumio sudo[21570]: pam_unix(sudo:session): session closed for user root Feb 18 20:48:29 volumio volumio[21524]: info: Loading plugin "services"... Feb 18 20:48:29 volumio volumio[21524]: info: Loading plugin "alsa_controller"... Feb 18 20:48:29 volumio sudo[21579]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 18 20:48:29 volumio sudo[21579]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:48:29 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 20:48:29 volumio volumio[21524]: info: Loading plugin "wizard"... Feb 18 20:48:29 volumio volumio[21524]: info: Loading plugin "networkfs"... Feb 18 20:48:29 volumio go-librespot[21561]: time="2026-02-18T20:48:29+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 20:48:29 volumio go-librespot[21561]: time="2026-02-18T20:48:29+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 20:48:29 volumio go-librespot[21561]: time="2026-02-18T20:48:29+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 20:48:29 volumio volumio[21524]: info: Starting Udev Watcher for removable devices Feb 18 20:48:30 volumio go-librespot[21561]: time="2026-02-18T20:48:30+07:00" level=info msg="zeroconf server listening on port 37777" Feb 18 20:48:30 volumio volumio[21524]: info: Ignoring mount for partition: boot Feb 18 20:48:30 volumio volumio[21524]: info: Ignoring mount for partition: volumio Feb 18 20:48:30 volumio volumio[21524]: info: Ignoring mount for partition: volumio_data Feb 18 20:48:30 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 20:48:30 volumio volumio[21524]: info: Loading plugin "volumio_command_line_client"... Feb 18 20:48:30 volumio volumio[21524]: info: Loading plugin "upnp"... Feb 18 20:48:30 volumio volumio[21524]: info: [1771422510080] Starting Upmpd Daemon Feb 18 20:48:30 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 20:48:30 volumio volumio[21524]: info: Loading plugin "my_music"... Feb 18 20:48:30 volumio volumio[21524]: info: Loading plugin "mpd"... Feb 18 20:48:30 volumio go-librespot[21561]: time="2026-02-18T20:48:30+07:00" level=debug msg="obtained new client token: AAAZuc55U+JAIdUOwqYLU3e5PYyZLa0QpdKFvw6WerQCq+aZSQ+hr2xVr7GTrO7bVmBcIXKnDKhcCVjXqfRjxXq0W5zXmGTxfV9BwK/6hETh/7PgpmmIgZSvQuhfPNJ0cg27dOfTnpjLqUDAIO9h04s3+NMpnT3OAQSly5yY5TW0i6g5EXK2HSgHfxWVqM3HNS6HrC22ZNDM4p843m7ynfuXwgHDUfw1KEn6NKNNTDaYj76Xlh6Ay6KuXg==" Feb 18 20:48:30 volumio go-librespot[21561]: time="2026-02-18T20:48:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:48:30 volumio go-librespot[21561]: time="2026-02-18T20:48:30+07:00" level=debug msg="completed keyexchange" Feb 18 20:48:30 volumio go-librespot[21561]: time="2026-02-18T20:48:30+07:00" level=debug msg="completed challenge" Feb 18 20:48:30 volumio go-librespot[21561]: time="2026-02-18T20:48:30+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 20:48:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:48:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:48:30 volumio volumio[21524]: info: Loading plugin "upnp_browser"... Feb 18 20:48:32 volumio sudo[21579]: pam_unix(sudo:session): session closed for user root Feb 18 20:48:33 volumio volumio[21524]: info: Starting UPNP Browser Feb 18 20:48:33 volumio volumio[21524]: info: Loading plugin "alarm-clock"... Feb 18 20:48:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 18 20:48:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:33 volumio go-librespot[21603]: go-librespot daemon starting... Feb 18 20:48:33 volumio go-librespot[21604]: time="2026-02-18T20:48:33+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:48:33 volumio go-librespot[21604]: time="2026-02-18T20:48:33+07:00" level=debug msg="app state loaded" Feb 18 20:48:33 volumio go-librespot[21604]: time="2026-02-18T20:48:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:48:34 volumio volumio[21524]: info: Loading plugin "airplay_emulation"... Feb 18 20:48:34 volumio volumio[21524]: info: Starting Shairport Sync Feb 18 20:48:34 volumio volumio[21524]: info: Loading plugin "last_100"... Feb 18 20:48:34 volumio volumio[21524]: info: Loading plugin "webradio"... Feb 18 20:48:34 volumio volumio[21524]: info: Loading plugin "i2s_dacs"... Feb 18 20:48:34 volumio volumio[21524]: info: Loading plugin "volumiodiscovery"... Feb 18 20:48:34 volumio volumio[21524]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 20:48:34 volumio volumio[21524]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 20:48:34 volumio volumio[21524]: *** WARNING *** For more information see Feb 18 20:48:34 volumio volumio[21524]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 20:48:34 volumio volumio[21524]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 20:48:34 volumio volumio[21524]: *** WARNING *** For more information see Feb 18 20:48:34 volumio node[21524]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 20:48:34 volumio node[21524]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 20:48:34 volumio node[21524]: *** WARNING *** For more information see Feb 18 20:48:34 volumio node[21524]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 20:48:34 volumio node[21524]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 20:48:34 volumio node[21524]: *** WARNING *** For more information see Feb 18 20:48:34 volumio volumio[21524]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 18 20:48:34 volumio volumio[21524]: info: Discovery: Started advertising with name: Volumio Feb 18 20:48:34 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 20:48:34 volumio volumio[21524]: info: Loading plugin "spop"... Feb 18 20:48:34 volumio go-librespot[21604]: time="2026-02-18T20:48:34+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 20:48:34 volumio go-librespot[21604]: time="2026-02-18T20:48:34+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 20:48:34 volumio go-librespot[21604]: time="2026-02-18T20:48:34+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 20:48:34 volumio go-librespot[21604]: time="2026-02-18T20:48:34+07:00" level=info msg="zeroconf server listening on port 37927" Feb 18 20:48:35 volumio go-librespot[21604]: time="2026-02-18T20:48:35+07:00" level=debug msg="obtained new client token: AADRpScQoP4mspRDQ9LOZsSTVwqap/kAYnja3RXfY3UT6R41AIFGrCo7pPGxBpWvUnrv2pHAH8ReBVrM4BtPVQfC21pX+PsjuAq+lrvFepmOooIMyZAYxjwPXWxV9jUXVFc6wLKumlGm9MJLvBW4HAWdldbBdFF2L3XXNoXuUniMz589jSVFRK9r81OrX5lDzX9CwAAF6PH+9GhHOG+fu2gwN0bOYX34tBw9kLqgf76nQo9rWVk8aw5jdA==" Feb 18 20:48:35 volumio go-librespot[21604]: time="2026-02-18T20:48:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:48:35 volumio go-librespot[21604]: time="2026-02-18T20:48:35+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 20:48:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:48:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:48:36 volumio volumio[21524]: info: Loading plugin "ytcr"... Feb 18 20:48:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 18 20:48:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:38 volumio go-librespot[21614]: go-librespot daemon starting... Feb 18 20:48:38 volumio go-librespot[21615]: time="2026-02-18T20:48:38+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:48:38 volumio go-librespot[21615]: time="2026-02-18T20:48:38+07:00" level=debug msg="app state loaded" Feb 18 20:48:38 volumio go-librespot[21615]: time="2026-02-18T20:48:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:48:38 volumio volumio[21524]: info: Loading plugin "ytmusic"... Feb 18 20:48:39 volumio go-librespot[21615]: time="2026-02-18T20:48:39+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 20:48:39 volumio go-librespot[21615]: time="2026-02-18T20:48:39+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 20:48:39 volumio go-librespot[21615]: time="2026-02-18T20:48:39+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 20:48:39 volumio go-librespot[21615]: time="2026-02-18T20:48:39+07:00" level=info msg="zeroconf server listening on port 46199" Feb 18 20:48:39 volumio go-librespot[21615]: time="2026-02-18T20:48:39+07:00" level=debug msg="obtained new client token: AACW9Cyw0w9pRnMU8sv7Uxu+7lmK8WW+PwcgvYSkq2ELHUYQ0rWRTHBXS9M+VmV4KOtiiQ3cu7opwFJqGnx13+Znyl1B78ICD8wcRJwkJbTJbPtL/n2KH0neCyF3jmWqDysF6aWJC/xFDKLGWtKUPlvz3chHbwQLc4n+I6hKb2fZWVV2HyeEetmJELTvkI42ty/7Fq3m3jz5oyVe5Qa8Dz5dbK+Z+joVQEAD3XIueXC1iJPd7/FazKPF8Q==" Feb 18 20:48:39 volumio go-librespot[21615]: time="2026-02-18T20:48:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:48:39 volumio go-librespot[21615]: time="2026-02-18T20:48:39+07:00" level=debug msg="completed keyexchange" Feb 18 20:48:39 volumio go-librespot[21615]: time="2026-02-18T20:48:39+07:00" level=debug msg="completed challenge" Feb 18 20:48:39 volumio go-librespot[21615]: time="2026-02-18T20:48:39+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 20:48:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:48:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:48:39 volumio volumio-remote-updater[25144]: [2026-02-18 20:48:39] [connect] Successful connection Feb 18 20:48:40 volumio volumio[21524]: info: Loading plugin "outputs"... Feb 18 20:48:40 volumio volumio[21524]: info: Loading plugin "albumart"... Feb 18 20:48:40 volumio volumio[21524]: info: Plugin example_plugin is not enabled Feb 18 20:48:40 volumio volumio[21524]: info: Loading plugin "inputs"... Feb 18 20:48:40 volumio volumio[21524]: info: Loading plugin "updater_comm"... Feb 18 20:48:40 volumio volumio[21524]: info: Plugin mpdemulation is not enabled Feb 18 20:48:40 volumio volumio[21524]: info: Loading plugin "rest_api"... Feb 18 20:48:40 volumio volumio[21524]: info: Loading plugin "websocket"... Feb 18 20:48:40 volumio volumio[21524]: info: Starting Socket.io Server version 1.7.4 Feb 18 20:48:40 volumio volumio[21524]: info: Loading plugin "RoonBridge"... Feb 18 20:48:40 volumio volumio[21524]: info: Applying required configuration parameters for plugin RoonBridge Feb 18 20:48:40 volumio volumio[21524]: info: Loading i18n strings for locale en Feb 18 20:48:40 volumio volumio[21524]: Updating browse sources language Feb 18 20:48:40 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:48:41 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 20:48:41 volumio volumio[21524]: info: CoreCommandRouter::initPlayerControls Feb 18 20:48:41 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:41 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:41 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:41 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:41 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:41 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:41 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:41 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:41 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 20:48:41 volumio volumio[21637]: Forking 3 albumart workers Feb 18 20:48:41 volumio volumio[21524]: Express server listening on port 3000 Feb 18 20:48:41 volumio volumio[21524]: [Metrics] WebUI: 16s 76.07ms Feb 18 20:48:41 volumio volumio[21524]: info: CoreStateMachine::resetVolumioState Feb 18 20:48:41 volumio volumio[21524]: info: CoreStateMachine::getcurrentVolume Feb 18 20:48:41 volumio volumio[21524]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 20:48:41 volumio sudo[21678]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 20:48:41 volumio sudo[21678]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:48:41 volumio sudo[21678]: pam_unix(sudo:session): session closed for user root Feb 18 20:48:41 volumio sudo[21681]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 20:48:41 volumio sudo[21681]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:48:41 volumio sudo[21681]: pam_unix(sudo:session): session closed for user root Feb 18 20:48:41 volumio volumio[21524]: info: Volumio Network Manager: Network status updated: 1 Feb 18 20:48:41 volumio volumio[21524]: info: VolumeController:: Volume=100 Mute =false Feb 18 20:48:41 volumio volumio[21524]: info: CoreStateMachine::pushState Feb 18 20:48:41 volumio volumio[21524]: info: CorePlayQueue::getTrack 0 Feb 18 20:48:41 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 20:48:41 volumio volumio[21524]: info: CoreCommandRouter::volumioPushState Feb 18 20:48:41 volumio volumio[21524]: info: CoreStateMachine::updateTrackBlock Feb 18 20:48:41 volumio volumio[21524]: info: CorePlayQueue::getTrackBlock Feb 18 20:48:41 volumio volumio[21524]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 20:48:41 volumio volumio-remote-updater[25144]: [2026-02-18 20:48:41] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771422519 101 Feb 18 20:48:41 volumio volumio[21524]: 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 18 20:48:41 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:48:41 volumio volumio[21524]: info: Reloading queue from file Feb 18 20:48:41 volumio volumio[21524]: info: CoreStateMachine::setRepeat null single undefined Feb 18 20:48:41 volumio volumio[21524]: info: CoreStateMachine::pushState Feb 18 20:48:41 volumio volumio[21524]: info: CorePlayQueue::getTrack 0 Feb 18 20:48:41 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 20:48:41 volumio volumio[21524]: info: CoreCommandRouter::volumioPushState Feb 18 20:48:42 volumio volumio[21524]: info: CoreStateMachine::setRandom null Feb 18 20:48:42 volumio volumio[21524]: info: CoreStateMachine::pushState Feb 18 20:48:42 volumio volumio[21524]: info: CorePlayQueue::getTrack 0 Feb 18 20:48:42 volumio volumio[21524]: info: CoreCommandRouter::volumioPushState Feb 18 20:48:42 volumio volumio[21524]: info: Setting Device type: Raspberry PI Feb 18 20:48:42 volumio volumio[21524]: info: Completed loading Core Plugins Feb 18 20:48:42 volumio volumio[21524]: info: Preparing to generate the ALSA configuration file Feb 18 20:48:42 volumio volumio[21524]: info: VolumeController:: Volume=100 Mute =false Feb 18 20:48:42 volumio volumio[21524]: info: CoreStateMachine::pushState Feb 18 20:48:42 volumio volumio[21524]: info: CorePlayQueue::getTrack 0 Feb 18 20:48:42 volumio volumio[21524]: info: CoreCommandRouter::volumioPushState Feb 18 20:48:42 volumio volumio[21524]: info: Asound.conf file unchanged, so no further update is needed Feb 18 20:48:42 volumio volumio[21524]: info: Output device has changed, restarting MPD Feb 18 20:48:42 volumio sudo[21698]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 18 20:48:42 volumio sudo[21698]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:48:42 volumio volumio[21524]: info: Output device has changed, restarting Shairport Sync Feb 18 20:48:42 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:42 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:48:42 volumio sudo[21701]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 20:48:42 volumio sudo[21701]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:48:42 volumio sudo[21698]: pam_unix(sudo:session): session closed for user root Feb 18 20:48:42 volumio sudo[21701]: pam_unix(sudo:session): session closed for user root Feb 18 20:48:42 volumio sudo[21703]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 20:48:42 volumio sudo[21703]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:48:42 volumio volumio[21524]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 20:48:42 volumio volumio[21524]: info: ___________ START PLUGINS ___________ Feb 18 20:48:42 volumio volumio[21524]: info: ControllerMpd::onStart: Initializing MPD Feb 18 20:48:42 volumio volumio[21524]: info: Creating MPD Configuration file Feb 18 20:48:42 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 20:48:42 volumio volumio[21524]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 20:48:42 volumio volumio[21524]: info: [1771422522564] CoreMusicLibrary::Adding element Media Servers Feb 18 20:48:42 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:48:42 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 18 20:48:42 volumio volumio[21524]: info: UPNP Browser: Client initialized successfully Feb 18 20:48:42 volumio sudo[21711]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 20:48:42 volumio sudo[21711]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:48:42 volumio sudo[21711]: pam_unix(sudo:session): session closed for user root Feb 18 20:48:42 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 20:48:42 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 20:48:42 volumio systemd[1]: mpd.service: Consumed 7.288s CPU time. Feb 18 20:48:42 volumio sudo[21713]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 20:48:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 18 20:48:42 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 20:48:42 volumio sudo[21713]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:48:42 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 20:48:42 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 20:48:42 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:42 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:48:42 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 20:48:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:42 volumio go-librespot[21718]: go-librespot daemon starting... Feb 18 20:48:42 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 20:48:42 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 20:48:42 volumio volumio[21524]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 20:48:42 volumio go-librespot[21722]: time="2026-02-18T20:48:42+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:48:42 volumio go-librespot[21722]: time="2026-02-18T20:48:42+07:00" level=debug msg="app state loaded" Feb 18 20:48:42 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 20:48:42 volumio go-librespot[21722]: time="2026-02-18T20:48:42+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:48:42 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:42 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 20:48:42 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:48:42 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 20:48:42 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 20:48:43 volumio volumio[21524]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 20:48:43 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 20:48:43 volumio volumio[21524]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 20:48:43 volumio volumio[21524]: info: [1771422523047] CoreMusicLibrary::Adding element Last_100 Feb 18 20:48:43 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:48:43 volumio volumio[21524]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 20:48:43 volumio volumio[21524]: info: [1771422523057] CoreMusicLibrary::Adding element Webradio Feb 18 20:48:43 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:48:43 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 20:48:43 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 20:48:43 volumio volumio[21524]: info: Initializing BBC Radios Feb 18 20:48:43 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 20:48:43 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:48:43 volumio volumio[21524]: info: Creating Spotify config file Feb 18 20:48:43 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:43 volumio sudo[21735]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 20:48:43 volumio sudo[21735]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 20:48:43 volumio sudo[21735]: pam_unix(sudo:session): session closed for user root Feb 18 20:48:43 volumio go-librespot[21722]: time="2026-02-18T20:48:43+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 20:48:43 volumio go-librespot[21722]: time="2026-02-18T20:48:43+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 20:48:43 volumio go-librespot[21722]: time="2026-02-18T20:48:43+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 20:48:43 volumio go-librespot[21722]: time="2026-02-18T20:48:43+07:00" level=info msg="zeroconf server listening on port 38119" Feb 18 20:48:43 volumio go-librespot[21722]: time="2026-02-18T20:48:43+07:00" level=debug msg="obtained new client token: AAAmGQW6jZj3+EhgT9Hi1X+2z2dWCPVybQJCUrJTGeQ9WZ4OqCKW5Qhiht3yTQpukX4Xzt93MjgJtghonm3SYEXdOJSH1w+2UBzov5xDdKB951IN/X+FlRHcVmVvhv+ZmYFbW+/EFGF0XONwG7ZNHoPEX2GN1jvjqIIxrjeTyBCo8nsbqNTZIpVqs+fqWffoIPcUfKMof0R/Sp+eAxojZfPlydoGghcdoRC/n9bhuxmsOcYxddWh9kQ5Lg==" Feb 18 20:48:44 volumio go-librespot[21722]: time="2026-02-18T20:48:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:48:44 volumio go-librespot[21722]: time="2026-02-18T20:48:44+07:00" level=debug msg="completed keyexchange" Feb 18 20:48:44 volumio go-librespot[21722]: time="2026-02-18T20:48:44+07:00" level=debug msg="completed challenge" Feb 18 20:48:44 volumio go-librespot[21722]: time="2026-02-18T20:48:44+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 20:48:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:48:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:48:44 volumio volumio[21652]: Starting albumart workers Feb 18 20:48:44 volumio volumio[21651]: Starting albumart workers Feb 18 20:48:44 volumio volumio[21524]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 20:48:44 volumio volumio[21524]: info: [1771422524854] CoreMusicLibrary::Adding element YouTube Music Feb 18 20:48:44 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:48:44 volumio volumio[21648]: Starting albumart workers Feb 18 20:48:44 volumio volumio[21524]: Cannot find translation for source YouTube Music Feb 18 20:48:44 volumio volumio[21524]: info: Volumio Calling Home Feb 18 20:48:45 volumio sudo[21752]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 20:48:45 volumio sudo[21752]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:48:45 volumio sudo[21752]: pam_unix(sudo:session): session closed for user root Feb 18 20:48:45 volumio volumio[21524]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 20:48:45 volumio volumio[21524]: info: Discovery: Found device Volumio Feb 18 20:48:45 volumio volumio[21524]: info: CoreCommandRouter::volumioGetState Feb 18 20:48:45 volumio volumio[21524]: info: CorePlayQueue::getTrack 0 Feb 18 20:48:45 volumio volumio[21524]: info: MPD Permissions set Feb 18 20:48:45 volumio volumio[21524]: info: MPD Permissions set Feb 18 20:48:45 volumio volumio[21524]: info: Upmpdcli Daemon Started Feb 18 20:48:45 volumio volumio[21524]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 20:48:45 volumio volumio[21524]: info: Discovery: Found device Volumio Feb 18 20:48:45 volumio volumio[21524]: info: CoreCommandRouter::volumioGetState Feb 18 20:48:45 volumio volumio[21524]: info: CorePlayQueue::getTrack 0 Feb 18 20:48:45 volumio volumio[21524]: info: Volumio called home Feb 18 20:48:45 volumio volumio[21524]: info: Spotify config file written Feb 18 20:48:46 volumio volumio[21524]: 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 18 20:48:46 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:46 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:46 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:46 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:46 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:46 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:46 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:46 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:46 volumio sudo[21758]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 20:48:46 volumio sudo[21758]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:48:46 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:48:46 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:46 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:46 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:46 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:46 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:46 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:46 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:46 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:46 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:46 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:48:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:46 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:46 volumio volumio[21524]: info: No need to fix Spotify hosts Feb 18 20:48:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:46 volumio go-librespot[21770]: go-librespot daemon starting... Feb 18 20:48:46 volumio sudo[21758]: pam_unix(sudo:session): session closed for user root Feb 18 20:48:46 volumio go-librespot[21771]: time="2026-02-18T20:48:46+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:48:46 volumio go-librespot[21771]: time="2026-02-18T20:48:46+07:00" level=debug msg="app state loaded" Feb 18 20:48:46 volumio go-librespot[21771]: time="2026-02-18T20:48:46+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:48:47 volumio go-librespot[21771]: time="2026-02-18T20:48:47+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 20:48:47 volumio go-librespot[21771]: time="2026-02-18T20:48:47+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 20:48:47 volumio go-librespot[21771]: time="2026-02-18T20:48:47+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 20:48:47 volumio go-librespot[21771]: time="2026-02-18T20:48:47+07:00" level=info msg="zeroconf server listening on port 33669" Feb 18 20:48:47 volumio go-librespot[21771]: time="2026-02-18T20:48:47+07:00" level=debug msg="obtained new client token: AABoAnBU06c8tiO5upzz/P3BMXV/0rCQVsnL2UW19j+KqAWH/N6avG0+5x9nDGbn1pPgyjZPIgGeTVV4MeDzEWYurf3+O6GxZbj5CJ/P2vT/bZJmIE67x7D1WPwggFF7spOFHr3zte+RWVXSkFIOFkOCXWjuQSs5yedVco6LWqCJrdwSC+7z7AJFj9jpuPF82RwFT8meBD1/99l40PnbwnvxG3bwu0IEJnSB8NF0YhO/3HcAyxlaJe7UhQ==" Feb 18 20:48:47 volumio go-librespot[21771]: time="2026-02-18T20:48:47+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:48:47 volumio volumio[21524]: info: Starting Shairport Sync Feb 18 20:48:47 volumio volumio[21524]: info: Starting Shairport Sync Feb 18 20:48:47 volumio volumio[21524]: info: Starting Shairport Sync Feb 18 20:48:47 volumio go-librespot[21771]: time="2026-02-18T20:48:47+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 20:48:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:48:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:48:47 volumio sudo[21797]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 20:48:47 volumio sudo[21797]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:48:47 volumio sudo[21799]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 20:48:47 volumio sudo[21799]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:48:47 volumio volumio[21524]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 20:48:47 volumio volumio[21524]: SPOTIFY: BQBZMNKh36G_DW5EdLRzwNGl5NPruQGsi8aX5aHQuBT72yCBa7M77ZypMMDQKKBWs2vK5mycu4gQxySqmsdF1-YUhxiG_fgRE1K0NDa_iKOjFSuq2OZ3EIsT_AJYKeBEGLA3MpEo3yJV9scYjDnNezFsBglFWwfD09EW2R6o4_G90xuJQQ8CK7JDdsPDXcYR0CpuTCwZ3_eLR0pK-TLJHTdiIx-wwqy0_oMeJNyV_8bsu294H8KLY7F3HMszBgYAtiKiJD-_w_cbaPMEghwaQTEpkdc8ow4cHmjT4Lsl7bSCmV8th63llGDI Feb 18 20:48:47 volumio volumio[21524]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 20:48:47 volumio sudo[21801]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 20:48:47 volumio volumio[21524]: info: New Spotify access token = BQBZMNKh36G_DW5EdLRzwNGl5NPruQGsi8aX5aHQuBT72yCBa7M77ZypMMDQKKBWs2vK5mycu4gQxySqmsdF1-YUhxiG_fgRE1K0NDa_iKOjFSuq2OZ3EIsT_AJYKeBEGLA3MpEo3yJV9scYjDnNezFsBglFWwfD09EW2R6o4_G90xuJQQ8CK7JDdsPDXcYR0CpuTCwZ3_eLR0pK-TLJHTdiIx-wwqy0_oMeJNyV_8bsu294H8KLY7F3HMszBgYAtiKiJD-_w_cbaPMEghwaQTEpkdc8ow4cHmjT4Lsl7bSCmV8th63llGDI Feb 18 20:48:47 volumio sudo[21801]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:48:47 volumio volumio[21524]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 20:48:47 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 20:48:47 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 20:48:47 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 20:48:47 volumio systemd[1]: shairport-sync.service: Consumed 2.320s CPU time. Feb 18 20:48:47 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 20:48:47 volumio sudo[21797]: pam_unix(sudo:session): session closed for user root Feb 18 20:48:47 volumio sudo[21799]: pam_unix(sudo:session): session closed for user root Feb 18 20:48:48 volumio volumio[21524]: info: Shairport-Sync Started Feb 18 20:48:48 volumio volumio[21524]: Error adding Membership: Error: addMembership EINVAL Feb 18 20:48:48 volumio volumio[21524]: info: Shairport-Sync Started Feb 18 20:48:48 volumio volumio[21524]: info: CoreCommandRouter::volumioGetState Feb 18 20:48:48 volumio volumio[21524]: info: CorePlayQueue::getTrack 0 Feb 18 20:48:48 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 20:48:48 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 20:48:48 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 20:48:48 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 20:48:48 volumio sudo[21801]: pam_unix(sudo:session): session closed for user root Feb 18 20:48:48 volumio volumio[21524]: info: Shairport-Sync Started Feb 18 20:48:48 volumio volumio[21524]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 18 20:48:48 volumio volumio[21524]: info: Spotify Successfully logged in Feb 18 20:48:48 volumio volumio[21524]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 20:48:48 volumio volumio[21524]: info: [1771422528386] CoreMusicLibrary::Adding element Spotify Feb 18 20:48:48 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:48:48 volumio volumio[21524]: Cannot find translation for source YouTube Music Feb 18 20:48:48 volumio volumio[21524]: Cannot find translation for source Spotify Feb 18 20:48:48 volumio volumio[21524]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 20:48:48 volumio volumio[21524]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 20:48:49 volumio volumio[21524]: info: VolumeController:: Volume=100 Mute =false Feb 18 20:48:49 volumio volumio[21524]: info: CoreCommandRouter::volumioGetState Feb 18 20:48:49 volumio volumio[21524]: info: CorePlayQueue::getTrack 0 Feb 18 20:48:49 volumio volumio[21524]: info: CoreStateMachine::pushState Feb 18 20:48:49 volumio volumio[21524]: info: CorePlayQueue::getTrack 0 Feb 18 20:48:49 volumio volumio[21524]: info: CoreCommandRouter::volumioPushState Feb 18 20:48:50 volumio volumio[21524]: info: go-librespot daemon successfully initialized Feb 18 20:48:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 18 20:48:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:50 volumio mpd[21750]: 2026-02-18T20:48:50 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 20:48:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:50 volumio go-librespot[21848]: go-librespot daemon starting... Feb 18 20:48:50 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 20:48:50 volumio sudo[21703]: pam_unix(sudo:session): session closed for user root Feb 18 20:48:50 volumio sudo[21713]: pam_unix(sudo:session): session closed for user root Feb 18 20:48:50 volumio go-librespot[21851]: time="2026-02-18T20:48:50+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:48:50 volumio go-librespot[21851]: time="2026-02-18T20:48:50+07:00" level=debug msg="app state loaded" Feb 18 20:48:50 volumio go-librespot[21851]: time="2026-02-18T20:48:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:48:51 volumio volumio[21524]: error: MPD error: The expression evaluated to a falsy value: Feb 18 20:48:51 volumio volumio[21524]: assert.ok(self.idling) Feb 18 20:48:51 volumio volumio[21524]: error: The expression evaluated to a falsy value: Feb 18 20:48:51 volumio volumio[21524]: assert.ok(self.idling) Feb 18 20:48:51 volumio volumio[21524]: info: Completed starting Core Plugins Feb 18 20:48:51 volumio volumio[21524]: info: ------------------------------------------- Feb 18 20:48:51 volumio volumio[21524]: info: ----- MyVolumio plugins startup ---- Feb 18 20:48:51 volumio volumio[21524]: info: ------------------------------------------- Feb 18 20:48:51 volumio volumio[21524]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 20:48:51 volumio volumio[21524]: error: updateQueue error: null Feb 18 20:48:51 volumio volumio[21524]: info: MPD running with PID21750 Feb 18 20:48:51 volumio volumio[21524]: ,establishing connection Feb 18 20:48:51 volumio volumio[21524]: error: updateQueue error: null Feb 18 20:48:51 volumio go-librespot[21851]: time="2026-02-18T20:48:51+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 20:48:51 volumio go-librespot[21851]: time="2026-02-18T20:48:51+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 20:48:51 volumio go-librespot[21851]: time="2026-02-18T20:48:51+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 20:48:51 volumio go-librespot[21851]: time="2026-02-18T20:48:51+07:00" level=info msg="zeroconf server listening on port 43083" Feb 18 20:48:51 volumio go-librespot[21851]: time="2026-02-18T20:48:51+07:00" level=debug msg="obtained new client token: AABuxgtnutwvmsKNoB9O+elVkgpY20oE0frCrgsmBTdUPmUs+AOcZlo72D/Fl74HNoJR/RJqxVhazIR0/3UYCo4fHf7uQ5pEh8WP0WveEEA11tAyVJ3ILC2B17BSjxXRFvyvUV+zNhs796ZsFUzSXRh+CD5fVHFBUQU0JHPOSZHBe0Sld3tLCh8Lrb5btRzHBHQCNWn+pdwjLsKsAt4T/1xIuL19TpJieap1gG8RPsrpInsGT58lG2cMRQ==" Feb 18 20:48:51 volumio go-librespot[21851]: time="2026-02-18T20:48:51+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:48:51 volumio go-librespot[21851]: time="2026-02-18T20:48:51+07:00" level=debug msg="completed keyexchange" Feb 18 20:48:51 volumio go-librespot[21851]: time="2026-02-18T20:48:51+07:00" level=debug msg="completed challenge" Feb 18 20:48:52 volumio go-librespot[21851]: time="2026-02-18T20:48:52+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 20:48:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:48:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:48:53 volumio volumio[21524]: info: Initializing connection to go-librespot Websocket Feb 18 20:48:53 volumio volumio[21524]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 20:48:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 18 20:48:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:55 volumio go-librespot[21861]: go-librespot daemon starting... Feb 18 20:48:55 volumio go-librespot[21862]: time="2026-02-18T20:48:55+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:48:55 volumio go-librespot[21862]: time="2026-02-18T20:48:55+07:00" level=debug msg="app state loaded" Feb 18 20:48:55 volumio go-librespot[21862]: time="2026-02-18T20:48:55+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:48:55 volumio go-librespot[21862]: time="2026-02-18T20:48:55+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 20:48:55 volumio go-librespot[21862]: time="2026-02-18T20:48:55+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 20:48:55 volumio go-librespot[21862]: time="2026-02-18T20:48:55+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 20:48:55 volumio go-librespot[21862]: time="2026-02-18T20:48:55+07:00" level=info msg="zeroconf server listening on port 33701" Feb 18 20:48:55 volumio go-librespot[21862]: time="2026-02-18T20:48:55+07:00" level=debug msg="obtained new client token: AADaM1bhjPoPHXV3zUcgien20EWtVE5rGGAqgiNGuBBMGdpmbjErcQGfvYx99xVl5fEa/IUxS8aCluohhcBQNl1eQhu1QRocGG6pmcKCMjj/q50N++cSgy2zxzltgjtFrXFmVInHJH/ciKTzK3fREZ+QXsbGijaDCyS/hQFYADclO3BSDXW3jP382XLgPY18dvbe31AHzVRgK9qvLp3+xR99I+2Z6Wx0AmwRfNJ1S+nrdg38YbyYpqQucQ==" Feb 18 20:48:55 volumio go-librespot[21862]: time="2026-02-18T20:48:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:48:56 volumio go-librespot[21862]: time="2026-02-18T20:48:56+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 20:48:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:48:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:48:56 volumio volumio[21524]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 20:48:56 volumio volumio[21524]: info: Initializing connection to go-librespot Websocket Feb 18 20:48:56 volumio volumio[21524]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 20:48:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 18 20:48:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:59 volumio go-librespot[21869]: go-librespot daemon starting... Feb 18 20:48:59 volumio go-librespot[21870]: time="2026-02-18T20:48:59+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:48:59 volumio go-librespot[21870]: time="2026-02-18T20:48:59+07:00" level=debug msg="app state loaded" Feb 18 20:48:59 volumio go-librespot[21870]: time="2026-02-18T20:48:59+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:48:59 volumio volumio[21524]: info: Initializing connection to go-librespot Websocket Feb 18 20:48:59 volumio go-librespot[21870]: time="2026-02-18T20:48:59+07:00" level=debug msg="new websocket client" Feb 18 20:48:59 volumio volumio[21524]: info: Connection to go-librespot Websocket established Feb 18 20:48:59 volumio go-librespot[21870]: time="2026-02-18T20:48:59+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 20:48:59 volumio go-librespot[21870]: time="2026-02-18T20:48:59+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 20:48:59 volumio go-librespot[21870]: time="2026-02-18T20:48:59+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 20:48:59 volumio go-librespot[21870]: time="2026-02-18T20:48:59+07:00" level=info msg="zeroconf server listening on port 35965" Feb 18 20:48:59 volumio go-librespot[21870]: time="2026-02-18T20:48:59+07:00" level=debug msg="obtained new client token: AADxlPG5pa6wvcP3MknlvoUarvSyDx484i50r3pECCuEopEO/NfG+2xUMmwAiiOSIf1ZNqoBwjeif+axT/onXONraXUjDnT+tC/MRkPB01N0GoUeijAC4eV9qgZOWa65OEGjmiKzsL8v4uDR52ufGRUFSbcM5L7vBCEg0gFQR61Bo+3AX6EZjz60AHzpCrFzaqDuNFS5yasQe8J1f62KCUm6oApQPTRj80LBkWuHFjSTnqoNk2bN6XWBWA==" Feb 18 20:49:00 volumio go-librespot[21870]: time="2026-02-18T20:49:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:49:00 volumio volumio[21524]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 18 20:49:00 volumio volumio[21524]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 18 20:49:00 volumio volumio[21524]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 18 20:49:00 volumio volumio[21524]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 18 20:49:00 volumio volumio[21524]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 18 20:49:00 volumio volumio[21524]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 18 20:49:00 volumio volumio[21524]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 18 20:49:00 volumio volumio[21524]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 18 20:49:00 volumio volumio[21524]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 18 20:49:00 volumio volumio[21524]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 18 20:49:00 volumio volumio[21524]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 18 20:49:00 volumio volumio[21524]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 18 20:49:00 volumio volumio[21524]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 18 20:49:00 volumio volumio[21524]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 18 20:49:00 volumio volumio[21524]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 18 20:49:00 volumio volumio[21524]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 18 20:49:00 volumio volumio[21524]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 18 20:49:00 volumio volumio[21524]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 18 20:49:00 volumio volumio[21524]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 18 20:49:00 volumio volumio[21524]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 18 20:49:00 volumio volumio[21524]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 18 20:49:00 volumio volumio[21524]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 18 20:49:00 volumio volumio[21524]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 18 20:49:00 volumio volumio[21524]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 18 20:49:00 volumio volumio[21524]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 18 20:49:00 volumio volumio[21524]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 18 20:49:00 volumio volumio[21524]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 18 20:49:00 volumio volumio[21524]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 18 20:49:00 volumio volumio[21524]: info: Adding plugin bluetooth to MyMusic Plugins Feb 18 20:49:00 volumio volumio[21524]: info: Adding plugin multiroom to MyMusic Plugins Feb 18 20:49:00 volumio volumio[21524]: info: Adding plugin metavolumio to MyMusic Plugins Feb 18 20:49:00 volumio volumio[21524]: info: Adding plugin cd_controller to MyMusic Plugins Feb 18 20:49:00 volumio volumio[21524]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 18 20:49:00 volumio volumio[21524]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 18 20:49:00 volumio volumio[21524]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 18 20:49:00 volumio volumio[21524]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 18 20:49:00 volumio go-librespot[21870]: time="2026-02-18T20:49:00+07:00" level=debug msg="completed keyexchange" Feb 18 20:49:00 volumio go-librespot[21870]: time="2026-02-18T20:49:00+07:00" level=debug msg="completed challenge" Feb 18 20:49:00 volumio go-librespot[21870]: time="2026-02-18T20:49:00+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 20:49:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:49:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:49:02 volumio volumio[21524]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 18 20:49:02 volumio volumio[21524]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 18 20:49:02 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:49:02 volumio volumio[21524]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:49:02 volumio volumio[21524]: info: Starting MyVolumio Remote Streaming Endpoints Feb 18 20:49:02 volumio volumio[21524]: info: MyVolumio login type: Token Feb 18 20:49:02 volumio volumio[21524]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 18 20:49:02 volumio volumio[21524]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 18 20:49:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 18 20:49:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:49:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:49:03 volumio go-librespot[21891]: go-librespot daemon starting... Feb 18 20:49:03 volumio go-librespot[21892]: time="2026-02-18T20:49:03+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:49:03 volumio go-librespot[21892]: time="2026-02-18T20:49:03+07:00" level=debug msg="app state loaded" Feb 18 20:49:03 volumio go-librespot[21892]: time="2026-02-18T20:49:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:49:03 volumio volumio[21524]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 18 20:49:03 volumio volumio[21524]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 18 20:49:03 volumio volumio[21524]: info: Streaming services startup Feb 18 20:49:03 volumio volumio[21524]: info: Starting Streaming Daemon Feb 18 20:49:03 volumio volumio[21524]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 18 20:49:03 volumio sudo[21900]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 20:49:03 volumio sudo[21900]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:49:03 volumio sudo[21900]: pam_unix(sudo:session): session closed for user root Feb 18 20:49:03 volumio go-librespot[21892]: time="2026-02-18T20:49:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 20:49:03 volumio go-librespot[21892]: time="2026-02-18T20:49:03+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 20:49:03 volumio go-librespot[21892]: time="2026-02-18T20:49:03+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 20:49:03 volumio go-librespot[21892]: time="2026-02-18T20:49:03+07:00" level=info msg="zeroconf server listening on port 44563" Feb 18 20:49:03 volumio volumio[21524]: info: Getting Spotify volume Feb 18 20:49:04 volumio volumio[21524]: info: Connection to go-librespot Websocket closed Feb 18 20:49:04 volumio volumio[21524]: error: Cannot start Volumio Streaming Daemon Feb 18 20:49:04 volumio volumio[21524]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 20:49:04 volumio volumio[21524]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 20:49:04 volumio volumio[21524]: 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 18 20:49:04 volumio go-librespot[21892]: time="2026-02-18T20:49:04+07:00" level=debug msg="obtained new client token: AAAiWZEaZtWhK52RjHw23E73sDsvwZ41k1TJtqG5oJkZOWdqx1g1QVH3XP+/8yO2u3OXpuL81aAsa/4DuwOetfkOEUqyltl9pl61UZBIswK8qHyXSng6coISEuzPF5ehccz0WHfTbN/GdMvC+VIYpoKZkvSBPAi4D/b5JKBpELiqWYcOfUX2GoczmGWjQ4DwW5QMMglPTv9O2pP9YLf+kJ8TlJo8/bt8/2u4OGaUvdSOroT/rWME0qE=" Feb 18 20:49:04 volumio volumio[21524]: info: CoreCommandRouter::volumioGetState Feb 18 20:49:04 volumio volumio[21524]: info: CorePlayQueue::getTrack 0 Feb 18 20:49:04 volumio go-librespot[21892]: time="2026-02-18T20:49:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:49:04 volumio volumio[21524]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 18 20:49:04 volumio volumio[21524]: SPOTIFY: SPOTIFY VOLUME undefined Feb 18 20:49:04 volumio volumio[21524]: SPOTIFY: VOLUMIO VOLUME 100 Feb 18 20:49:04 volumio volumio[21524]: info: Aligning Spotify Volume to Volumio Volume Feb 18 20:49:04 volumio volumio[21524]: info: CoreCommandRouter::volumioGetState Feb 18 20:49:04 volumio volumio[21524]: info: CorePlayQueue::getTrack 0 Feb 18 20:49:04 volumio volumio[21524]: info: Setting Spotify Volume from Volumio: 100 Feb 18 20:49:04 volumio go-librespot[21892]: time="2026-02-18T20:49:04+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 20:49:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:49:04 volumio volumio[21524]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 20:49:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:49:04 volumio volumio[21524]: Error: socket hang up Feb 18 20:49:04 volumio volumio[21524]: at connResetException (node:internal/errors:720:14) Feb 18 20:49:04 volumio volumio[21524]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 18 20:49:04 volumio volumio[21524]: at Socket.emit (node:events:526:35) Feb 18 20:49:04 volumio volumio[21524]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 18 20:49:04 volumio volumio[21524]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 18 20:49:04 volumio volumio[21524]: code: 'ECONNRESET', Feb 18 20:49:04 volumio volumio[21524]: response: undefined Feb 18 20:49:04 volumio volumio[21524]: } Feb 18 20:49:04 volumio volumio[21524]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 20:49:05 volumio sudo[21922]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 20:48' Feb 18 20:49:05 volumio sudo[21922]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:49:06 volumio sudo[21922]: pam_unix(sudo:session): session closed for user root Feb 18 20:49:07 volumio volumio-remote-updater[25144]: [2026-02-18 20:49:07] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Feb 18 20:49:07 volumio volumio-remote-updater[25144]: [2026-02-18 20:49:07] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Feb 18 20:49:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Feb 18 20:49:07 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:49:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:49:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:49:07 volumio go-librespot[21930]: go-librespot daemon starting... Feb 18 20:49:07 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 18 20:49:07 volumio systemd[1]: volumio.service: Consumed 1min 2ms CPU time. Feb 18 20:49:07 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 20:49:07 volumio go-librespot[21931]: time="2026-02-18T20:49:07+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:49:07 volumio go-librespot[21931]: time="2026-02-18T20:49:07+07:00" level=debug msg="app state loaded" Feb 18 20:49:07 volumio go-librespot[21931]: time="2026-02-18T20:49:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:49:07 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 20:49:07 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 22416. Feb 18 20:49:07 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 20:49:07 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 18 20:49:07 volumio systemd[1]: volumio.service: Consumed 1min 2ms CPU time. Feb 18 20:49:07 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 18 20:49:07 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 20:49:08 volumio go-librespot[21931]: time="2026-02-18T20:49:08+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 20:49:08 volumio go-librespot[21931]: time="2026-02-18T20:49:08+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 20:49:08 volumio go-librespot[21931]: time="2026-02-18T20:49:08+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 20:49:08 volumio go-librespot[21931]: time="2026-02-18T20:49:08+07:00" level=info msg="zeroconf server listening on port 39675" Feb 18 20:49:08 volumio go-librespot[21931]: time="2026-02-18T20:49:08+07:00" level=debug msg="obtained new client token: AACb3AUxWgLZKAOgVz/cyIx6AFoatyzR7Qdko6+NGrVqhE617FLQB/fqh3zeovEF9f2naRSzMOriOpT9fa/2OMLJ66ldVEgxqzDIsUXt6iNC38Has4HJ5QVGesmXElxHEQrVfcjEMLE8un+manpIajNSoiE2555VuhQvkMW2yj+rxRPftSAQt96FHRK4cSXMPPBpbxN3IHbpUDTczErhrOjdg2IjgBIZFVYDrTPeNiG6IYhJjCJokjlWEg==" Feb 18 20:49:08 volumio go-librespot[21931]: time="2026-02-18T20:49:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:49:08 volumio go-librespot[21931]: time="2026-02-18T20:49:08+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 20:49:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:49:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:49:11 volumio volumio[21945]: info: ------------------------------------------- Feb 18 20:49:11 volumio volumio[21945]: info: ----- Volumio3 ---- Feb 18 20:49:11 volumio volumio[21945]: info: ------------------------------------------- Feb 18 20:49:11 volumio volumio[21945]: info: ----- System startup ---- Feb 18 20:49:11 volumio volumio[21945]: info: ------------------------------------------- Feb 18 20:49:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Feb 18 20:49:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:49:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:49:11 volumio go-librespot[21967]: go-librespot daemon starting... Feb 18 20:49:11 volumio go-librespot[21968]: time="2026-02-18T20:49:11+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:49:11 volumio go-librespot[21968]: time="2026-02-18T20:49:11+07:00" level=debug msg="app state loaded" Feb 18 20:49:11 volumio go-librespot[21968]: time="2026-02-18T20:49:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:49:12 volumio go-librespot[21968]: time="2026-02-18T20:49:12+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 20:49:12 volumio go-librespot[21968]: time="2026-02-18T20:49:12+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 20:49:12 volumio go-librespot[21968]: time="2026-02-18T20:49:12+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 20:49:12 volumio go-librespot[21968]: time="2026-02-18T20:49:12+07:00" level=info msg="zeroconf server listening on port 33883" Feb 18 20:49:12 volumio volumio-remote-updater[25144]: [2026-02-18 20:49:12] [connect] Successful connection Feb 18 20:49:12 volumio go-librespot[21968]: time="2026-02-18T20:49:12+07:00" level=debug msg="obtained new client token: AAA/x0T9xAdAd6UQKHY+RBkJWiyAHj8qm+ZH7/C5OdeHEmIbI8D8gIQlOL1qeWyRtfAA64+TZzWfRVbc7vBmQ4rEaq9d65U+iK6yKy+ASp5ZOqqtevF2MBGR7OjuuHaSmbIwkpa0nHvjbkQVh6NZ/kZgym65zJeNHtNA4uBdVU8kHGEiH3wygyqbJWhnWHVbol/zSd3rIGtwtOEI5IDb0/DuRfzU2/d27uvD7U+1XJnPQQIItv7iB5NBvA==" Feb 18 20:49:12 volumio go-librespot[21968]: time="2026-02-18T20:49:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:49:12 volumio volumio[21945]: info: MYVOLUMIO Environment detected Feb 18 20:49:12 volumio go-librespot[21968]: time="2026-02-18T20:49:12+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 20:49:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:49:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:49:13 volumio volumio[21945]: info: Plugin folders cleanup Feb 18 20:49:13 volumio volumio[21945]: info: Scanning into folder /volumio/app/plugins/ Feb 18 20:49:13 volumio volumio[21945]: info: Scanning category audio_interface Feb 18 20:49:13 volumio volumio[21945]: info: Scanning category miscellanea Feb 18 20:49:13 volumio volumio[21945]: info: Scanning category music_service Feb 18 20:49:13 volumio volumio[21945]: info: Scanning category plugins.json Feb 18 20:49:13 volumio volumio[21945]: info: Scanning category system_controller Feb 18 20:49:13 volumio volumio[21945]: info: Scanning category user_interface Feb 18 20:49:13 volumio volumio[21945]: info: Scanning into folder /data/plugins/ Feb 18 20:49:13 volumio volumio[21945]: info: Scanning category music_service Feb 18 20:49:13 volumio volumio[21945]: info: Plugin folders cleanup completed Feb 18 20:49:13 volumio volumio[21945]: info: ------------------------------------------- Feb 18 20:49:13 volumio volumio[21945]: info: ----- Core plugins startup ---- Feb 18 20:49:13 volumio volumio[21945]: info: ------------------------------------------- Feb 18 20:49:13 volumio volumio[21945]: info: Loading plugins from folder /volumio/app/plugins/ Feb 18 20:49:13 volumio volumio[21945]: info: Adding plugin upnp to MyMusic Plugins Feb 18 20:49:13 volumio volumio[21945]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 18 20:49:13 volumio volumio[21945]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 18 20:49:13 volumio volumio[21945]: info: Loading plugins from folder /data/plugins/ Feb 18 20:49:13 volumio volumio[21945]: info: Loading plugin "system"... Feb 18 20:49:13 volumio volumio[21945]: info: Loading plugin "appearance"... Feb 18 20:49:15 volumio volumio[21945]: info: Loading plugin "network"... Feb 18 20:49:15 volumio volumio[21945]: info: Refreshing Cached IP Addresses Feb 18 20:49:15 volumio sudo[21983]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 20:49:15 volumio sudo[21983]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:49:15 volumio sudo[21983]: pam_unix(sudo:session): session closed for user root Feb 18 20:49:15 volumio sudo[21985]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 20:49:15 volumio sudo[21985]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:49:15 volumio volumio[21945]: info: Loading plugin "services"... Feb 18 20:49:15 volumio sudo[21985]: pam_unix(sudo:session): session closed for user root Feb 18 20:49:15 volumio volumio[21945]: info: Loading plugin "alsa_controller"... Feb 18 20:49:15 volumio sudo[21993]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 18 20:49:15 volumio sudo[21993]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:49:15 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 20:49:15 volumio volumio[21945]: info: Loading plugin "wizard"... Feb 18 20:49:15 volumio volumio[21945]: info: Loading plugin "networkfs"... Feb 18 20:49:15 volumio volumio[21945]: info: Starting Udev Watcher for removable devices Feb 18 20:49:15 volumio volumio[21945]: info: Ignoring mount for partition: boot Feb 18 20:49:15 volumio volumio[21945]: info: Ignoring mount for partition: volumio Feb 18 20:49:15 volumio volumio[21945]: info: Ignoring mount for partition: volumio_data Feb 18 20:49:15 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 20:49:15 volumio volumio[21945]: info: Loading plugin "volumio_command_line_client"... Feb 18 20:49:15 volumio volumio[21945]: info: Loading plugin "upnp"... Feb 18 20:49:15 volumio volumio[21945]: info: [1771422555458] Starting Upmpd Daemon Feb 18 20:49:15 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 20:49:15 volumio volumio[21945]: info: Loading plugin "my_music"... Feb 18 20:49:15 volumio volumio[21945]: info: Loading plugin "mpd"... Feb 18 20:49:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Feb 18 20:49:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:49:16 volumio volumio[21945]: info: Loading plugin "upnp_browser"... Feb 18 20:49:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:49:16 volumio go-librespot[22016]: go-librespot daemon starting... Feb 18 20:49:16 volumio go-librespot[22017]: time="2026-02-18T20:49:16+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:49:16 volumio go-librespot[22017]: time="2026-02-18T20:49:16+07:00" level=debug msg="app state loaded" Feb 18 20:49:16 volumio go-librespot[22017]: time="2026-02-18T20:49:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:49:16 volumio go-librespot[22017]: time="2026-02-18T20:49:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 20:49:16 volumio go-librespot[22017]: time="2026-02-18T20:49:16+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 20:49:16 volumio go-librespot[22017]: time="2026-02-18T20:49:16+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 20:49:16 volumio go-librespot[22017]: time="2026-02-18T20:49:16+07:00" level=info msg="zeroconf server listening on port 35001" Feb 18 20:49:16 volumio go-librespot[22017]: time="2026-02-18T20:49:16+07:00" level=debug msg="obtained new client token: AADTckZbbTiiO84gKvHLLFM/8m2Pf/5B/5ZW4epXHX4CndY6YZhmUJ0LackI4D3jneMhPKTgMfQ6qF/wnjRTI/9UdyBsRgw5+zqYlUE7dQGEAy+dn6IjUyHep/y0q7SVQuNyEkHq+3X4aoHfRxHl6IJAAbe0MdrmFeG9tC9u1TZ2CTTv9APtwB3d0eIiX/GWUm64VIlUCSP5jDQAMMuVsQrVq8uwweX1PAjPhrX9MaSUhk9kkRBfEiZu7Q==" Feb 18 20:49:17 volumio go-librespot[22017]: time="2026-02-18T20:49:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:49:17 volumio go-librespot[22017]: time="2026-02-18T20:49:17+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 20:49:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:49:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:49:18 volumio sudo[21993]: pam_unix(sudo:session): session closed for user root Feb 18 20:49:19 volumio volumio[21945]: info: Starting UPNP Browser Feb 18 20:49:19 volumio volumio[21945]: info: Loading plugin "alarm-clock"... Feb 18 20:49:19 volumio volumio[21945]: info: Loading plugin "airplay_emulation"... Feb 18 20:49:19 volumio volumio[21945]: info: Starting Shairport Sync Feb 18 20:49:19 volumio volumio[21945]: info: Loading plugin "last_100"... Feb 18 20:49:19 volumio volumio[21945]: info: Loading plugin "webradio"... Feb 18 20:49:19 volumio volumio[21945]: info: Loading plugin "i2s_dacs"... Feb 18 20:49:19 volumio volumio[21945]: info: Loading plugin "volumiodiscovery"... Feb 18 20:49:19 volumio volumio[21945]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 20:49:19 volumio volumio[21945]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 20:49:19 volumio node[21945]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 20:49:19 volumio volumio[21945]: *** WARNING *** For more information see Feb 18 20:49:19 volumio volumio[21945]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 20:49:19 volumio volumio[21945]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 20:49:19 volumio volumio[21945]: *** WARNING *** For more information see Feb 18 20:49:19 volumio node[21945]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 20:49:19 volumio node[21945]: *** WARNING *** For more information see Feb 18 20:49:19 volumio node[21945]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 20:49:19 volumio node[21945]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 20:49:19 volumio node[21945]: *** WARNING *** For more information see Feb 18 20:49:19 volumio volumio[21945]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 18 20:49:19 volumio volumio[21945]: info: Discovery: Started advertising with name: Volumio Feb 18 20:49:19 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 20:49:19 volumio volumio[21945]: info: Loading plugin "spop"... Feb 18 20:49:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Feb 18 20:49:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:49:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:49:20 volumio go-librespot[22026]: go-librespot daemon starting... Feb 18 20:49:20 volumio go-librespot[22027]: time="2026-02-18T20:49:20+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:49:20 volumio go-librespot[22027]: time="2026-02-18T20:49:20+07:00" level=debug msg="app state loaded" Feb 18 20:49:20 volumio go-librespot[22027]: time="2026-02-18T20:49:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:49:20 volumio go-librespot[22027]: time="2026-02-18T20:49:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 20:49:20 volumio go-librespot[22027]: time="2026-02-18T20:49:20+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 20:49:20 volumio go-librespot[22027]: time="2026-02-18T20:49:20+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 20:49:21 volumio go-librespot[22027]: time="2026-02-18T20:49:21+07:00" level=info msg="zeroconf server listening on port 46295" Feb 18 20:49:21 volumio go-librespot[22027]: time="2026-02-18T20:49:21+07:00" level=debug msg="obtained new client token: AABOMOxHZp3cZ5roZiAn6TIu3gBanBbUfhVAihMaSYrCOvNb977LGx21xf34KOLBnUNNepne9sZolOJTF0As9xkiFn916cPsELn3i8e8BJNGk2oKueU58gLnnI43quz2xxH8Z5OfRlh12/pv3RoayhwhzBvAizLT6VGBzh1Ij4fbhjtQ/GcZskOWW1mnu/ABx4tx5il9D0D0aJlwQCh4Yx0/VTtRB+/OOImpvu5oruw+vpTPFA9RN0w=" Feb 18 20:49:21 volumio go-librespot[22027]: time="2026-02-18T20:49:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:49:21 volumio go-librespot[22027]: time="2026-02-18T20:49:21+07:00" level=debug msg="completed keyexchange" Feb 18 20:49:21 volumio go-librespot[22027]: time="2026-02-18T20:49:21+07:00" level=debug msg="completed challenge" Feb 18 20:49:21 volumio volumio[21945]: info: Loading plugin "ytcr"... Feb 18 20:49:21 volumio go-librespot[22027]: time="2026-02-18T20:49:21+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 20:49:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:49:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:49:24 volumio volumio[21945]: info: Loading plugin "ytmusic"... Feb 18 20:49:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Feb 18 20:49:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:49:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:49:24 volumio go-librespot[22034]: go-librespot daemon starting... Feb 18 20:49:24 volumio go-librespot[22035]: time="2026-02-18T20:49:24+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:49:24 volumio go-librespot[22035]: time="2026-02-18T20:49:24+07:00" level=debug msg="app state loaded" Feb 18 20:49:24 volumio go-librespot[22035]: time="2026-02-18T20:49:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:49:25 volumio volumio-remote-updater[25144]: [2026-02-18 20:49:25] [connect] Successful connection Feb 18 20:49:25 volumio volumio[21945]: info: Loading plugin "outputs"... Feb 18 20:49:25 volumio volumio[21945]: info: Loading plugin "albumart"... Feb 18 20:49:25 volumio volumio[21945]: info: Plugin example_plugin is not enabled Feb 18 20:49:25 volumio volumio[21945]: info: Loading plugin "inputs"... Feb 18 20:49:25 volumio volumio[21945]: info: Loading plugin "updater_comm"... Feb 18 20:49:25 volumio go-librespot[22035]: time="2026-02-18T20:49:25+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 20:49:25 volumio go-librespot[22035]: time="2026-02-18T20:49:25+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 20:49:25 volumio go-librespot[22035]: time="2026-02-18T20:49:25+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 20:49:25 volumio go-librespot[22035]: time="2026-02-18T20:49:25+07:00" level=info msg="zeroconf server listening on port 41791" Feb 18 20:49:25 volumio volumio[21945]: info: Plugin mpdemulation is not enabled Feb 18 20:49:25 volumio volumio[21945]: info: Loading plugin "rest_api"... Feb 18 20:49:25 volumio volumio[21945]: info: Loading plugin "websocket"... Feb 18 20:49:25 volumio volumio[21945]: info: Starting Socket.io Server version 1.7.4 Feb 18 20:49:25 volumio volumio[21945]: info: Loading plugin "RoonBridge"... Feb 18 20:49:25 volumio go-librespot[22035]: time="2026-02-18T20:49:25+07:00" level=debug msg="obtained new client token: AAAnbfdO46KFdu3K1aJigDAdUtjS6G+J+qgPuuz5sGp66TG/+BLc+EqkdK7Oc9BijC6pyeMT7Gj39uzOiT9ZNVdqueThanKZy5kiuQTASZz7eUi/cOKqbKGAN+FNEWGEvDc4Ts9ibjkXv5QRwuZZyLEvvNZHxxfnS4LfiY1iinAuhqAE5iXQi0GleBt0jZSLqiMFvaMcCS+Htlo3LBBCvV4EligN1Vnu6cVUmoGFOpsMeYxdJrqlmj84Qw==" Feb 18 20:49:25 volumio go-librespot[22035]: time="2026-02-18T20:49:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:49:25 volumio go-librespot[22035]: time="2026-02-18T20:49:25+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 20:49:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:49:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:49:26 volumio volumio[21945]: info: Applying required configuration parameters for plugin RoonBridge Feb 18 20:49:26 volumio volumio[21945]: info: Loading i18n strings for locale en Feb 18 20:49:26 volumio volumio[21945]: Updating browse sources language Feb 18 20:49:26 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:49:26 volumio volumio[22056]: Forking 3 albumart workers Feb 18 20:49:26 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 20:49:26 volumio volumio[21945]: info: CoreCommandRouter::initPlayerControls Feb 18 20:49:26 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:49:26 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:49:26 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:49:26 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:49:26 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:49:26 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:49:26 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:49:26 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:49:26 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 20:49:26 volumio volumio[21945]: Express server listening on port 3000 Feb 18 20:49:26 volumio volumio[21945]: [Metrics] WebUI: 16s 157.48ms Feb 18 20:49:26 volumio volumio[21945]: info: CoreStateMachine::resetVolumioState Feb 18 20:49:26 volumio volumio[21945]: info: CoreStateMachine::getcurrentVolume Feb 18 20:49:26 volumio volumio[21945]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 20:49:26 volumio sudo[22101]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 20:49:26 volumio sudo[22101]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:49:26 volumio sudo[22101]: pam_unix(sudo:session): session closed for user root Feb 18 20:49:26 volumio sudo[22103]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 20:49:26 volumio sudo[22103]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:49:26 volumio volumio[21945]: info: Volumio Network Manager: Network status updated: 1 Feb 18 20:49:26 volumio sudo[22103]: pam_unix(sudo:session): session closed for user root Feb 18 20:49:27 volumio volumio-remote-updater[25144]: [2026-02-18 20:49:27] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771422565 101 Feb 18 20:49:27 volumio volumio[21945]: 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 18 20:49:27 volumio volumio[21945]: info: VolumeController:: Volume=100 Mute =false Feb 18 20:49:27 volumio volumio[21945]: info: CoreStateMachine::pushState Feb 18 20:49:27 volumio volumio[21945]: info: CorePlayQueue::getTrack 0 Feb 18 20:49:27 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 20:49:27 volumio volumio[21945]: info: CoreCommandRouter::volumioPushState Feb 18 20:49:27 volumio volumio[21945]: info: CoreStateMachine::updateTrackBlock Feb 18 20:49:27 volumio volumio[21945]: info: CorePlayQueue::getTrackBlock Feb 18 20:49:27 volumio volumio[21945]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 20:49:27 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:49:27 volumio volumio[21945]: info: Reloading queue from file Feb 18 20:49:27 volumio volumio[21945]: info: CoreStateMachine::setRepeat null single undefined Feb 18 20:49:27 volumio volumio[21945]: info: CoreStateMachine::pushState Feb 18 20:49:27 volumio volumio[21945]: info: CorePlayQueue::getTrack 0 Feb 18 20:49:27 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 20:49:27 volumio volumio[21945]: info: CoreCommandRouter::volumioPushState Feb 18 20:49:27 volumio volumio[21945]: info: CoreStateMachine::setRandom null Feb 18 20:49:27 volumio volumio[21945]: info: CoreStateMachine::pushState Feb 18 20:49:27 volumio volumio[21945]: info: CorePlayQueue::getTrack 0 Feb 18 20:49:27 volumio volumio[21945]: info: CoreCommandRouter::volumioPushState Feb 18 20:49:27 volumio volumio[21945]: info: Setting Device type: Raspberry PI Feb 18 20:49:27 volumio volumio[21945]: info: Completed loading Core Plugins Feb 18 20:49:27 volumio volumio[21945]: info: Preparing to generate the ALSA configuration file Feb 18 20:49:27 volumio volumio[21945]: info: VolumeController:: Volume=100 Mute =false Feb 18 20:49:27 volumio volumio[21945]: info: CoreStateMachine::pushState Feb 18 20:49:27 volumio volumio[21945]: info: CorePlayQueue::getTrack 0 Feb 18 20:49:27 volumio volumio[21945]: info: CoreCommandRouter::volumioPushState Feb 18 20:49:27 volumio volumio[21945]: info: Asound.conf file unchanged, so no further update is needed Feb 18 20:49:27 volumio volumio[21945]: info: Output device has changed, restarting MPD Feb 18 20:49:27 volumio volumio[21945]: info: Output device has changed, restarting Shairport Sync Feb 18 20:49:27 volumio sudo[22116]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 18 20:49:27 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:49:27 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:49:27 volumio sudo[22116]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:49:27 volumio sudo[22118]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 20:49:27 volumio sudo[22118]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:49:27 volumio sudo[22118]: pam_unix(sudo:session): session closed for user root Feb 18 20:49:27 volumio volumio[21945]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 20:49:27 volumio sudo[22120]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 20:49:27 volumio volumio[21945]: info: ___________ START PLUGINS ___________ Feb 18 20:49:27 volumio sudo[22120]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:49:27 volumio sudo[22116]: pam_unix(sudo:session): session closed for user root Feb 18 20:49:27 volumio volumio[21945]: info: ControllerMpd::onStart: Initializing MPD Feb 18 20:49:27 volumio volumio[21945]: info: Creating MPD Configuration file Feb 18 20:49:28 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 20:49:28 volumio volumio[21945]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 20:49:28 volumio volumio[21945]: info: [1771422568074] CoreMusicLibrary::Adding element Media Servers Feb 18 20:49:28 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:49:28 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 18 20:49:28 volumio volumio[21945]: info: UPNP Browser: Client initialized successfully Feb 18 20:49:28 volumio sudo[22129]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 20:49:28 volumio sudo[22129]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:49:28 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 20:49:28 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 20:49:28 volumio systemd[1]: mpd.service: Consumed 7.374s CPU time. Feb 18 20:49:28 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 20:49:28 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 20:49:28 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 20:49:28 volumio sudo[22129]: pam_unix(sudo:session): session closed for user root Feb 18 20:49:28 volumio sudo[22131]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 20:49:28 volumio sudo[22131]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:49:28 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:49:28 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:49:28 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 20:49:28 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 20:49:28 volumio volumio[21945]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 20:49:28 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:49:28 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:49:28 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 20:49:28 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 20:49:28 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 20:49:28 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 20:49:28 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 20:49:28 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 20:49:28 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 20:49:28 volumio volumio[21945]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 20:49:28 volumio volumio[21945]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 20:49:28 volumio volumio[21945]: info: [1771422568470] CoreMusicLibrary::Adding element Last_100 Feb 18 20:49:28 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:49:28 volumio volumio[21945]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 20:49:28 volumio volumio[21945]: info: [1771422568495] CoreMusicLibrary::Adding element Webradio Feb 18 20:49:28 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:49:28 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 20:49:28 volumio volumio[21945]: info: Initializing BBC Radios Feb 18 20:49:28 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 20:49:28 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:49:28 volumio volumio[21945]: info: Creating Spotify config file Feb 18 20:49:28 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:49:28 volumio sudo[22145]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 20:49:28 volumio sudo[22145]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 20:49:28 volumio sudo[22145]: pam_unix(sudo:session): session closed for user root Feb 18 20:49:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Feb 18 20:49:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:49:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:49:29 volumio go-librespot[22161]: go-librespot daemon starting... Feb 18 20:49:29 volumio go-librespot[22162]: time="2026-02-18T20:49:29+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:49:29 volumio volumio[22066]: Starting albumart workers Feb 18 20:49:29 volumio volumio[22068]: Starting albumart workers Feb 18 20:49:29 volumio go-librespot[22162]: time="2026-02-18T20:49:29+07:00" level=info msg="zeroconf server listening on port 35899" Feb 18 20:49:29 volumio volumio[22067]: Starting albumart workers Feb 18 20:49:30 volumio volumio[21945]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 20:49:30 volumio volumio[21945]: info: [1771422570218] CoreMusicLibrary::Adding element YouTube Music Feb 18 20:49:30 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:49:30 volumio volumio[21945]: Cannot find translation for source YouTube Music Feb 18 20:49:30 volumio volumio[21945]: info: Volumio Calling Home Feb 18 20:49:30 volumio sudo[22171]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 20:49:30 volumio sudo[22171]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:49:30 volumio sudo[22171]: pam_unix(sudo:session): session closed for user root Feb 18 20:49:31 volumio volumio[21945]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 20:49:31 volumio volumio[21945]: info: Discovery: Found device Volumio Feb 18 20:49:31 volumio volumio[21945]: info: CoreCommandRouter::volumioGetState Feb 18 20:49:31 volumio volumio[21945]: info: CorePlayQueue::getTrack 0 Feb 18 20:49:31 volumio volumio[21945]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 20:49:31 volumio volumio[21945]: info: Discovery: Found device Volumio Feb 18 20:49:31 volumio volumio[21945]: info: CoreCommandRouter::volumioGetState Feb 18 20:49:31 volumio volumio[21945]: info: CorePlayQueue::getTrack 0 Feb 18 20:49:31 volumio volumio[21945]: info: MPD Permissions set Feb 18 20:49:31 volumio volumio[21945]: info: MPD Permissions set Feb 18 20:49:31 volumio volumio[21945]: info: Upmpdcli Daemon Started Feb 18 20:49:31 volumio volumio[21945]: info: Spotify config file written Feb 18 20:49:31 volumio sudo[22184]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 20:49:31 volumio sudo[22184]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:49:31 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 18 20:49:31 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 18 20:49:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:49:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:49:31 volumio go-librespot[22186]: go-librespot daemon starting... Feb 18 20:49:31 volumio sudo[22184]: pam_unix(sudo:session): session closed for user root Feb 18 20:49:31 volumio volumio[21945]: 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 18 20:49:31 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:49:31 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:49:31 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:49:31 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:49:31 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:49:31 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:49:31 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:49:31 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:49:31 volumio go-librespot[22187]: time="2026-02-18T20:49:31+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:49:31 volumio go-librespot[22187]: time="2026-02-18T20:49:31+07:00" level=debug msg="app state loaded" Feb 18 20:49:31 volumio go-librespot[22187]: time="2026-02-18T20:49:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:49:31 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:49:31 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:49:31 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:49:31 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:49:31 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:49:31 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:49:31 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:49:31 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:49:31 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:49:31 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:49:31 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:49:31 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:49:31 volumio volumio[21945]: info: No need to fix Spotify hosts Feb 18 20:49:32 volumio go-librespot[22187]: time="2026-02-18T20:49:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 20:49:32 volumio go-librespot[22187]: time="2026-02-18T20:49:32+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 20:49:32 volumio go-librespot[22187]: time="2026-02-18T20:49:32+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 20:49:32 volumio go-librespot[22187]: time="2026-02-18T20:49:32+07:00" level=info msg="zeroconf server listening on port 32883" Feb 18 20:49:32 volumio volumio[21945]: info: Volumio called home Feb 18 20:49:32 volumio go-librespot[22187]: time="2026-02-18T20:49:32+07:00" level=debug msg="obtained new client token: AAA6WeDKivN+FduF6z7pu2MDoeIc5yJ93oQBcvxSy4CkKQ4/+naBfrb+LEDvfre3EhzD8jTL5xzKNcKsCl0537pV4MhkUYKtFBeqjYm+RLrwCJ8xjdCAQ813bQyUIGWNwp3tSEWgVsAup2KtQH2tZ9Y9kF6Ck5CqMaZ3lKNqJuXf/yMBvYvJ5VuytHlmo+giXWonUT8Pl90gz4OkajaDJC0n/0MSuevwFS9iLfRFjrHQaWwVSpjlcUSeVA==" Feb 18 20:49:32 volumio volumio[21945]: info: Starting Shairport Sync Feb 18 20:49:32 volumio volumio[21945]: info: Starting Shairport Sync Feb 18 20:49:32 volumio volumio[21945]: info: Starting Shairport Sync Feb 18 20:49:32 volumio sudo[22221]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 20:49:32 volumio sudo[22221]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:49:32 volumio go-librespot[22187]: time="2026-02-18T20:49:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:49:32 volumio sudo[22225]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 20:49:32 volumio sudo[22225]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:49:32 volumio sudo[22223]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 20:49:32 volumio sudo[22223]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:49:32 volumio go-librespot[22187]: time="2026-02-18T20:49:32+07:00" level=debug msg="completed keyexchange" Feb 18 20:49:32 volumio go-librespot[22187]: time="2026-02-18T20:49:32+07:00" level=debug msg="completed challenge" Feb 18 20:49:33 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 20:49:33 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 20:49:33 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 20:49:33 volumio systemd[1]: shairport-sync.service: Consumed 2.299s CPU time. Feb 18 20:49:33 volumio go-librespot[22187]: time="2026-02-18T20:49:33+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 20:49:33 volumio volumio[21945]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 20:49:33 volumio volumio[21945]: SPOTIFY: BQAu2dfDv65U7I5pTZnLK0EJIQzATA9BHK3jSGJhKntOjhLk18KqvSsMbf2ES5IciThohPeeDw8vOmDL62PvCrnehYNYeh8auXCrzmeACIl4zCzlXdOy8wVI-RpTRcwYzN4x6lA_eQvmMGqBLLqkKroUq-kcLq76FyIRBVPSI2KVofe_f35QCay0WtCnbxQPOZajIlbd0qx4Ijh1e-K676pH_Mv-NjKb0EFiyH7v0-vvzzFR0f3DN7NnctzWZfFG5B0ENWTfP2lMgBlS4oa0irr_lj0Mk_EHGW8_6WDJg9sJkDZAkEU7Hf_R Feb 18 20:49:33 volumio volumio[21945]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 20:49:33 volumio volumio[21945]: info: New Spotify access token = BQAu2dfDv65U7I5pTZnLK0EJIQzATA9BHK3jSGJhKntOjhLk18KqvSsMbf2ES5IciThohPeeDw8vOmDL62PvCrnehYNYeh8auXCrzmeACIl4zCzlXdOy8wVI-RpTRcwYzN4x6lA_eQvmMGqBLLqkKroUq-kcLq76FyIRBVPSI2KVofe_f35QCay0WtCnbxQPOZajIlbd0qx4Ijh1e-K676pH_Mv-NjKb0EFiyH7v0-vvzzFR0f3DN7NnctzWZfFG5B0ENWTfP2lMgBlS4oa0irr_lj0Mk_EHGW8_6WDJg9sJkDZAkEU7Hf_R Feb 18 20:49:33 volumio volumio[21945]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 20:49:33 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 20:49:33 volumio sudo[22221]: pam_unix(sudo:session): session closed for user root Feb 18 20:49:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:49:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:49:33 volumio sudo[22225]: pam_unix(sudo:session): session closed for user root Feb 18 20:49:33 volumio sudo[22223]: pam_unix(sudo:session): session closed for user root Feb 18 20:49:33 volumio volumio[21945]: info: Shairport-Sync Started Feb 18 20:49:33 volumio volumio[21945]: Error adding Membership: Error: addMembership EINVAL Feb 18 20:49:33 volumio volumio[21945]: info: CoreCommandRouter::volumioGetState Feb 18 20:49:33 volumio volumio[21945]: info: CorePlayQueue::getTrack 0 Feb 18 20:49:33 volumio volumio[21945]: info: Shairport-Sync Started Feb 18 20:49:33 volumio volumio[21945]: info: Shairport-Sync Started Feb 18 20:49:33 volumio volumio[21945]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 18 20:49:33 volumio volumio[21945]: info: Spotify Successfully logged in Feb 18 20:49:33 volumio volumio[21945]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 20:49:33 volumio volumio[21945]: info: [1771422573625] CoreMusicLibrary::Adding element Spotify Feb 18 20:49:33 volumio volumio[21945]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:49:33 volumio volumio[21945]: Cannot find translation for source YouTube Music Feb 18 20:49:33 volumio volumio[21945]: Cannot find translation for source Spotify Feb 18 20:49:34 volumio volumio[21945]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 20:49:34 volumio volumio[21945]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 20:49:34 volumio volumio[21945]: info: VolumeController:: Volume=100 Mute =false Feb 18 20:49:34 volumio volumio[21945]: info: CoreCommandRouter::volumioGetState Feb 18 20:49:34 volumio volumio[21945]: info: CorePlayQueue::getTrack 0 Feb 18 20:49:34 volumio volumio[21945]: info: CoreStateMachine::pushState Feb 18 20:49:34 volumio volumio[21945]: info: CorePlayQueue::getTrack 0 Feb 18 20:49:34 volumio volumio[21945]: info: CoreCommandRouter::volumioPushState Feb 18 20:49:35 volumio volumio[21945]: info: go-librespot daemon successfully initialized Feb 18 20:49:36 volumio mpd[22160]: 2026-02-18T20:49:36 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 20:49:36 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 20:49:36 volumio sudo[22131]: pam_unix(sudo:session): session closed for user root Feb 18 20:49:36 volumio sudo[22120]: pam_unix(sudo:session): session closed for user root Feb 18 20:49:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 18 20:49:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:49:36 volumio volumio[21945]: error: MPD error: The expression evaluated to a falsy value: Feb 18 20:49:36 volumio volumio[21945]: assert.ok(self.idling) Feb 18 20:49:36 volumio volumio[21945]: error: The expression evaluated to a falsy value: Feb 18 20:49:36 volumio volumio[21945]: assert.ok(self.idling) Feb 18 20:49:36 volumio volumio[21945]: error: updateQueue error: null Feb 18 20:49:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:49:36 volumio volumio[21945]: info: MPD running with PID22160 Feb 18 20:49:36 volumio volumio[21945]: ,establishing connection Feb 18 20:49:36 volumio go-librespot[22265]: go-librespot daemon starting... Feb 18 20:49:36 volumio go-librespot[22266]: time="2026-02-18T20:49:36+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:49:36 volumio go-librespot[22266]: time="2026-02-18T20:49:36+07:00" level=debug msg="app state loaded" Feb 18 20:49:36 volumio go-librespot[22266]: time="2026-02-18T20:49:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:49:36 volumio volumio[21945]: info: Completed starting Core Plugins Feb 18 20:49:36 volumio volumio[21945]: info: ------------------------------------------- Feb 18 20:49:36 volumio volumio[21945]: info: ----- MyVolumio plugins startup ---- Feb 18 20:49:36 volumio volumio[21945]: info: ------------------------------------------- Feb 18 20:49:36 volumio volumio[21945]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 20:49:36 volumio volumio[21945]: error: updateQueue error: null Feb 18 20:49:37 volumio go-librespot[22266]: time="2026-02-18T20:49:37+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 20:49:37 volumio go-librespot[22266]: time="2026-02-18T20:49:37+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 20:49:37 volumio go-librespot[22266]: time="2026-02-18T20:49:37+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 20:49:37 volumio go-librespot[22266]: time="2026-02-18T20:49:37+07:00" level=info msg="zeroconf server listening on port 38215" Feb 18 20:49:37 volumio go-librespot[22266]: time="2026-02-18T20:49:37+07:00" level=debug msg="obtained new client token: AACm7jJhwYc4gkxirKU2S9SbuJ/mKK5zrNabROImiBDCGdETGY79bVaJzQGQxkyrHbTETiU0rNP0KTHDGG0s+uRr58KTv+4KVBiEYU2Iq8GBKDTe38lr4onB1rcyYhe340E2WvxgtJ0OsaFwArDA0M45tIFPbwqgcnhEkhiwTsKhXbv4qL/8Xn+JukNMXR08BOujcRfDhfY3nHbWRCw+4UFlnT8uNk9DH7oFSklOvUX0P79rXyYIl/+fAQ==" Feb 18 20:49:37 volumio go-librespot[22266]: time="2026-02-18T20:49:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:49:37 volumio go-librespot[22266]: time="2026-02-18T20:49:37+07:00" level=debug msg="completed keyexchange" Feb 18 20:49:37 volumio go-librespot[22266]: time="2026-02-18T20:49:37+07:00" level=debug msg="completed challenge" Feb 18 20:49:37 volumio go-librespot[22266]: time="2026-02-18T20:49:37+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 20:49:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:49:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:49:38 volumio volumio[21945]: info: Initializing connection to go-librespot Websocket Feb 18 20:49:38 volumio volumio[21945]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 20:49:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 18 20:49:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:49:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:49:40 volumio go-librespot[22273]: go-librespot daemon starting... Feb 18 20:49:40 volumio go-librespot[22274]: time="2026-02-18T20:49:40+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:49:40 volumio go-librespot[22274]: time="2026-02-18T20:49:40+07:00" level=debug msg="app state loaded" Feb 18 20:49:40 volumio go-librespot[22274]: time="2026-02-18T20:49:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:49:41 volumio volumio[21945]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 20:49:41 volumio go-librespot[22274]: time="2026-02-18T20:49:41+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 20:49:41 volumio go-librespot[22274]: time="2026-02-18T20:49:41+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 20:49:41 volumio go-librespot[22274]: time="2026-02-18T20:49:41+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 20:49:41 volumio go-librespot[22274]: time="2026-02-18T20:49:41+07:00" level=info msg="zeroconf server listening on port 45455" Feb 18 20:49:41 volumio go-librespot[22274]: time="2026-02-18T20:49:41+07:00" level=debug msg="obtained new client token: AABf5yJqVF7nQJ5rfYgvLIZUC7bQKW/nq9MyAk3WA4fVXZZKsPFKg+lkuTmbuBkXXdeoac0t8htv12rRQtrFFI17nH+XtPdgRMC5UpGpvP4RVbFS3iB9Ibt+V6RKqrAEvyOOTdt2FczZzbFXeB48NJ5Z2nGEbSI0elGyiz9Jsg+xAbsW5/lswVXO5OETerzRK61r2m3zx560KSo5P9IkxJYV7jQZWRE0sPNOrsMva65BzMNicJAONwfmUw==" Feb 18 20:49:41 volumio volumio[21945]: info: Initializing connection to go-librespot Websocket Feb 18 20:49:41 volumio go-librespot[22274]: time="2026-02-18T20:49:41+07:00" level=debug msg="new websocket client" Feb 18 20:49:41 volumio volumio[21945]: info: Connection to go-librespot Websocket established Feb 18 20:49:41 volumio go-librespot[22274]: time="2026-02-18T20:49:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:49:41 volumio go-librespot[22274]: time="2026-02-18T20:49:41+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 20:49:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:49:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:49:41 volumio volumio[21945]: info: Connection to go-librespot Websocket closed Feb 18 20:49:44 volumio volumio[21945]: info: Getting Spotify volume Feb 18 20:49:44 volumio volumio[21945]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 20:49:44 volumio volumio[21945]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 20:49:44 volumio volumio[21945]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 18 20:49:44 volumio volumio[21945]: errno: -111, Feb 18 20:49:44 volumio volumio[21945]: code: 'ECONNREFUSED', Feb 18 20:49:44 volumio volumio[21945]: syscall: 'connect', Feb 18 20:49:44 volumio volumio[21945]: address: '127.0.0.1', Feb 18 20:49:44 volumio volumio[21945]: port: 9879, Feb 18 20:49:44 volumio volumio[21945]: response: undefined Feb 18 20:49:44 volumio volumio[21945]: } Feb 18 20:49:44 volumio volumio[21945]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 20:49:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 18 20:49:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:49:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:49:45 volumio go-librespot[22293]: go-librespot daemon starting... Feb 18 20:49:45 volumio go-librespot[22294]: time="2026-02-18T20:49:45+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:49:45 volumio go-librespot[22294]: time="2026-02-18T20:49:45+07:00" level=debug msg="app state loaded" Feb 18 20:49:45 volumio go-librespot[22294]: time="2026-02-18T20:49:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:49:45 volumio go-librespot[22294]: time="2026-02-18T20:49:45+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 20:49:45 volumio go-librespot[22294]: time="2026-02-18T20:49:45+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 20:49:45 volumio go-librespot[22294]: time="2026-02-18T20:49:45+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 20:49:45 volumio go-librespot[22294]: time="2026-02-18T20:49:45+07:00" level=info msg="zeroconf server listening on port 35673" Feb 18 20:49:46 volumio go-librespot[22294]: time="2026-02-18T20:49:46+07:00" level=debug msg="obtained new client token: AABCuisJAXWrWdmRSAVSqSoQIWi6hlTMIvOBJ3xUt5z2lbzgwBeh5kmY4IBbue9/+zut2vDhoIDs5BXetFsZuBm9XLIQnquSnaLxfDf49PtWWRwamvEMp77s8EjQuMgMNUvJBETt3jK/k3BHQjVmiMuqgnffxgpmYZguVCQkHnfk5/7sVh32AknZtyizZ4lxmS6GbPvXy0yjtDLahugRDy+W7PMd3x82XCM3AqlTT1aml5OH2hK0R0pjbA==" Feb 18 20:49:46 volumio go-librespot[22294]: time="2026-02-18T20:49:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:49:46 volumio go-librespot[22294]: time="2026-02-18T20:49:46+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 20:49:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:49:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:49:46 volumio sudo[22317]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 20:48' Feb 18 20:49:46 volumio sudo[22317]: 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="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"