Feb 07 08:30:00 music volumio[24877]: info: Loading plugin "outputs"... Feb 07 08:30:00 music volumio[24877]: info: Loading plugin "albumart"... Feb 07 08:30:00 music volumio[24877]: info: Plugin example_plugin is not enabled Feb 07 08:30:00 music volumio[24877]: info: Loading plugin "inputs"... Feb 07 08:30:00 music volumio[24877]: info: Loading plugin "updater_comm"... Feb 07 08:30:00 music volumio[24877]: info: Plugin mpdemulation is not enabled Feb 07 08:30:00 music volumio[24877]: info: Loading plugin "rest_api"... Feb 07 08:30:00 music volumio[24877]: info: Loading plugin "websocket"... Feb 07 08:30:00 music volumio[24877]: info: Starting Socket.io Server version 1.7.4 Feb 07 08:30:00 music volumio[24877]: info: Loading i18n strings for locale en Feb 07 08:30:00 music volumio[24877]: Updating browse sources language Feb 07 08:30:00 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 08:30:00 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 08:30:00 music volumio[24877]: info: CoreCommandRouter::initPlayerControls Feb 07 08:30:00 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:00 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:00 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:00 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:00 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:00 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:00 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:00 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:00 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 08:30:00 music volumio[24877]: Express server listening on port 3000 Feb 07 08:30:00 music volumio[24877]: [Metrics] WebUI: 6s 547.11ms Feb 07 08:30:00 music volumio[24877]: info: CoreStateMachine::resetVolumioState Feb 07 08:30:00 music volumio[24877]: info: CoreStateMachine::getcurrentVolume Feb 07 08:30:00 music volumio[24877]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 08:30:00 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 08:30:00 music volumio[24877]: info: Volumio Network Manager: Network status updated: 1 Feb 07 08:30:01 music volumio-remote-updater[31331]: [2026-02-07 08:30:01] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770470997 101 Feb 07 08:30:01 music volumio[24950]: Forking 3 albumart workers Feb 07 08:30:01 music volumio[24877]: 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 07 08:30:01 music volumio[24877]: info: VolumeController:: Volume=86 Mute =false Feb 07 08:30:01 music volumio[24877]: info: CoreStateMachine::pushState Feb 07 08:30:01 music volumio[24877]: info: CorePlayQueue::getTrack 0 Feb 07 08:30:01 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 08:30:01 music volumio[24877]: info: CoreCommandRouter::volumioPushState Feb 07 08:30:01 music volumio[24877]: info: CoreStateMachine::updateTrackBlock Feb 07 08:30:01 music volumio[24877]: info: CorePlayQueue::getTrackBlock Feb 07 08:30:01 music volumio[24877]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 08:30:01 music volumio[24877]: info: Reloading queue from file Feb 07 08:30:01 music volumio[24877]: info: CoreStateMachine::setRepeat null single undefined Feb 07 08:30:01 music volumio[24877]: info: CoreStateMachine::pushState Feb 07 08:30:01 music volumio[24877]: info: CorePlayQueue::getTrack 0 Feb 07 08:30:01 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 08:30:01 music volumio[24877]: info: CoreCommandRouter::volumioPushState Feb 07 08:30:01 music volumio[24877]: info: CoreStateMachine::setRandom null Feb 07 08:30:01 music volumio[24877]: info: CoreStateMachine::pushState Feb 07 08:30:01 music volumio[24877]: info: CorePlayQueue::getTrack 0 Feb 07 08:30:01 music volumio[24877]: info: CoreCommandRouter::volumioPushState Feb 07 08:30:01 music volumio[24877]: info: Setting Device type: Raspberry PI Feb 07 08:30:01 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 07 08:30:01 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 08:30:01 music volumio[24877]: info: VolumeController:: Volume=86 Mute =false Feb 07 08:30:01 music volumio[24877]: info: CoreStateMachine::pushState Feb 07 08:30:01 music volumio[24877]: info: CorePlayQueue::getTrack 0 Feb 07 08:30:01 music volumio[24877]: info: CoreCommandRouter::volumioPushState Feb 07 08:30:01 music volumio[24877]: info: Completed loading Core Plugins Feb 07 08:30:01 music volumio[24877]: info: Preparing to generate the ALSA configuration file Feb 07 08:30:01 music volumio[24877]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 07 08:30:01 music volumio[24877]: info: Discovery: Found device music Feb 07 08:30:01 music volumio[24877]: info: CoreCommandRouter::volumioGetState Feb 07 08:30:01 music volumio[24877]: info: CorePlayQueue::getTrack 0 Feb 07 08:30:01 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 08:30:01 music volumio[24877]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 07 08:30:01 music go-librespot[25003]: go-librespot daemon starting... Feb 07 08:30:01 music volumio[24877]: info: Discovery: Found device music Feb 07 08:30:01 music volumio[24877]: info: CoreCommandRouter::volumioGetState Feb 07 08:30:01 music volumio[24877]: info: CorePlayQueue::getTrack 0 Feb 07 08:30:01 music volumio[24877]: info: Asound.conf file unchanged, so no further update is needed Feb 07 08:30:01 music volumio[24877]: info: Output device has changed, restarting MPD Feb 07 08:30:01 music go-librespot[25004]: time="2026-02-07T08:30:01-05:00" level=info msg="running go-librespot 0.6.2" Feb 07 08:30:01 music go-librespot[25004]: time="2026-02-07T08:30:01-05:00" level=debug msg="app state loaded" Feb 07 08:30:01 music volumio[24877]: info: Output device has changed, restarting Shairport Sync Feb 07 08:30:01 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:01 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 08:30:01 music sudo[25014]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 08:30:01 music sudo[25014]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:01 music go-librespot[25004]: time="2026-02-07T08:30:01-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 08:30:01 music sudo[25011]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 08:30:01 music sudo[25011]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:01 music sudo[25011]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:01 music volumio[24877]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 08:30:01 music volumio[24877]: info: ___________ START PLUGINS ___________ Feb 07 08:30:01 music systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 07 08:30:01 music volumio[24877]: info: ControllerMpd::onStart: Initializing MPD Feb 07 08:30:01 music volumio[24877]: info: Creating MPD Configuration file Feb 07 08:30:01 music systemd[1]: mpd.service: Deactivated successfully. Feb 07 08:30:01 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 08:30:01 music systemd[1]: mpd.service: Consumed 4.165s CPU time. Feb 07 08:30:01 music systemd[1]: mpd.socket: Deactivated successfully. Feb 07 08:30:01 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 08:30:01 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 08:30:01 music sudo[25023]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 08:30:01 music sudo[25023]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:01 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 08:30:01 music volumio[24877]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 08:30:01 music volumio[24877]: info: [1770471001735] CoreMusicLibrary::Adding element Media Servers Feb 07 08:30:01 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 08:30:01 music sudo[25023]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:01 music sudo[25026]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 08:30:01 music sudo[25026]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:01 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 08:30:01 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 08:30:01 music volumio[24877]: info: UPNP Browser: Client initialized successfully Feb 07 08:30:01 music systemd[1]: mpd.service: Deactivated successfully. Feb 07 08:30:01 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 08:30:01 music systemd[1]: mpd.socket: Deactivated successfully. Feb 07 08:30:01 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 08:30:01 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 08:30:01 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 08:30:01 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 08:30:01 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:01 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 08:30:01 music volumio[24877]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 08:30:01 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:01 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 08:30:01 music go-librespot[25004]: time="2026-02-07T08:30:01-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 08:30:01 music go-librespot[25004]: time="2026-02-07T08:30:01-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 07 08:30:01 music go-librespot[25004]: time="2026-02-07T08:30:01-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 07 08:30:01 music go-librespot[25004]: time="2026-02-07T08:30:01-05:00" level=info msg="zeroconf server listening on port 45103" Feb 07 08:30:01 music volumio[24877]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 08:30:01 music volumio[24877]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 08:30:01 music volumio[24877]: info: [1770471001976] CoreMusicLibrary::Adding element Last_100 Feb 07 08:30:01 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 08:30:01 music volumio[24877]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 08:30:01 music volumio[24877]: info: [1770471001986] CoreMusicLibrary::Adding element Webradio Feb 07 08:30:01 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 08:30:01 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 08:30:02 music volumio[24877]: info: Initializing BBC Radios Feb 07 08:30:02 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 08:30:02 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 08:30:02 music volumio[24877]: info: Creating Spotify config file Feb 07 08:30:02 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:02 music go-librespot[25004]: time="2026-02-07T08:30:02-05:00" level=debug msg="obtained new client token: AADaX6rSTttOscGk6DrJuDk8mBC9hRz2XPVZBMUG5fyDKT83e5GSNiholrSbgB3boJX95+tEgG1lHJKdR4xnzm9hoVkHQemhKXU0yR7I2CzL/257V1qcrbpWEtzcXZ93vu3bYgQ/hvHuxAj3F/VV9j89J9Ug8Dcvt/roDBbUK1Sge+cbkvGHyqSl/kmhMnzb9QqCY62NXwZCUVE7OzrbmD4EmEzTPUB+/HeJBkiO0/OVUtfNt4Cn" Feb 07 08:30:02 music sudo[25033]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 07 08:30:02 music sudo[25033]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 07 08:30:02 music sudo[25033]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:02 music go-librespot[25004]: time="2026-02-07T08:30:02-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 08:30:02 music go-librespot[25004]: time="2026-02-07T08:30:02-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:02 music go-librespot[25004]: time="2026-02-07T08:30:02-05:00" level=debug msg="completed challenge" Feb 07 08:30:02 music go-librespot[25004]: time="2026-02-07T08:30:02-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:02 music volumio[24966]: Starting albumart workers Feb 07 08:30:02 music volumio[24877]: info: Volumio Calling Home Feb 07 08:30:02 music go-librespot[25004]: time="2026-02-07T08:30:02-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 08:30:02 music go-librespot[25004]: time="2026-02-07T08:30:02-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:02 music go-librespot[25004]: time="2026-02-07T08:30:02-05:00" level=debug msg="completed challenge" Feb 07 08:30:03 music go-librespot[25004]: time="2026-02-07T08:30:03-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:03 music volumio[24877]: info: MPD Permissions set Feb 07 08:30:03 music volumio[24968]: Starting albumart workers Feb 07 08:30:03 music volumio[24877]: info: MPD Permissions set Feb 07 08:30:03 music volumio[24965]: Starting albumart workers Feb 07 08:30:03 music volumio[24877]: info: Volumio called home Feb 07 08:30:03 music volumio[24877]: info: Spotify config file written Feb 07 08:30:03 music sudo[25061]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 07 08:30:03 music sudo[25061]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:03 music volumio[24877]: info: CoreCommandRouter::volumioGetState Feb 07 08:30:03 music volumio[24877]: info: CorePlayQueue::getTrack 0 Feb 07 08:30:03 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 07 08:30:03 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 07 08:30:03 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 08:30:03 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 08:30:03 music go-librespot[25063]: go-librespot daemon starting... Feb 07 08:30:03 music sudo[25061]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:03 music go-librespot[25064]: time="2026-02-07T08:30:03-05:00" level=info msg="running go-librespot 0.6.2" Feb 07 08:30:03 music go-librespot[25064]: time="2026-02-07T08:30:03-05:00" level=debug msg="app state loaded" Feb 07 08:30:03 music volumio[24877]: 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 07 08:30:03 music go-librespot[25064]: time="2026-02-07T08:30:03-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 08:30:03 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:03 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:03 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:03 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:03 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:03 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:03 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:03 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:03 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 08:30:03 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:03 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:03 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:03 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:03 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:03 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:03 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:03 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:03 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:04 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 08:30:04 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:04 music volumio[24877]: info: No need to fix Spotify hosts Feb 07 08:30:04 music go-librespot[25064]: time="2026-02-07T08:30:04-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 08:30:04 music go-librespot[25064]: time="2026-02-07T08:30:04-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 07 08:30:04 music go-librespot[25064]: time="2026-02-07T08:30:04-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 07 08:30:04 music go-librespot[25064]: time="2026-02-07T08:30:04-05:00" level=info msg="zeroconf server listening on port 36167" Feb 07 08:30:04 music go-librespot[25064]: time="2026-02-07T08:30:04-05:00" level=debug msg="obtained new client token: AACFgTK8Yg9H2+hRQSgKJzmrC+BeWDj0ICmuScSKYHx+P1X9Vy2yvk8VEZu/hHJ3+o4ssxfkcVEc5b/VbzFci9+KQj2E7kppCk7IT2+V0PCAP0msPhpUYW6M127QOUK2tmehi7MyNpbtKtYINF0aTwRVO68ElC9c+oYQwzu04W/piceuJkkHUMf2EUqAJ5XayPDL1Q0MYAdoUOExmKm67l1QOzKQnec+VzPSdI2jnAy3BsPO5scw0Vc=" Feb 07 08:30:04 music volumio[24877]: info: Listing playlists Feb 07 08:30:04 music volumio[24877]: info: Listing playlists Feb 07 08:30:04 music go-librespot[25064]: time="2026-02-07T08:30:04-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 08:30:04 music volumio[24877]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 07 08:30:04 music volumio[24877]: info: Starting Shairport Sync Feb 07 08:30:04 music volumio[24877]: info: Starting Shairport Sync Feb 07 08:30:04 music volumio[24877]: info: Starting Shairport Sync Feb 07 08:30:04 music go-librespot[25064]: time="2026-02-07T08:30:04-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:04 music sudo[25098]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 08:30:04 music sudo[25098]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:04 music go-librespot[25064]: time="2026-02-07T08:30:04-05:00" level=debug msg="completed challenge" Feb 07 08:30:04 music sudo[25100]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 08:30:04 music sudo[25100]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:04 music sudo[25102]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 08:30:04 music sudo[25102]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:04 music go-librespot[25064]: time="2026-02-07T08:30:04-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:04 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 07 08:30:04 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 07 08:30:04 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 08:30:04 music systemd[1]: shairport-sync.service: Consumed 1.886s CPU time. Feb 07 08:30:04 music volumio[24877]: info: CoreCommandRouter::volumioGetState Feb 07 08:30:04 music volumio[24877]: info: CorePlayQueue::getTrack 0 Feb 07 08:30:04 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 08:30:04 music sudo[25100]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:04 music sudo[25102]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:04 music sudo[25098]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:04 music volumio[24877]: info: Shairport-Sync Started Feb 07 08:30:04 music volumio[24877]: Error adding Membership: Error: addMembership EINVAL Feb 07 08:30:04 music volumio[24877]: info: Shairport-Sync Started Feb 07 08:30:04 music volumio[24877]: info: Shairport-Sync Started Feb 07 08:30:05 music go-librespot[25064]: time="2026-02-07T08:30:05-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 08:30:05 music go-librespot[25064]: time="2026-02-07T08:30:05-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:05 music go-librespot[25064]: time="2026-02-07T08:30:05-05:00" level=debug msg="completed challenge" Feb 07 08:30:05 music go-librespot[25064]: time="2026-02-07T08:30:05-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:06 music go-librespot[25064]: time="2026-02-07T08:30:06-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 07 08:30:06 music go-librespot[25064]: time="2026-02-07T08:30:06-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:06 music go-librespot[25064]: time="2026-02-07T08:30:06-05:00" level=debug msg="completed challenge" Feb 07 08:30:06 music go-librespot[25064]: time="2026-02-07T08:30:06-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:06 music mpd[25056]: 2026-02-07T08:30:06 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 07 08:30:06 music systemd[1]: Started mpd.service - Music Player Daemon. Feb 07 08:30:06 music sudo[25014]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:06 music sudo[25026]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:06 music volumio[24877]: info: Completed starting Core Plugins Feb 07 08:30:06 music volumio[24877]: info: ------------------------------------------- Feb 07 08:30:06 music volumio[24877]: info: ----- MyVolumio plugins startup ---- Feb 07 08:30:06 music volumio[24877]: info: ------------------------------------------- Feb 07 08:30:06 music volumio[24877]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 07 08:30:06 music volumio[24877]: error: MPD error: The expression evaluated to a falsy value: Feb 07 08:30:06 music volumio[24877]: assert.ok(self.idling) Feb 07 08:30:06 music volumio[24877]: error: The expression evaluated to a falsy value: Feb 07 08:30:06 music volumio[24877]: assert.ok(self.idling) Feb 07 08:30:06 music volumio[24877]: info: MPD running with PID25056 Feb 07 08:30:06 music volumio[24877]: ,establishing connection Feb 07 08:30:06 music volumio[24877]: error: updateQueue error: null Feb 07 08:30:06 music volumio[24877]: error: updateQueue error: null Feb 07 08:30:06 music go-librespot[25064]: time="2026-02-07T08:30:06-05:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 08:30:07 music go-librespot[25064]: time="2026-02-07T08:30:07-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 07 08:30:07 music sudo[25148]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 08:30:07 music sudo[25148]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:07 music sudo[25150]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 08:30:07 music sudo[25148]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:07 music sudo[25150]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:07 music sudo[25150]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:07 music sudo[25152]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 07 08:30:07 music sudo[25152]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:07 music sudo[25152]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:07 music volumio[24877]: info: Upmpdcli Daemon Started Feb 07 08:30:07 music volumio[24877]: info: go-librespot daemon successfully initialized Feb 07 08:30:07 music go-librespot[25064]: time="2026-02-07T08:30:07-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 08:30:07 music go-librespot[25064]: time="2026-02-07T08:30:07-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 07 08:30:08 music go-librespot[25064]: time="2026-02-07T08:30:08-05:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:80, retrying with a different AP" error="dial tcp 34.158.1.133:80: connect: connection refused" Feb 07 08:30:08 music go-librespot[25064]: time="2026-02-07T08:30:08-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 08:30:08 music go-librespot[25064]: time="2026-02-07T08:30:08-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:08 music go-librespot[25064]: time="2026-02-07T08:30:08-05:00" level=debug msg="completed challenge" Feb 07 08:30:08 music go-librespot[25064]: time="2026-02-07T08:30:08-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:08 music go-librespot[25064]: time="2026-02-07T08:30:08-05: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 07 08:30:08 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 08:30:08 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 08:30:09 music sudo[25157]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 07 08:30:09 music sudo[25157]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:09 music sudo[25159]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 07 08:30:09 music sudo[25159]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:09 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 07 08:30:09 music systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 07 08:30:09 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 07 08:30:09 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 07 08:30:09 music sudo[25159]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:09 music sudo[25157]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:09 music volumio[24877]: info: Successfully started MPD Monitor Feb 07 08:30:09 music mpd_monitor.sh[25162]: MPD Monitor Service: Starting MPD Monitor Service Feb 07 08:30:09 music volumio[24877]: info: Successfully started MPD Monitor Feb 07 08:30:10 music volumio[24877]: info: Initializing connection to go-librespot Websocket Feb 07 08:30:10 music volumio[24877]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 08:30:11 music volumio[24877]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 07 08:30:11 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 07 08:30:11 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 08:30:11 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 08:30:11 music go-librespot[25166]: go-librespot daemon starting... Feb 07 08:30:11 music go-librespot[25167]: time="2026-02-07T08:30:11-05:00" level=info msg="running go-librespot 0.6.2" Feb 07 08:30:11 music go-librespot[25167]: time="2026-02-07T08:30:11-05:00" level=debug msg="app state loaded" Feb 07 08:30:11 music go-librespot[25167]: time="2026-02-07T08:30:11-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 08:30:12 music volumio[24877]: info: CoreCommandRouter::volumioGetState Feb 07 08:30:12 music volumio[24877]: info: CorePlayQueue::getTrack 0 Feb 07 08:30:12 music go-librespot[25167]: time="2026-02-07T08:30:12-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Feb 07 08:30:12 music go-librespot[25167]: time="2026-02-07T08:30:12-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 07 08:30:12 music go-librespot[25167]: time="2026-02-07T08:30:12-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 07 08:30:12 music go-librespot[25167]: time="2026-02-07T08:30:12-05:00" level=info msg="zeroconf server listening on port 41231" Feb 07 08:30:12 music go-librespot[25167]: time="2026-02-07T08:30:12-05:00" level=debug msg="obtained new client token: AADkfjwfNKuuWmRmc/gXEGDaKDosI8ZkJGpbmTtn4Tk8av0BFEkjkFIQKD6NMt4jrBUja5Vl4qlmpsR0DkEgKvW/iyuXfqG51gtxVQqFEC2AQp+1F/yYqz49Ql9iBlPhFBks4DhP8OjKB67K8mxPrHGHpwrYvvcOYtpvB8w2mpB8nh8AmfKw0NQZhlWTJ3nw5m5pN+kyI8vKLhIGzDQAH1zMUXYUQ101FnEzD30XUHw7Aqn+DkPxQWs=" Feb 07 08:30:12 music go-librespot[25167]: time="2026-02-07T08:30:12-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 08:30:12 music go-librespot[25167]: time="2026-02-07T08:30:12-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:12 music go-librespot[25167]: time="2026-02-07T08:30:12-05:00" level=debug msg="completed challenge" Feb 07 08:30:12 music go-librespot[25167]: time="2026-02-07T08:30:12-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:13 music go-librespot[25167]: time="2026-02-07T08:30:13-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 08:30:13 music go-librespot[25167]: time="2026-02-07T08:30:13-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:13 music go-librespot[25167]: time="2026-02-07T08:30:13-05:00" level=debug msg="completed challenge" Feb 07 08:30:13 music go-librespot[25167]: time="2026-02-07T08:30:13-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:13 music volumio[24877]: info: Initializing connection to go-librespot Websocket Feb 07 08:30:13 music volumio[24877]: info: Connection to go-librespot Websocket established Feb 07 08:30:13 music go-librespot[25167]: time="2026-02-07T08:30:13-05:00" level=debug msg="new websocket client" Feb 07 08:30:13 music go-librespot[25167]: time="2026-02-07T08:30:13-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 07 08:30:13 music go-librespot[25167]: time="2026-02-07T08:30:13-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:13 music go-librespot[25167]: time="2026-02-07T08:30:13-05:00" level=debug msg="completed challenge" Feb 07 08:30:13 music go-librespot[25167]: time="2026-02-07T08:30:13-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:14 music go-librespot[25167]: time="2026-02-07T08:30:14-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 07 08:30:14 music go-librespot[25167]: time="2026-02-07T08:30:14-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:14 music go-librespot[25167]: time="2026-02-07T08:30:14-05:00" level=debug msg="completed challenge" Feb 07 08:30:14 music go-librespot[25167]: time="2026-02-07T08:30:14-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:14 music volumio[24877]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 07 08:30:14 music volumio[24877]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 07 08:30:14 music volumio[24877]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 07 08:30:14 music volumio[24877]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 07 08:30:14 music volumio[24877]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 07 08:30:14 music volumio[24877]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 07 08:30:14 music volumio[24877]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 07 08:30:14 music volumio[24877]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 07 08:30:14 music volumio[24877]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 07 08:30:14 music volumio[24877]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 07 08:30:14 music volumio[24877]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 07 08:30:14 music volumio[24877]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 07 08:30:14 music volumio[24877]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 07 08:30:14 music volumio[24877]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 07 08:30:14 music volumio[24877]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 07 08:30:14 music volumio[24877]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 07 08:30:14 music volumio[24877]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 07 08:30:14 music volumio[24877]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 07 08:30:14 music volumio[24877]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 07 08:30:14 music volumio[24877]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 07 08:30:14 music volumio[24877]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 07 08:30:14 music volumio[24877]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 07 08:30:14 music volumio[24877]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 07 08:30:14 music volumio[24877]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 07 08:30:14 music volumio[24877]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 07 08:30:14 music volumio[24877]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 07 08:30:14 music volumio[24877]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 07 08:30:14 music volumio[24877]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 07 08:30:14 music volumio[24877]: info: Adding plugin bluetooth to MyMusic Plugins Feb 07 08:30:14 music volumio[24877]: info: Adding plugin multiroom to MyMusic Plugins Feb 07 08:30:14 music volumio[24877]: info: Adding plugin metavolumio to MyMusic Plugins Feb 07 08:30:14 music volumio[24877]: info: Adding plugin cd_controller to MyMusic Plugins Feb 07 08:30:14 music volumio[24877]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 07 08:30:14 music volumio[24877]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 07 08:30:14 music volumio[24877]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 07 08:30:14 music volumio[24877]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 07 08:30:15 music go-librespot[25167]: time="2026-02-07T08:30:15-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 07 08:30:15 music go-librespot[25167]: time="2026-02-07T08:30:15-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:15 music go-librespot[25167]: time="2026-02-07T08:30:15-05:00" level=debug msg="completed challenge" Feb 07 08:30:15 music volumio[24877]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 07 08:30:15 music volumio[24877]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 07 08:30:15 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 08:30:15 music volumio[24877]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 08:30:15 music volumio[24877]: info: Starting MyVolumio Remote Streaming Endpoints Feb 07 08:30:15 music go-librespot[25167]: time="2026-02-07T08:30:15-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:15 music volumio[24877]: info: MyVolumio login type: Token Feb 07 08:30:15 music volumio[24877]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 07 08:30:15 music volumio[24877]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 07 08:30:16 music go-librespot[25167]: time="2026-02-07T08:30:16-05:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 08:30:16 music go-librespot[25167]: time="2026-02-07T08:30:16-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.3.63:50208->104.199.65.9:80: read: connection reset by peer" Feb 07 08:30:16 music go-librespot[25167]: time="2026-02-07T08:30:16-05: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: read tcp 192.168.3.63:50208->104.199.65.9:80: read: connection reset by peer" Feb 07 08:30:16 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 08:30:16 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 08:30:16 music volumio[24877]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 07 08:30:16 music volumio[24877]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 07 08:30:16 music volumio[24877]: info: Streaming services startup Feb 07 08:30:16 music volumio[24877]: info: Starting Streaming Daemon Feb 07 08:30:16 music sudo[25177]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 07 08:30:16 music sudo[25177]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:16 music volumio[24877]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 07 08:30:16 music sudo[25177]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:16 music volumio[24877]: info: Getting Spotify volume Feb 07 08:30:16 music volumio[24877]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 08:30:16 music volumio[24877]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 08:30:16 music volumio[24877]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 07 08:30:16 music volumio[24877]: errno: -111, Feb 07 08:30:16 music volumio[24877]: code: 'ECONNREFUSED', Feb 07 08:30:16 music volumio[24877]: syscall: 'connect', Feb 07 08:30:16 music volumio[24877]: address: '127.0.0.1', Feb 07 08:30:16 music volumio[24877]: port: 9879, Feb 07 08:30:16 music volumio[24877]: response: undefined Feb 07 08:30:16 music volumio[24877]: } Feb 07 08:30:16 music volumio[24877]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 08:30:17 music sudo[25212]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-07 08:29' Feb 07 08:30:17 music sudo[25212]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:17 music sudo[25212]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:17 music volumio-remote-updater[31331]: [2026-02-07 08:30:17] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 07 08:30:17 music volumio-remote-updater[31331]: [2026-02-07 08:30:17] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 07 08:30:17 music systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 07 08:30:18 music systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 07 08:30:18 music systemd[1]: volumio.service: Consumed 26.439s CPU time. Feb 07 08:30:18 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 08:30:18 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 08:30:18 music systemd[1]: volumio.service: Scheduled restart job, restart counter is at 49417. Feb 07 08:30:18 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 08:30:18 music systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 07 08:30:18 music systemd[1]: volumio.service: Consumed 26.439s CPU time. Feb 07 08:30:18 music systemd[1]: Started volumio.service - Volumio Backend Module. Feb 07 08:30:18 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 08:30:19 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 07 08:30:19 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 08:30:19 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 08:30:19 music go-librespot[25239]: go-librespot daemon starting... Feb 07 08:30:19 music go-librespot[25240]: time="2026-02-07T08:30:19-05:00" level=info msg="running go-librespot 0.6.2" Feb 07 08:30:19 music go-librespot[25240]: time="2026-02-07T08:30:19-05:00" level=debug msg="app state loaded" Feb 07 08:30:19 music go-librespot[25240]: time="2026-02-07T08:30:19-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 08:30:19 music go-librespot[25240]: time="2026-02-07T08:30:19-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 08:30:19 music go-librespot[25240]: time="2026-02-07T08:30:19-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 07 08:30:19 music go-librespot[25240]: time="2026-02-07T08:30:19-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 07 08:30:20 music go-librespot[25240]: time="2026-02-07T08:30:20-05:00" level=info msg="zeroconf server listening on port 36601" Feb 07 08:30:20 music go-librespot[25240]: time="2026-02-07T08:30:20-05:00" level=debug msg="obtained new client token: AACcqoFQzV9RNblJuY/1mY43m0H+0OBb60yGh2f8U5+ookFtym7NiUbEviGqTywWSpIYRksybVqn/n7BOwvVmhWN6nnfI8frLKmf6cD+hyBHH/4DDzHlCFI+gIKjUDuWQrnt3vZiyAZkwa4BpZRAp9imVXxAtT9Zf7GU39Dqjzh+amjM+RBA88G4aRMHa3LCFE/dMrGYHzsfySovpxtnNvCZ6t35peK2snwB6PAp7SIl8kh0J2fG" Feb 07 08:30:20 music go-librespot[25240]: time="2026-02-07T08:30:20-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 08:30:20 music go-librespot[25240]: time="2026-02-07T08:30:20-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:20 music go-librespot[25240]: time="2026-02-07T08:30:20-05:00" level=debug msg="completed challenge" Feb 07 08:30:20 music go-librespot[25240]: time="2026-02-07T08:30:20-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:20 music volumio[25224]: info: ------------------------------------------- Feb 07 08:30:20 music volumio[25224]: info: ----- Volumio3 ---- Feb 07 08:30:20 music volumio[25224]: info: ------------------------------------------- Feb 07 08:30:20 music volumio[25224]: info: ----- System startup ---- Feb 07 08:30:20 music volumio[25224]: info: ------------------------------------------- Feb 07 08:30:20 music go-librespot[25240]: time="2026-02-07T08:30:20-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 08:30:20 music go-librespot[25240]: time="2026-02-07T08:30:20-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:20 music go-librespot[25240]: time="2026-02-07T08:30:20-05:00" level=debug msg="completed challenge" Feb 07 08:30:21 music go-librespot[25240]: time="2026-02-07T08:30:21-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:21 music volumio[25224]: info: MYVOLUMIO Environment detected Feb 07 08:30:21 music volumio[25224]: info: Plugin folders cleanup Feb 07 08:30:21 music volumio[25224]: info: Scanning into folder /volumio/app/plugins/ Feb 07 08:30:21 music volumio[25224]: info: Scanning category audio_interface Feb 07 08:30:21 music volumio[25224]: info: Scanning category miscellanea Feb 07 08:30:21 music volumio[25224]: info: Scanning category music_service Feb 07 08:30:21 music volumio[25224]: info: Scanning category plugins.json Feb 07 08:30:21 music volumio[25224]: info: Scanning category system_controller Feb 07 08:30:21 music volumio[25224]: info: Scanning category user_interface Feb 07 08:30:21 music volumio[25224]: info: Scanning into folder /data/plugins/ Feb 07 08:30:21 music volumio[25224]: info: Scanning category music_service Feb 07 08:30:21 music volumio[25224]: info: Plugin folders cleanup completed Feb 07 08:30:21 music volumio[25224]: info: ------------------------------------------- Feb 07 08:30:21 music volumio[25224]: info: ----- Core plugins startup ---- Feb 07 08:30:21 music volumio[25224]: info: ------------------------------------------- Feb 07 08:30:21 music volumio[25224]: info: Loading plugins from folder /volumio/app/plugins/ Feb 07 08:30:21 music volumio[25224]: info: Adding plugin upnp to MyMusic Plugins Feb 07 08:30:21 music volumio[25224]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 07 08:30:21 music volumio[25224]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 07 08:30:21 music volumio[25224]: info: Loading plugins from folder /data/plugins/ Feb 07 08:30:21 music volumio[25224]: info: Loading plugin "system"... Feb 07 08:30:21 music volumio[25224]: info: Loading plugin "appearance"... Feb 07 08:30:21 music go-librespot[25240]: time="2026-02-07T08:30:21-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:80, retrying with a different AP" error="dial tcp 34.158.255.62:80: connect: connection refused" Feb 07 08:30:21 music go-librespot[25240]: time="2026-02-07T08:30:21-05:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 08:30:22 music go-librespot[25240]: time="2026-02-07T08:30:22-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:22 music go-librespot[25240]: time="2026-02-07T08:30:22-05:00" level=debug msg="completed challenge" Feb 07 08:30:22 music volumio[25224]: info: Loading plugin "network"... Feb 07 08:30:22 music volumio[25224]: info: Refreshing Cached IP Addresses Feb 07 08:30:22 music sudo[25262]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 08:30:22 music sudo[25262]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:22 music sudo[25262]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:22 music sudo[25264]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 08:30:22 music sudo[25264]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:22 music volumio[25224]: info: Loading plugin "services"... Feb 07 08:30:22 music volumio[25224]: info: Loading plugin "alsa_controller"... Feb 07 08:30:22 music sudo[25264]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:22 music sudo[25272]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 07 08:30:22 music go-librespot[25240]: time="2026-02-07T08:30:22-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:22 music sudo[25272]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:22 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 08:30:22 music volumio[25224]: info: Loading plugin "wizard"... Feb 07 08:30:22 music volumio[25224]: info: Loading plugin "networkfs"... Feb 07 08:30:22 music volumio[25224]: info: Starting Udev Watcher for removable devices Feb 07 08:30:22 music volumio[25224]: info: Ignoring mount for partition: boot Feb 07 08:30:22 music volumio[25224]: info: Ignoring mount for partition: volumio Feb 07 08:30:22 music volumio[25224]: info: Ignoring mount for partition: volumio_data Feb 07 08:30:22 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 08:30:22 music volumio[25224]: info: Loading plugin "volumio_command_line_client"... Feb 07 08:30:22 music volumio[25224]: info: Loading plugin "upnp"... Feb 07 08:30:22 music volumio[25224]: info: [1770471022661] Starting Upmpd Daemon Feb 07 08:30:22 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 08:30:22 music volumio[25224]: info: Loading plugin "my_music"... Feb 07 08:30:22 music volumio[25224]: info: Loading plugin "mpd"... Feb 07 08:30:22 music volumio-remote-updater[31331]: [2026-02-07 08:30:22] [connect] Successful connection Feb 07 08:30:23 music volumio[25224]: info: Loading plugin "upnp_browser"... Feb 07 08:30:23 music sudo[25272]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:23 music go-librespot[25240]: time="2026-02-07T08:30:23-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 08:30:23 music go-librespot[25240]: time="2026-02-07T08:30:23-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.3.63:44340->104.199.65.9:443: read: connection reset by peer" Feb 07 08:30:23 music go-librespot[25240]: time="2026-02-07T08:30:23-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 07 08:30:24 music go-librespot[25240]: time="2026-02-07T08:30:24-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:24 music go-librespot[25240]: time="2026-02-07T08:30:24-05:00" level=debug msg="completed challenge" Feb 07 08:30:24 music go-librespot[25240]: time="2026-02-07T08:30:24-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:24 music volumio[25224]: info: Starting UPNP Browser Feb 07 08:30:24 music volumio[25224]: info: Loading plugin "alarm-clock"... Feb 07 08:30:24 music go-librespot[25240]: time="2026-02-07T08:30:24-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 08:30:24 music go-librespot[25240]: time="2026-02-07T08:30:24-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:24 music go-librespot[25240]: time="2026-02-07T08:30:24-05:00" level=debug msg="completed challenge" Feb 07 08:30:24 music volumio[25224]: info: Loading plugin "airplay_emulation"... Feb 07 08:30:24 music volumio[25224]: info: Starting Shairport Sync Feb 07 08:30:24 music volumio[25224]: info: Loading plugin "last_100"... Feb 07 08:30:24 music volumio[25224]: info: Loading plugin "webradio"... Feb 07 08:30:24 music go-librespot[25240]: time="2026-02-07T08:30:24-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:24 music go-librespot[25240]: time="2026-02-07T08:30:24-05: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 07 08:30:24 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 08:30:24 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 08:30:24 music volumio[25224]: info: Loading plugin "i2s_dacs"... Feb 07 08:30:24 music volumio[25224]: info: I2S DAC not set, start Auto-detection Feb 07 08:30:24 music volumio[25224]: info: Loading plugin "volumiodiscovery"... Feb 07 08:30:24 music volumio[25224]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 08:30:24 music volumio[25224]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 08:30:24 music volumio[25224]: *** WARNING *** For more information see Feb 07 08:30:24 music volumio[25224]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 08:30:24 music volumio[25224]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 08:30:24 music volumio[25224]: *** WARNING *** For more information see Feb 07 08:30:24 music node[25224]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 08:30:24 music node[25224]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 08:30:24 music node[25224]: *** WARNING *** For more information see Feb 07 08:30:24 music node[25224]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 08:30:24 music node[25224]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 08:30:24 music node[25224]: *** WARNING *** For more information see Feb 07 08:30:24 music volumio[25224]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 07 08:30:24 music volumio[25224]: info: Discovery: Started advertising with name: music Feb 07 08:30:25 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 08:30:25 music volumio[25224]: info: Loading plugin "spop"... Feb 07 08:30:26 music volumio[25224]: info: Loading plugin "outputs"... Feb 07 08:30:26 music volumio[25224]: info: Loading plugin "albumart"... Feb 07 08:30:26 music volumio[25224]: info: Plugin example_plugin is not enabled Feb 07 08:30:26 music volumio[25224]: info: Loading plugin "inputs"... Feb 07 08:30:26 music volumio[25224]: info: Loading plugin "updater_comm"... Feb 07 08:30:26 music volumio[25224]: info: Plugin mpdemulation is not enabled Feb 07 08:30:26 music volumio[25224]: info: Loading plugin "rest_api"... Feb 07 08:30:26 music volumio[25224]: info: Loading plugin "websocket"... Feb 07 08:30:26 music volumio[25224]: info: Starting Socket.io Server version 1.7.4 Feb 07 08:30:26 music volumio[25224]: info: Loading i18n strings for locale en Feb 07 08:30:26 music volumio[25224]: Updating browse sources language Feb 07 08:30:26 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 08:30:26 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 08:30:26 music volumio[25224]: info: CoreCommandRouter::initPlayerControls Feb 07 08:30:26 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:26 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:26 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:26 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:26 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:26 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:26 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:26 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:26 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 08:30:26 music volumio[25224]: Express server listening on port 3000 Feb 07 08:30:26 music volumio[25224]: [Metrics] WebUI: 6s 622.15ms Feb 07 08:30:26 music volumio[25224]: info: CoreStateMachine::resetVolumioState Feb 07 08:30:26 music volumio[25224]: info: CoreStateMachine::getcurrentVolume Feb 07 08:30:26 music volumio[25224]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 08:30:26 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 08:30:26 music volumio[25224]: info: Volumio Network Manager: Network status updated: 1 Feb 07 08:30:26 music volumio[25224]: info: VolumeController:: Volume=86 Mute =false Feb 07 08:30:26 music volumio[25224]: info: CoreStateMachine::pushState Feb 07 08:30:26 music volumio[25224]: info: CorePlayQueue::getTrack 0 Feb 07 08:30:26 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 08:30:26 music volumio[25224]: info: CoreCommandRouter::volumioPushState Feb 07 08:30:26 music volumio[25224]: info: CoreStateMachine::updateTrackBlock Feb 07 08:30:26 music volumio[25224]: info: CorePlayQueue::getTrackBlock Feb 07 08:30:26 music volumio[25224]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 08:30:26 music volumio[25224]: info: CoreCommandRouter::volumioGetState Feb 07 08:30:26 music volumio[25224]: info: CorePlayQueue::getTrack 0 Feb 07 08:30:26 music volumio[25297]: Forking 3 albumart workers Feb 07 08:30:26 music volumio-remote-updater[31331]: [2026-02-07 08:30:26] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770471022 101 Feb 07 08:30:26 music volumio[25224]: 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 07 08:30:26 music volumio[25224]: info: Reloading queue from file Feb 07 08:30:26 music volumio[25224]: info: CoreStateMachine::setRepeat null single undefined Feb 07 08:30:26 music volumio[25224]: info: CoreStateMachine::pushState Feb 07 08:30:26 music volumio[25224]: info: CorePlayQueue::getTrack 0 Feb 07 08:30:26 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 08:30:26 music volumio[25224]: info: CoreCommandRouter::volumioPushState Feb 07 08:30:26 music volumio[25224]: info: CoreStateMachine::setRandom null Feb 07 08:30:26 music volumio[25224]: info: CoreStateMachine::pushState Feb 07 08:30:26 music volumio[25224]: info: CorePlayQueue::getTrack 0 Feb 07 08:30:26 music volumio[25224]: info: CoreCommandRouter::volumioPushState Feb 07 08:30:26 music volumio[25224]: info: Setting Device type: Raspberry PI Feb 07 08:30:26 music volumio[25224]: info: Listing playlists Feb 07 08:30:26 music volumio[25224]: info: Listing playlists Feb 07 08:30:26 music volumio[25224]: info: VolumeController:: Volume=86 Mute =false Feb 07 08:30:26 music volumio[25224]: info: CoreStateMachine::pushState Feb 07 08:30:26 music volumio[25224]: info: CorePlayQueue::getTrack 0 Feb 07 08:30:26 music volumio[25224]: info: CoreCommandRouter::volumioPushState Feb 07 08:30:26 music volumio[25224]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 07 08:30:26 music volumio[25224]: info: Discovery: Found device music Feb 07 08:30:26 music volumio[25224]: info: CoreCommandRouter::volumioGetState Feb 07 08:30:26 music volumio[25224]: info: CorePlayQueue::getTrack 0 Feb 07 08:30:27 music volumio[25224]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 07 08:30:27 music volumio[25224]: info: Discovery: Found device music Feb 07 08:30:27 music volumio[25224]: info: CoreCommandRouter::volumioGetState Feb 07 08:30:27 music volumio[25224]: info: CorePlayQueue::getTrack 0 Feb 07 08:30:27 music volumio[25224]: info: Completed loading Core Plugins Feb 07 08:30:27 music volumio[25224]: info: Preparing to generate the ALSA configuration file Feb 07 08:30:27 music volumio[25224]: info: Asound.conf file unchanged, so no further update is needed Feb 07 08:30:27 music volumio[25224]: info: Output device has changed, restarting MPD Feb 07 08:30:27 music volumio[25224]: info: Output device has changed, restarting Shairport Sync Feb 07 08:30:27 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:27 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 08:30:27 music sudo[25352]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 08:30:27 music sudo[25352]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:27 music sudo[25352]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:27 music volumio[25224]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 08:30:27 music volumio[25224]: info: ___________ START PLUGINS ___________ Feb 07 08:30:27 music sudo[25354]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 08:30:27 music sudo[25354]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:27 music volumio[25224]: info: ControllerMpd::onStart: Initializing MPD Feb 07 08:30:27 music volumio[25224]: info: Creating MPD Configuration file Feb 07 08:30:27 music sudo[25362]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 08:30:27 music sudo[25362]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:27 music systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 07 08:30:27 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 08:30:27 music volumio[25224]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 08:30:27 music volumio[25224]: info: [1770471027256] CoreMusicLibrary::Adding element Media Servers Feb 07 08:30:27 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 08:30:27 music sudo[25362]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:27 music sudo[25365]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 08:30:27 music sudo[25365]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:27 music volumio[25224]: info: UPNP Browser: Client initialized successfully Feb 07 08:30:27 music systemd[1]: mpd.service: Deactivated successfully. Feb 07 08:30:27 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 08:30:27 music systemd[1]: mpd.service: Consumed 4.203s CPU time. Feb 07 08:30:27 music systemd[1]: mpd.socket: Deactivated successfully. Feb 07 08:30:27 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 08:30:27 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 08:30:27 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:27 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 08:30:27 music volumio[25224]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 08:30:27 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:27 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 08:30:27 music volumio[25224]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 08:30:27 music volumio[25224]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 08:30:27 music volumio[25224]: info: [1770471027418] CoreMusicLibrary::Adding element Last_100 Feb 07 08:30:27 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 08:30:27 music volumio[25224]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 08:30:27 music volumio[25224]: info: [1770471027423] CoreMusicLibrary::Adding element Webradio Feb 07 08:30:27 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 08:30:27 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 08:30:27 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 08:30:27 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 08:30:27 music volumio[25224]: info: Initializing BBC Radios Feb 07 08:30:27 music systemd[1]: mpd.service: Deactivated successfully. Feb 07 08:30:27 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 08:30:27 music systemd[1]: mpd.socket: Deactivated successfully. Feb 07 08:30:27 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 08:30:27 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 08:30:27 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 08:30:27 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 08:30:27 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 08:30:27 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 08:30:27 music volumio[25224]: info: Creating Spotify config file Feb 07 08:30:27 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:27 music sudo[25381]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 07 08:30:27 music sudo[25381]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 07 08:30:27 music sudo[25381]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:27 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 07 08:30:27 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 08:30:27 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 08:30:27 music go-librespot[25394]: go-librespot daemon starting... Feb 07 08:30:27 music go-librespot[25395]: time="2026-02-07T08:30:27-05:00" level=info msg="running go-librespot 0.6.2" Feb 07 08:30:28 music volumio[25224]: info: Volumio Calling Home Feb 07 08:30:28 music go-librespot[25395]: time="2026-02-07T08:30:28-05:00" level=info msg="zeroconf server listening on port 38121" Feb 07 08:30:28 music volumio[25314]: Starting albumart workers Feb 07 08:30:28 music volumio[25224]: info: MPD Permissions set Feb 07 08:30:28 music volumio[25224]: info: MPD Permissions set Feb 07 08:30:28 music volumio[25315]: Starting albumart workers Feb 07 08:30:28 music volumio[25224]: info: Spotify config file written Feb 07 08:30:28 music sudo[25408]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 07 08:30:28 music sudo[25408]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:28 music volumio[25224]: 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 07 08:30:28 music volumio[25224]: info: Volumio called home Feb 07 08:30:28 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:28 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:28 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:28 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:28 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:28 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:28 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:28 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:28 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 07 08:30:28 music systemd[1]: go-librespot-daemon.service: Killing process 25398 (go-librespot) with signal SIGKILL. Feb 07 08:30:28 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 07 08:30:28 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 08:30:29 music volumio[25316]: Starting albumart workers Feb 07 08:30:29 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 08:30:29 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:29 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:29 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:29 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:29 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:29 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:29 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:29 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:29 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:29 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 08:30:29 music go-librespot[25412]: go-librespot daemon starting... Feb 07 08:30:29 music sudo[25408]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:29 music go-librespot[25416]: time="2026-02-07T08:30:29-05:00" level=info msg="running go-librespot 0.6.2" Feb 07 08:30:29 music go-librespot[25416]: time="2026-02-07T08:30:29-05:00" level=debug msg="app state loaded" Feb 07 08:30:29 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 08:30:29 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:29 music volumio[25224]: info: No need to fix Spotify hosts Feb 07 08:30:29 music go-librespot[25416]: time="2026-02-07T08:30:29-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 08:30:29 music go-librespot[25416]: time="2026-02-07T08:30:29-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 08:30:29 music go-librespot[25416]: time="2026-02-07T08:30:29-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 07 08:30:29 music go-librespot[25416]: time="2026-02-07T08:30:29-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 07 08:30:29 music go-librespot[25416]: time="2026-02-07T08:30:29-05:00" level=info msg="zeroconf server listening on port 33305" Feb 07 08:30:29 music go-librespot[25416]: time="2026-02-07T08:30:29-05:00" level=debug msg="obtained new client token: AABep9dmPia1lnQKaWej1ApZmC8RszkAL+Fzaem9BnTt7oZEegIngN3tza0eLv0OrWrXMEev9THAwlP0wpxLIaO/4mLwUpHg0q9SMxp8thHElm9v/2yw3+F8hIpO8MXHPwed/ch3E1N97OFXok0tbS36hHGq07Sh+zV7ZYCgOXjmmQWsQoJVHmV6ctg8vlgl0ojV/xORHJ4FpeoeoZm8Gu2qHK+4XpRZOBoRH5J8jS2NGebC3kkjWnU=" Feb 07 08:30:29 music go-librespot[25416]: time="2026-02-07T08:30:29-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 08:30:29 music volumio[25224]: info: Starting Shairport Sync Feb 07 08:30:29 music volumio[25224]: info: Starting Shairport Sync Feb 07 08:30:29 music volumio[25224]: info: Starting Shairport Sync Feb 07 08:30:30 music go-librespot[25416]: time="2026-02-07T08:30:30-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:30 music go-librespot[25416]: time="2026-02-07T08:30:30-05:00" level=debug msg="completed challenge" Feb 07 08:30:30 music sudo[25441]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 08:30:30 music volumio[25224]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 07 08:30:30 music sudo[25439]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 08:30:30 music sudo[25439]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:30 music sudo[25441]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:30 music go-librespot[25416]: time="2026-02-07T08:30:30-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:30 music sudo[25443]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 08:30:30 music sudo[25443]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:30 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 07 08:30:30 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 07 08:30:30 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 08:30:30 music systemd[1]: shairport-sync.service: Consumed 1.865s CPU time. Feb 07 08:30:30 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 08:30:30 music sudo[25441]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:30 music sudo[25439]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:30 music volumio[25224]: info: CoreCommandRouter::volumioGetState Feb 07 08:30:30 music volumio[25224]: info: CorePlayQueue::getTrack 0 Feb 07 08:30:30 music sudo[25443]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:30 music volumio[25224]: info: Shairport-Sync Started Feb 07 08:30:30 music volumio[25224]: Error adding Membership: Error: addMembership EINVAL Feb 07 08:30:30 music volumio[25224]: info: Shairport-Sync Started Feb 07 08:30:30 music volumio[25224]: info: Shairport-Sync Started Feb 07 08:30:30 music go-librespot[25416]: time="2026-02-07T08:30:30-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.255.62:443: connect: connection refused" Feb 07 08:30:30 music go-librespot[25416]: time="2026-02-07T08:30:30-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:80, retrying with a different AP" error="dial tcp 34.158.255.62:80: connect: connection refused" Feb 07 08:30:30 music go-librespot[25416]: time="2026-02-07T08:30:30-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 07 08:30:30 music go-librespot[25416]: time="2026-02-07T08:30:30-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:30 music go-librespot[25416]: time="2026-02-07T08:30:30-05:00" level=debug msg="completed challenge" Feb 07 08:30:30 music go-librespot[25416]: time="2026-02-07T08:30:30-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:31 music go-librespot[25416]: time="2026-02-07T08:30:31-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 08:30:31 music go-librespot[25416]: time="2026-02-07T08:30:31-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.3.63:55542->104.199.65.9:443: read: connection reset by peer" Feb 07 08:30:32 music mpd[25393]: 2026-02-07T08:30:32 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 07 08:30:32 music systemd[1]: Started mpd.service - Music Player Daemon. Feb 07 08:30:32 music sudo[25365]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:32 music sudo[25354]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:32 music volumio[25224]: info: Completed starting Core Plugins Feb 07 08:30:32 music volumio[25224]: info: ------------------------------------------- Feb 07 08:30:32 music volumio[25224]: info: ----- MyVolumio plugins startup ---- Feb 07 08:30:32 music volumio[25224]: info: ------------------------------------------- Feb 07 08:30:32 music volumio[25224]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 07 08:30:32 music volumio[25224]: error: MPD error: The expression evaluated to a falsy value: Feb 07 08:30:32 music volumio[25224]: assert.ok(self.idling) Feb 07 08:30:32 music volumio[25224]: error: The expression evaluated to a falsy value: Feb 07 08:30:32 music volumio[25224]: assert.ok(self.idling) Feb 07 08:30:32 music volumio[25224]: error: updateQueue error: null Feb 07 08:30:32 music volumio[25224]: info: MPD running with PID25393 Feb 07 08:30:32 music volumio[25224]: ,establishing connection Feb 07 08:30:32 music volumio[25224]: info: CoreCommandRouter::volumioGetState Feb 07 08:30:32 music volumio[25224]: info: CorePlayQueue::getTrack 0 Feb 07 08:30:32 music volumio[25224]: error: updateQueue error: null Feb 07 08:30:32 music go-librespot[25416]: time="2026-02-07T08:30:32-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 07 08:30:32 music go-librespot[25416]: time="2026-02-07T08:30:32-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:32 music go-librespot[25416]: time="2026-02-07T08:30:32-05:00" level=debug msg="completed challenge" Feb 07 08:30:32 music go-librespot[25416]: time="2026-02-07T08:30:32-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:32 music sudo[25496]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 08:30:32 music sudo[25496]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:32 music sudo[25496]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:32 music sudo[25498]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 08:30:32 music sudo[25498]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:32 music sudo[25498]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:32 music volumio[25224]: info: go-librespot daemon successfully initialized Feb 07 08:30:32 music sudo[25502]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 07 08:30:32 music sudo[25502]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:32 music sudo[25502]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:32 music volumio[25224]: info: Upmpdcli Daemon Started Feb 07 08:30:33 music go-librespot[25416]: time="2026-02-07T08:30:33-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 08:30:33 music go-librespot[25416]: time="2026-02-07T08:30:33-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:33 music go-librespot[25416]: time="2026-02-07T08:30:33-05:00" level=debug msg="completed challenge" Feb 07 08:30:33 music go-librespot[25416]: time="2026-02-07T08:30:33-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:33 music go-librespot[25416]: time="2026-02-07T08:30:33-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.255.62:443: connect: connection refused" Feb 07 08:30:33 music go-librespot[25416]: time="2026-02-07T08:30:33-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 07 08:30:33 music go-librespot[25416]: time="2026-02-07T08:30:33-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:33 music go-librespot[25416]: time="2026-02-07T08:30:33-05:00" level=debug msg="completed challenge" Feb 07 08:30:33 music go-librespot[25416]: time="2026-02-07T08:30:33-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:33 music go-librespot[25416]: time="2026-02-07T08:30:33-05: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 07 08:30:33 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 08:30:33 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 08:30:35 music sudo[25506]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 07 08:30:35 music sudo[25506]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:35 music sudo[25508]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 07 08:30:35 music sudo[25508]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:35 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 07 08:30:35 music systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 07 08:30:35 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 07 08:30:35 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 07 08:30:35 music sudo[25506]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:35 music volumio[25224]: info: Successfully started MPD Monitor Feb 07 08:30:35 music mpd_monitor.sh[25511]: MPD Monitor Service: Starting MPD Monitor Service Feb 07 08:30:35 music sudo[25508]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:35 music volumio[25224]: info: Successfully started MPD Monitor Feb 07 08:30:35 music volumio[25224]: info: Initializing connection to go-librespot Websocket Feb 07 08:30:35 music volumio[25224]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 08:30:37 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 07 08:30:37 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 08:30:37 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 08:30:37 music go-librespot[25515]: go-librespot daemon starting... Feb 07 08:30:37 music volumio[25224]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 07 08:30:37 music go-librespot[25516]: time="2026-02-07T08:30:37-05:00" level=info msg="running go-librespot 0.6.2" Feb 07 08:30:37 music go-librespot[25516]: time="2026-02-07T08:30:37-05:00" level=debug msg="app state loaded" Feb 07 08:30:37 music go-librespot[25516]: time="2026-02-07T08:30:37-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 08:30:37 music go-librespot[25516]: time="2026-02-07T08:30:37-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 08:30:37 music go-librespot[25516]: time="2026-02-07T08:30:37-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 07 08:30:37 music go-librespot[25516]: time="2026-02-07T08:30:37-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 07 08:30:37 music go-librespot[25516]: time="2026-02-07T08:30:37-05:00" level=info msg="zeroconf server listening on port 39763" Feb 07 08:30:37 music go-librespot[25516]: time="2026-02-07T08:30:37-05:00" level=debug msg="obtained new client token: AACHp2N0dkQpFlGSC+qldbVDI3cRkJg7/p/+DfhQ2ShlDFfAyvZsbuCX1STjd9HGbYchFWaaeEIbmaflla1mITpT/xqEy/O/qeSHn9dmMfBE3xm89Fs7dWNWf6acC040G/xRTWDGLexD/G35KieBuNgf5uwX1WlNcOEqbHz6K/WAdVhD9l/kLxhpl6XkPT8UoDqFQ9ukFHoUh4G9UhteUQwTkAfwQRWwOggkZ+VRDhxc2kv+x5YtTqM=" Feb 07 08:30:37 music go-librespot[25516]: time="2026-02-07T08:30:37-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 08:30:37 music go-librespot[25516]: time="2026-02-07T08:30:37-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:37 music go-librespot[25516]: time="2026-02-07T08:30:37-05:00" level=debug msg="completed challenge" Feb 07 08:30:37 music go-librespot[25516]: time="2026-02-07T08:30:37-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:38 music go-librespot[25516]: time="2026-02-07T08:30:38-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 08:30:38 music go-librespot[25516]: time="2026-02-07T08:30:38-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:38 music go-librespot[25516]: time="2026-02-07T08:30:38-05:00" level=debug msg="completed challenge" Feb 07 08:30:38 music go-librespot[25516]: time="2026-02-07T08:30:38-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:38 music volumio[25224]: info: Initializing connection to go-librespot Websocket Feb 07 08:30:38 music go-librespot[25516]: time="2026-02-07T08:30:38-05:00" level=debug msg="new websocket client" Feb 07 08:30:38 music volumio[25224]: info: Connection to go-librespot Websocket established Feb 07 08:30:39 music go-librespot[25516]: time="2026-02-07T08:30:39-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:80, retrying with a different AP" error="dial tcp 34.158.255.62:80: connect: connection refused" Feb 07 08:30:39 music go-librespot[25516]: time="2026-02-07T08:30:39-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 07 08:30:39 music go-librespot[25516]: time="2026-02-07T08:30:39-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:39 music go-librespot[25516]: time="2026-02-07T08:30:39-05:00" level=debug msg="completed challenge" Feb 07 08:30:39 music go-librespot[25516]: time="2026-02-07T08:30:39-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:39 music go-librespot[25516]: time="2026-02-07T08:30:39-05: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 07 08:30:40 music go-librespot[25516]: time="2026-02-07T08:30:40-05:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:80, retrying with a different AP" error="dial tcp 34.158.1.133:80: connect: connection refused" Feb 07 08:30:40 music go-librespot[25516]: time="2026-02-07T08:30:40-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 08:30:40 music go-librespot[25516]: time="2026-02-07T08:30:40-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:40 music go-librespot[25516]: time="2026-02-07T08:30:40-05:00" level=debug msg="completed challenge" Feb 07 08:30:40 music go-librespot[25516]: time="2026-02-07T08:30:40-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:40 music volumio[25224]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 07 08:30:40 music volumio[25224]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 07 08:30:40 music volumio[25224]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 07 08:30:40 music volumio[25224]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 07 08:30:40 music volumio[25224]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 07 08:30:40 music volumio[25224]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 07 08:30:40 music volumio[25224]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 07 08:30:40 music volumio[25224]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 07 08:30:40 music volumio[25224]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 07 08:30:40 music volumio[25224]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 07 08:30:40 music volumio[25224]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 07 08:30:40 music volumio[25224]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 07 08:30:40 music volumio[25224]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 07 08:30:40 music volumio[25224]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 07 08:30:40 music volumio[25224]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 07 08:30:40 music volumio[25224]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 07 08:30:40 music volumio[25224]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 07 08:30:40 music volumio[25224]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 07 08:30:40 music volumio[25224]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 07 08:30:40 music volumio[25224]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 07 08:30:40 music volumio[25224]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 07 08:30:40 music volumio[25224]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 07 08:30:40 music volumio[25224]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 07 08:30:40 music volumio[25224]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 07 08:30:40 music volumio[25224]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 07 08:30:40 music volumio[25224]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 07 08:30:40 music volumio[25224]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 07 08:30:40 music volumio[25224]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 07 08:30:40 music volumio[25224]: info: Adding plugin bluetooth to MyMusic Plugins Feb 07 08:30:40 music volumio[25224]: info: Adding plugin multiroom to MyMusic Plugins Feb 07 08:30:40 music volumio[25224]: info: Adding plugin metavolumio to MyMusic Plugins Feb 07 08:30:40 music volumio[25224]: info: Adding plugin cd_controller to MyMusic Plugins Feb 07 08:30:40 music volumio[25224]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 07 08:30:40 music volumio[25224]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 07 08:30:40 music volumio[25224]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 07 08:30:40 music volumio[25224]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 07 08:30:40 music go-librespot[25516]: time="2026-02-07T08:30:40-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 08:30:40 music go-librespot[25516]: time="2026-02-07T08:30:40-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:40 music go-librespot[25516]: time="2026-02-07T08:30:40-05:00" level=debug msg="completed challenge" Feb 07 08:30:40 music go-librespot[25516]: time="2026-02-07T08:30:40-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:41 music volumio[25224]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 07 08:30:41 music volumio[25224]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 07 08:30:41 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 08:30:41 music volumio[25224]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 08:30:41 music volumio[25224]: info: Starting MyVolumio Remote Streaming Endpoints Feb 07 08:30:41 music volumio[25224]: info: MyVolumio login type: Token Feb 07 08:30:41 music volumio[25224]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 07 08:30:41 music volumio[25224]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 07 08:30:41 music go-librespot[25516]: time="2026-02-07T08:30:41-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 07 08:30:41 music go-librespot[25516]: time="2026-02-07T08:30:41-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:41 music go-librespot[25516]: time="2026-02-07T08:30:41-05:00" level=debug msg="completed challenge" Feb 07 08:30:41 music go-librespot[25516]: time="2026-02-07T08:30:41-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:41 music go-librespot[25516]: time="2026-02-07T08:30:41-05: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 07 08:30:41 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 08:30:41 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 08:30:42 music volumio[25224]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 07 08:30:42 music volumio[25224]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 07 08:30:42 music volumio[25224]: info: Streaming services startup Feb 07 08:30:42 music volumio[25224]: info: Starting Streaming Daemon Feb 07 08:30:42 music sudo[25527]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 07 08:30:42 music sudo[25527]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:42 music volumio[25224]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 07 08:30:42 music sudo[25527]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:42 music volumio[25224]: info: Getting Spotify volume Feb 07 08:30:42 music volumio[25224]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 08:30:42 music volumio[25224]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 08:30:42 music volumio[25224]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 07 08:30:42 music volumio[25224]: errno: -111, Feb 07 08:30:42 music volumio[25224]: code: 'ECONNREFUSED', Feb 07 08:30:42 music volumio[25224]: syscall: 'connect', Feb 07 08:30:42 music volumio[25224]: address: '127.0.0.1', Feb 07 08:30:42 music volumio[25224]: port: 9879, Feb 07 08:30:42 music volumio[25224]: response: undefined Feb 07 08:30:42 music volumio[25224]: } Feb 07 08:30:42 music volumio[25224]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 08:30:43 music sudo[25561]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-07 08:29' Feb 07 08:30:43 music sudo[25561]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:43 music sudo[25561]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:43 music volumio-remote-updater[31331]: [2026-02-07 08:30:43] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 07 08:30:43 music volumio-remote-updater[31331]: [2026-02-07 08:30:43] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 07 08:30:43 music systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 07 08:30:43 music systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 07 08:30:43 music systemd[1]: volumio.service: Consumed 26.421s CPU time. Feb 07 08:30:43 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 08:30:43 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 08:30:43 music systemd[1]: volumio.service: Scheduled restart job, restart counter is at 49418. Feb 07 08:30:43 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 08:30:43 music systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 07 08:30:43 music systemd[1]: volumio.service: Consumed 26.421s CPU time. Feb 07 08:30:43 music systemd[1]: Started volumio.service - Volumio Backend Module. Feb 07 08:30:43 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 08:30:44 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 07 08:30:44 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 08:30:44 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 08:30:44 music go-librespot[25591]: go-librespot daemon starting... Feb 07 08:30:44 music go-librespot[25592]: time="2026-02-07T08:30:44-05:00" level=info msg="running go-librespot 0.6.2" Feb 07 08:30:44 music go-librespot[25592]: time="2026-02-07T08:30:44-05:00" level=debug msg="app state loaded" Feb 07 08:30:44 music go-librespot[25592]: time="2026-02-07T08:30:44-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 08:30:45 music go-librespot[25592]: time="2026-02-07T08:30:45-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Feb 07 08:30:45 music go-librespot[25592]: time="2026-02-07T08:30:45-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 07 08:30:45 music go-librespot[25592]: time="2026-02-07T08:30:45-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 07 08:30:45 music go-librespot[25592]: time="2026-02-07T08:30:45-05:00" level=info msg="zeroconf server listening on port 40441" Feb 07 08:30:45 music go-librespot[25592]: time="2026-02-07T08:30:45-05:00" level=debug msg="obtained new client token: AABIkBQBVZhBPJHcKFEql1zAmtu+6ZIHNOgYQRRX/BJLbwh64rVHNog687jXjntFmmgEyme5cvjiIkW7tYS13MEQMLHI7Vcuyozj/aRJbTcK3lQ/4rcECAcl2CZBVoJZ7889dh57OZt7wFO+TBzgZVgv5gesTEAPJN2FZLhJ5fLNU+ZpX5aiUjthPvCv14Ntj3Gr3CGO9bhk2FYaFOdwDgK5yXcmVmeTmBBc+c8rYs7/F9c58ZO5ezM=" Feb 07 08:30:45 music go-librespot[25592]: time="2026-02-07T08:30:45-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 08:30:45 music go-librespot[25592]: time="2026-02-07T08:30:45-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:45 music go-librespot[25592]: time="2026-02-07T08:30:45-05:00" level=debug msg="completed challenge" Feb 07 08:30:45 music go-librespot[25592]: time="2026-02-07T08:30:45-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:45 music volumio[25576]: info: ------------------------------------------- Feb 07 08:30:45 music volumio[25576]: info: ----- Volumio3 ---- Feb 07 08:30:45 music volumio[25576]: info: ------------------------------------------- Feb 07 08:30:45 music volumio[25576]: info: ----- System startup ---- Feb 07 08:30:45 music volumio[25576]: info: ------------------------------------------- Feb 07 08:30:46 music go-librespot[25592]: time="2026-02-07T08:30:46-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 08:30:46 music go-librespot[25592]: time="2026-02-07T08:30:46-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:46 music go-librespot[25592]: time="2026-02-07T08:30:46-05:00" level=debug msg="completed challenge" Feb 07 08:30:46 music go-librespot[25592]: time="2026-02-07T08:30:46-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:46 music volumio[25576]: info: MYVOLUMIO Environment detected Feb 07 08:30:46 music volumio[25576]: info: Plugin folders cleanup Feb 07 08:30:46 music volumio[25576]: info: Scanning into folder /volumio/app/plugins/ Feb 07 08:30:46 music volumio[25576]: info: Scanning category audio_interface Feb 07 08:30:46 music volumio[25576]: info: Scanning category miscellanea Feb 07 08:30:46 music volumio[25576]: info: Scanning category music_service Feb 07 08:30:46 music volumio[25576]: info: Scanning category plugins.json Feb 07 08:30:46 music volumio[25576]: info: Scanning category system_controller Feb 07 08:30:46 music volumio[25576]: info: Scanning category user_interface Feb 07 08:30:46 music volumio[25576]: info: Scanning into folder /data/plugins/ Feb 07 08:30:46 music volumio[25576]: info: Scanning category music_service Feb 07 08:30:46 music volumio[25576]: info: Plugin folders cleanup completed Feb 07 08:30:46 music volumio[25576]: info: ------------------------------------------- Feb 07 08:30:46 music volumio[25576]: info: ----- Core plugins startup ---- Feb 07 08:30:46 music volumio[25576]: info: ------------------------------------------- Feb 07 08:30:46 music volumio[25576]: info: Loading plugins from folder /volumio/app/plugins/ Feb 07 08:30:46 music volumio[25576]: info: Adding plugin upnp to MyMusic Plugins Feb 07 08:30:46 music volumio[25576]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 07 08:30:46 music volumio[25576]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 07 08:30:46 music volumio[25576]: info: Loading plugins from folder /data/plugins/ Feb 07 08:30:46 music volumio[25576]: info: Loading plugin "system"... Feb 07 08:30:46 music volumio[25576]: info: Loading plugin "appearance"... Feb 07 08:30:46 music go-librespot[25592]: time="2026-02-07T08:30:46-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 07 08:30:47 music go-librespot[25592]: time="2026-02-07T08:30:47-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:47 music go-librespot[25592]: time="2026-02-07T08:30:47-05:00" level=debug msg="completed challenge" Feb 07 08:30:47 music go-librespot[25592]: time="2026-02-07T08:30:47-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:47 music go-librespot[25592]: time="2026-02-07T08:30:47-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 07 08:30:47 music go-librespot[25592]: time="2026-02-07T08:30:47-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:47 music go-librespot[25592]: time="2026-02-07T08:30:47-05:00" level=debug msg="completed challenge" Feb 07 08:30:47 music go-librespot[25592]: time="2026-02-07T08:30:47-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:47 music volumio[25576]: info: Loading plugin "network"... Feb 07 08:30:47 music volumio[25576]: info: Refreshing Cached IP Addresses Feb 07 08:30:47 music sudo[25614]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 08:30:47 music sudo[25614]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:47 music sudo[25616]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 08:30:47 music sudo[25616]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:47 music sudo[25614]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:47 music sudo[25616]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:47 music volumio[25576]: info: Loading plugin "services"... Feb 07 08:30:47 music volumio[25576]: info: Loading plugin "alsa_controller"... Feb 07 08:30:47 music sudo[25624]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 07 08:30:47 music sudo[25624]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:48 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 08:30:48 music volumio[25576]: info: Loading plugin "wizard"... Feb 07 08:30:48 music volumio[25576]: info: Loading plugin "networkfs"... Feb 07 08:30:48 music volumio[25576]: info: Starting Udev Watcher for removable devices Feb 07 08:30:48 music volumio[25576]: info: Ignoring mount for partition: boot Feb 07 08:30:48 music volumio[25576]: info: Ignoring mount for partition: volumio Feb 07 08:30:48 music volumio[25576]: info: Ignoring mount for partition: volumio_data Feb 07 08:30:48 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 08:30:48 music volumio[25576]: info: Loading plugin "volumio_command_line_client"... Feb 07 08:30:48 music volumio[25576]: info: Loading plugin "upnp"... Feb 07 08:30:48 music volumio[25576]: info: [1770471048138] Starting Upmpd Daemon Feb 07 08:30:48 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 08:30:48 music volumio[25576]: info: Loading plugin "my_music"... Feb 07 08:30:48 music volumio[25576]: info: Loading plugin "mpd"... Feb 07 08:30:48 music go-librespot[25592]: time="2026-02-07T08:30:48-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 07 08:30:48 music volumio[25576]: info: Loading plugin "upnp_browser"... Feb 07 08:30:48 music volumio-remote-updater[31331]: [2026-02-07 08:30:48] [connect] Successful connection Feb 07 08:30:48 music sudo[25624]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:48 music go-librespot[25592]: time="2026-02-07T08:30:48-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:48 music go-librespot[25592]: time="2026-02-07T08:30:48-05:00" level=debug msg="completed challenge" Feb 07 08:30:48 music go-librespot[25592]: time="2026-02-07T08:30:48-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:49 music go-librespot[25592]: time="2026-02-07T08:30:49-05:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 08:30:49 music go-librespot[25592]: time="2026-02-07T08:30:49-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.3.63:33240->104.199.65.9:80: read: connection reset by peer" Feb 07 08:30:49 music go-librespot[25592]: time="2026-02-07T08:30:49-05: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: read tcp 192.168.3.63:33240->104.199.65.9:80: read: connection reset by peer" Feb 07 08:30:49 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 08:30:49 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 08:30:50 music volumio[25576]: info: Starting UPNP Browser Feb 07 08:30:50 music volumio[25576]: info: Loading plugin "alarm-clock"... Feb 07 08:30:50 music volumio[25576]: info: Loading plugin "airplay_emulation"... Feb 07 08:30:50 music volumio[25576]: info: Starting Shairport Sync Feb 07 08:30:50 music volumio[25576]: info: Loading plugin "last_100"... Feb 07 08:30:50 music volumio[25576]: info: Loading plugin "webradio"... Feb 07 08:30:50 music volumio[25576]: info: Loading plugin "i2s_dacs"... Feb 07 08:30:50 music volumio[25576]: info: I2S DAC not set, start Auto-detection Feb 07 08:30:50 music volumio[25576]: info: Loading plugin "volumiodiscovery"... Feb 07 08:30:50 music volumio[25576]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 08:30:50 music volumio[25576]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 08:30:50 music volumio[25576]: *** WARNING *** For more information see Feb 07 08:30:50 music volumio[25576]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 08:30:50 music volumio[25576]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 08:30:50 music volumio[25576]: *** WARNING *** For more information see Feb 07 08:30:50 music node[25576]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 08:30:50 music node[25576]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 08:30:50 music node[25576]: *** WARNING *** For more information see Feb 07 08:30:50 music node[25576]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 08:30:50 music node[25576]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 08:30:50 music node[25576]: *** WARNING *** For more information see Feb 07 08:30:50 music volumio[25576]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 07 08:30:50 music volumio[25576]: info: Discovery: Started advertising with name: music Feb 07 08:30:50 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 08:30:50 music volumio[25576]: info: Loading plugin "spop"... Feb 07 08:30:51 music volumio[25576]: info: Loading plugin "outputs"... Feb 07 08:30:51 music volumio[25576]: info: Loading plugin "albumart"... Feb 07 08:30:51 music volumio[25576]: info: Plugin example_plugin is not enabled Feb 07 08:30:51 music volumio[25576]: info: Loading plugin "inputs"... Feb 07 08:30:51 music volumio[25576]: info: Loading plugin "updater_comm"... Feb 07 08:30:51 music volumio[25576]: info: Plugin mpdemulation is not enabled Feb 07 08:30:51 music volumio[25576]: info: Loading plugin "rest_api"... Feb 07 08:30:51 music volumio[25576]: info: Loading plugin "websocket"... Feb 07 08:30:51 music volumio[25576]: info: Starting Socket.io Server version 1.7.4 Feb 07 08:30:51 music volumio[25576]: info: Loading i18n strings for locale en Feb 07 08:30:51 music volumio[25576]: Updating browse sources language Feb 07 08:30:51 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 08:30:51 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 08:30:51 music volumio[25576]: info: CoreCommandRouter::initPlayerControls Feb 07 08:30:51 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:51 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:51 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:51 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:51 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:51 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:51 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:51 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:51 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 08:30:51 music volumio[25576]: Express server listening on port 3000 Feb 07 08:30:51 music volumio[25576]: [Metrics] WebUI: 6s 556.39ms Feb 07 08:30:51 music volumio[25576]: info: CoreStateMachine::resetVolumioState Feb 07 08:30:51 music volumio[25576]: info: CoreStateMachine::getcurrentVolume Feb 07 08:30:51 music volumio[25576]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 08:30:51 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 08:30:52 music volumio[25576]: info: Volumio Network Manager: Network status updated: 1 Feb 07 08:30:52 music volumio-remote-updater[31331]: [2026-02-07 08:30:52] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770471048 101 Feb 07 08:30:52 music volumio[25649]: Forking 3 albumart workers Feb 07 08:30:52 music volumio[25576]: 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 07 08:30:52 music volumio[25576]: info: VolumeController:: Volume=86 Mute =false Feb 07 08:30:52 music volumio[25576]: info: CoreStateMachine::pushState Feb 07 08:30:52 music volumio[25576]: info: CorePlayQueue::getTrack 0 Feb 07 08:30:52 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 08:30:52 music volumio[25576]: info: CoreCommandRouter::volumioPushState Feb 07 08:30:52 music volumio[25576]: info: CoreStateMachine::updateTrackBlock Feb 07 08:30:52 music volumio[25576]: info: CorePlayQueue::getTrackBlock Feb 07 08:30:52 music volumio[25576]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 08:30:52 music volumio[25576]: info: Reloading queue from file Feb 07 08:30:52 music volumio[25576]: info: CoreStateMachine::setRepeat null single undefined Feb 07 08:30:52 music volumio[25576]: info: CoreStateMachine::pushState Feb 07 08:30:52 music volumio[25576]: info: CorePlayQueue::getTrack 0 Feb 07 08:30:52 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 08:30:52 music volumio[25576]: info: CoreCommandRouter::volumioPushState Feb 07 08:30:52 music volumio[25576]: info: CoreStateMachine::setRandom null Feb 07 08:30:52 music volumio[25576]: info: CoreStateMachine::pushState Feb 07 08:30:52 music volumio[25576]: info: CorePlayQueue::getTrack 0 Feb 07 08:30:52 music volumio[25576]: info: CoreCommandRouter::volumioPushState Feb 07 08:30:52 music volumio[25576]: info: Setting Device type: Raspberry PI Feb 07 08:30:52 music volumio[25576]: info: CoreCommandRouter::volumioGetState Feb 07 08:30:52 music volumio[25576]: info: CorePlayQueue::getTrack 0 Feb 07 08:30:52 music volumio[25576]: info: Listing playlists Feb 07 08:30:52 music volumio[25576]: info: Listing playlists Feb 07 08:30:52 music volumio[25576]: info: VolumeController:: Volume=86 Mute =false Feb 07 08:30:52 music volumio[25576]: info: CoreStateMachine::pushState Feb 07 08:30:52 music volumio[25576]: info: CorePlayQueue::getTrack 0 Feb 07 08:30:52 music volumio[25576]: info: CoreCommandRouter::volumioPushState Feb 07 08:30:52 music volumio[25576]: info: Completed loading Core Plugins Feb 07 08:30:52 music volumio[25576]: info: Preparing to generate the ALSA configuration file Feb 07 08:30:52 music volumio[25576]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 07 08:30:52 music volumio[25576]: info: Discovery: Found device music Feb 07 08:30:52 music volumio[25576]: info: CoreCommandRouter::volumioGetState Feb 07 08:30:52 music volumio[25576]: info: CorePlayQueue::getTrack 0 Feb 07 08:30:52 music volumio[25576]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 07 08:30:52 music volumio[25576]: info: Discovery: Found device music Feb 07 08:30:52 music volumio[25576]: info: CoreCommandRouter::volumioGetState Feb 07 08:30:52 music volumio[25576]: info: CorePlayQueue::getTrack 0 Feb 07 08:30:52 music volumio[25576]: info: Asound.conf file unchanged, so no further update is needed Feb 07 08:30:52 music volumio[25576]: info: Output device has changed, restarting MPD Feb 07 08:30:52 music volumio[25576]: info: Output device has changed, restarting Shairport Sync Feb 07 08:30:52 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:52 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 08:30:52 music volumio[25576]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 08:30:52 music sudo[25704]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 08:30:52 music sudo[25704]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:52 music volumio[25576]: info: ___________ START PLUGINS ___________ Feb 07 08:30:52 music sudo[25704]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:52 music sudo[25706]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 08:30:52 music volumio[25576]: info: ControllerMpd::onStart: Initializing MPD Feb 07 08:30:52 music volumio[25576]: info: Creating MPD Configuration file Feb 07 08:30:52 music sudo[25706]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:52 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 08:30:52 music volumio[25576]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 08:30:52 music volumio[25576]: info: [1770471052667] CoreMusicLibrary::Adding element Media Servers Feb 07 08:30:52 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 08:30:52 music sudo[25714]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 08:30:52 music sudo[25714]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:52 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 07 08:30:52 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 08:30:52 music volumio[25576]: info: UPNP Browser: Client initialized successfully Feb 07 08:30:52 music sudo[25716]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 08:30:52 music sudo[25714]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:52 music sudo[25716]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:52 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:52 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 08:30:52 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 08:30:52 music go-librespot[25717]: go-librespot daemon starting... Feb 07 08:30:52 music systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 07 08:30:52 music volumio[25576]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 08:30:52 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:52 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 08:30:52 music go-librespot[25724]: time="2026-02-07T08:30:52-05:00" level=info msg="running go-librespot 0.6.2" Feb 07 08:30:52 music go-librespot[25724]: time="2026-02-07T08:30:52-05:00" level=debug msg="app state loaded" Feb 07 08:30:52 music volumio[25576]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 08:30:52 music volumio[25576]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 08:30:52 music volumio[25576]: info: [1770471052892] CoreMusicLibrary::Adding element Last_100 Feb 07 08:30:52 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 08:30:52 music go-librespot[25724]: time="2026-02-07T08:30:52-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 08:30:52 music volumio[25576]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 08:30:52 music volumio[25576]: info: [1770471052898] CoreMusicLibrary::Adding element Webradio Feb 07 08:30:52 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 08:30:52 music systemd[1]: mpd.service: Deactivated successfully. Feb 07 08:30:52 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 08:30:52 music systemd[1]: mpd.service: Consumed 4.183s CPU time. Feb 07 08:30:52 music systemd[1]: mpd.socket: Deactivated successfully. Feb 07 08:30:52 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 08:30:52 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 08:30:52 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 08:30:52 music volumio[25576]: info: Initializing BBC Radios Feb 07 08:30:52 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 08:30:52 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 08:30:53 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 08:30:53 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 08:30:53 music volumio[25576]: info: Creating Spotify config file Feb 07 08:30:53 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:53 music sudo[25747]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 07 08:30:53 music sudo[25747]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 07 08:30:53 music sudo[25747]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:53 music go-librespot[25724]: time="2026-02-07T08:30:53-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 08:30:53 music go-librespot[25724]: time="2026-02-07T08:30:53-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 07 08:30:53 music go-librespot[25724]: time="2026-02-07T08:30:53-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 07 08:30:53 music go-librespot[25724]: time="2026-02-07T08:30:53-05:00" level=info msg="zeroconf server listening on port 42131" Feb 07 08:30:53 music go-librespot[25724]: time="2026-02-07T08:30:53-05:00" level=debug msg="obtained new client token: AABKtLWv8oTi6rjVn7cRdyjXCz7wbpc6WFDyPlaApUzuX60dFdBlR1lAH5tP0TdTQ5Pi9NhNP6KqdTY7HkUbZqYMZ58maoAkaJYfEzsWOCdbS//lVukT4RqLx02aW/HJTj8OTEbPT0BDlRn5BXsmLUKL1NmkFYjBfayQnDRSXoqjp5e//kGrX9+KnJ0ldimsu3tmkZh/vtCFgxyAF3uCDBzpLrctvbgK5RXS832ZmZKx02VgYr6/nzs=" Feb 07 08:30:53 music go-librespot[25724]: time="2026-02-07T08:30:53-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 08:30:53 music volumio[25576]: info: Volumio Calling Home Feb 07 08:30:53 music go-librespot[25724]: time="2026-02-07T08:30:53-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:53 music go-librespot[25724]: time="2026-02-07T08:30:53-05:00" level=debug msg="completed challenge" Feb 07 08:30:53 music go-librespot[25724]: time="2026-02-07T08:30:53-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:54 music volumio[25665]: Starting albumart workers Feb 07 08:30:54 music volumio[25666]: Starting albumart workers Feb 07 08:30:54 music go-librespot[25724]: time="2026-02-07T08:30:54-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 08:30:54 music volumio[25576]: info: MPD Permissions set Feb 07 08:30:54 music volumio[25576]: info: MPD Permissions set Feb 07 08:30:54 music volumio[25667]: Starting albumart workers Feb 07 08:30:54 music volumio[25576]: info: Spotify config file written Feb 07 08:30:54 music go-librespot[25724]: time="2026-02-07T08:30:54-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:54 music go-librespot[25724]: time="2026-02-07T08:30:54-05:00" level=debug msg="completed challenge" Feb 07 08:30:54 music go-librespot[25724]: time="2026-02-07T08:30:54-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:54 music volumio[25576]: 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 07 08:30:54 music volumio[25576]: info: Volumio called home Feb 07 08:30:54 music sudo[25759]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 07 08:30:54 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:54 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:54 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:54 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:54 music sudo[25759]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:54 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:54 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:54 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:54 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:54 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 07 08:30:54 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 07 08:30:54 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 08:30:54 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 08:30:54 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:54 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:54 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:54 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:54 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:54 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:54 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:54 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:54 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:54 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 08:30:54 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 08:30:54 music go-librespot[25766]: go-librespot daemon starting... Feb 07 08:30:54 music sudo[25759]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:54 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:30:54 music volumio[25576]: info: No need to fix Spotify hosts Feb 07 08:30:54 music go-librespot[25772]: time="2026-02-07T08:30:54-05:00" level=info msg="running go-librespot 0.6.2" Feb 07 08:30:54 music go-librespot[25772]: time="2026-02-07T08:30:54-05:00" level=debug msg="app state loaded" Feb 07 08:30:54 music go-librespot[25772]: time="2026-02-07T08:30:54-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 08:30:55 music go-librespot[25772]: time="2026-02-07T08:30:55-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 08:30:55 music go-librespot[25772]: time="2026-02-07T08:30:55-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 07 08:30:55 music go-librespot[25772]: time="2026-02-07T08:30:55-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 07 08:30:55 music go-librespot[25772]: time="2026-02-07T08:30:55-05:00" level=info msg="zeroconf server listening on port 40827" Feb 07 08:30:55 music volumio[25576]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 07 08:30:55 music volumio[25576]: info: Starting Shairport Sync Feb 07 08:30:55 music volumio[25576]: info: Starting Shairport Sync Feb 07 08:30:55 music volumio[25576]: info: Starting Shairport Sync Feb 07 08:30:55 music go-librespot[25772]: time="2026-02-07T08:30:55-05:00" level=debug msg="obtained new client token: AAC39LkT5amvj+gKJH7eq0o9IkmW1pAJXeSKtxcWBSz4KXhV2wGarh00DZxjDHwWBI4SDrANFCZ2u/bATZKlTY7jcRXuT55D6ZIsVbufj9KdpIzc441EorxvWHnEUyUEgGlMybdAn6PIu2vDT1J0p/sgg0BnCXau5rOYSEhCXPYMkUB7pQeyRpLmcScLjhSNuTYM2Gh4OKw4DYYACDi88SWZGZPC75qW/FqP0leR0vW7Yxtqh7QFeaw=" Feb 07 08:30:55 music sudo[25792]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 08:30:55 music sudo[25792]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:55 music sudo[25794]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 08:30:55 music sudo[25794]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:55 music sudo[25790]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 08:30:55 music sudo[25790]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:55 music go-librespot[25772]: time="2026-02-07T08:30:55-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 08:30:55 music volumio[25576]: info: CoreCommandRouter::volumioGetState Feb 07 08:30:55 music volumio[25576]: info: CorePlayQueue::getTrack 0 Feb 07 08:30:55 music go-librespot[25772]: time="2026-02-07T08:30:55-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:55 music go-librespot[25772]: time="2026-02-07T08:30:55-05:00" level=debug msg="completed challenge" Feb 07 08:30:55 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 07 08:30:55 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 07 08:30:55 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 08:30:55 music systemd[1]: shairport-sync.service: Consumed 1.904s CPU time. Feb 07 08:30:55 music go-librespot[25772]: time="2026-02-07T08:30:55-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:55 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 08:30:55 music sudo[25794]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:55 music sudo[25790]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:55 music sudo[25792]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:55 music volumio[25576]: info: Shairport-Sync Started Feb 07 08:30:55 music volumio[25576]: Error adding Membership: Error: addMembership EINVAL Feb 07 08:30:55 music volumio[25576]: info: Shairport-Sync Started Feb 07 08:30:55 music volumio[25576]: info: Shairport-Sync Started Feb 07 08:30:56 music go-librespot[25772]: time="2026-02-07T08:30:56-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 08:30:56 music go-librespot[25772]: time="2026-02-07T08:30:56-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:56 music go-librespot[25772]: time="2026-02-07T08:30:56-05:00" level=debug msg="completed challenge" Feb 07 08:30:56 music go-librespot[25772]: time="2026-02-07T08:30:56-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:57 music go-librespot[25772]: time="2026-02-07T08:30:57-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 07 08:30:57 music go-librespot[25772]: time="2026-02-07T08:30:57-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:57 music go-librespot[25772]: time="2026-02-07T08:30:57-05:00" level=debug msg="completed challenge" Feb 07 08:30:57 music go-librespot[25772]: time="2026-02-07T08:30:57-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:57 music mpd[25754]: 2026-02-07T08:30:57 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 07 08:30:57 music systemd[1]: Started mpd.service - Music Player Daemon. Feb 07 08:30:57 music sudo[25716]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:57 music sudo[25706]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:57 music volumio[25576]: info: Completed starting Core Plugins Feb 07 08:30:57 music volumio[25576]: info: ------------------------------------------- Feb 07 08:30:57 music volumio[25576]: info: ----- MyVolumio plugins startup ---- Feb 07 08:30:57 music volumio[25576]: info: ------------------------------------------- Feb 07 08:30:57 music volumio[25576]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 07 08:30:57 music volumio[25576]: error: MPD error: The expression evaluated to a falsy value: Feb 07 08:30:57 music volumio[25576]: assert.ok(self.idling) Feb 07 08:30:57 music volumio[25576]: error: The expression evaluated to a falsy value: Feb 07 08:30:57 music volumio[25576]: assert.ok(self.idling) Feb 07 08:30:57 music volumio[25576]: info: MPD running with PID25754 Feb 07 08:30:57 music volumio[25576]: ,establishing connection Feb 07 08:30:57 music volumio[25576]: error: updateQueue error: null Feb 07 08:30:57 music volumio[25576]: error: updateQueue error: null Feb 07 08:30:57 music go-librespot[25772]: time="2026-02-07T08:30:57-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 07 08:30:57 music go-librespot[25772]: time="2026-02-07T08:30:57-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:57 music go-librespot[25772]: time="2026-02-07T08:30:57-05:00" level=debug msg="completed challenge" Feb 07 08:30:57 music go-librespot[25772]: time="2026-02-07T08:30:57-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:58 music sudo[25846]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 08:30:58 music sudo[25846]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:58 music sudo[25848]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 08:30:58 music sudo[25848]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:58 music sudo[25846]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:58 music sudo[25848]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:58 music sudo[25850]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 07 08:30:58 music sudo[25850]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:30:58 music sudo[25850]: pam_unix(sudo:session): session closed for user root Feb 07 08:30:58 music volumio[25576]: info: Upmpdcli Daemon Started Feb 07 08:30:58 music volumio[25576]: info: go-librespot daemon successfully initialized Feb 07 08:30:58 music go-librespot[25772]: time="2026-02-07T08:30:58-05: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 07 08:30:58 music go-librespot[25772]: time="2026-02-07T08:30:58-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 07 08:30:58 music go-librespot[25772]: time="2026-02-07T08:30:58-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:58 music go-librespot[25772]: time="2026-02-07T08:30:58-05:00" level=debug msg="completed challenge" Feb 07 08:30:59 music go-librespot[25772]: time="2026-02-07T08:30:59-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:59 music go-librespot[25772]: time="2026-02-07T08:30:59-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 08:30:59 music go-librespot[25772]: time="2026-02-07T08:30:59-05:00" level=debug msg="completed keyexchange" Feb 07 08:30:59 music go-librespot[25772]: time="2026-02-07T08:30:59-05:00" level=debug msg="completed challenge" Feb 07 08:30:59 music go-librespot[25772]: time="2026-02-07T08:30:59-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:30:59 music go-librespot[25772]: time="2026-02-07T08:30:59-05: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 07 08:30:59 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 08:30:59 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 08:31:00 music sudo[25855]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 07 08:31:00 music sudo[25855]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:31:00 music sudo[25858]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 07 08:31:00 music sudo[25858]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:31:00 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 07 08:31:00 music systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 07 08:31:00 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 07 08:31:00 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 07 08:31:00 music sudo[25855]: pam_unix(sudo:session): session closed for user root Feb 07 08:31:00 music mpd_monitor.sh[25860]: MPD Monitor Service: Starting MPD Monitor Service Feb 07 08:31:00 music volumio[25576]: info: Successfully started MPD Monitor Feb 07 08:31:00 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 07 08:31:00 music systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 07 08:31:00 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 07 08:31:00 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 07 08:31:00 music sudo[25858]: pam_unix(sudo:session): session closed for user root Feb 07 08:31:00 music mpd_monitor.sh[25863]: MPD Monitor Service: Starting MPD Monitor Service Feb 07 08:31:00 music volumio[25576]: info: Successfully started MPD Monitor Feb 07 08:31:01 music volumio[25576]: info: Initializing connection to go-librespot Websocket Feb 07 08:31:01 music volumio[25576]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 08:31:02 music volumio[25576]: info: CoreCommandRouter::volumioGetState Feb 07 08:31:02 music volumio[25576]: info: CorePlayQueue::getTrack 0 Feb 07 08:31:02 music volumio[25576]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 07 08:31:02 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 07 08:31:02 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 08:31:02 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 08:31:02 music go-librespot[25867]: go-librespot daemon starting... Feb 07 08:31:02 music go-librespot[25868]: time="2026-02-07T08:31:02-05:00" level=info msg="running go-librespot 0.6.2" Feb 07 08:31:02 music go-librespot[25868]: time="2026-02-07T08:31:02-05:00" level=debug msg="app state loaded" Feb 07 08:31:02 music go-librespot[25868]: time="2026-02-07T08:31:02-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 08:31:03 music go-librespot[25868]: time="2026-02-07T08:31:03-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 08:31:03 music go-librespot[25868]: time="2026-02-07T08:31:03-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 07 08:31:03 music go-librespot[25868]: time="2026-02-07T08:31:03-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 07 08:31:03 music go-librespot[25868]: time="2026-02-07T08:31:03-05:00" level=info msg="zeroconf server listening on port 42777" Feb 07 08:31:03 music go-librespot[25868]: time="2026-02-07T08:31:03-05:00" level=debug msg="obtained new client token: AADHRGG4Lj2rQvXQzluFbuFvPKZ/ZY7e3IlDUW/LVapjl+sAB5UFYs4zMlqjNo6U+Q6NNro3wXh4HyLd3YQfYtCRxxBu5196px7aQXn6PYOUfiokFgmTSzyG/lGF/7qQ6wYVwhG3DOk+Sn4QBnfumet2M5/+u/+eZt9TgDkeGFThgLx+meJkp5G3gglpAJBAaigBUJrLOZLuxUPLgdfHINITGtk63w6ET5ueerY9+0ZGUdUbnuA6HaE=" Feb 07 08:31:03 music go-librespot[25868]: time="2026-02-07T08:31:03-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 08:31:03 music go-librespot[25868]: time="2026-02-07T08:31:03-05:00" level=debug msg="completed keyexchange" Feb 07 08:31:03 music go-librespot[25868]: time="2026-02-07T08:31:03-05:00" level=debug msg="completed challenge" Feb 07 08:31:03 music go-librespot[25868]: time="2026-02-07T08:31:03-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:31:04 music go-librespot[25868]: time="2026-02-07T08:31:04-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 08:31:04 music go-librespot[25868]: time="2026-02-07T08:31:04-05:00" level=debug msg="completed keyexchange" Feb 07 08:31:04 music go-librespot[25868]: time="2026-02-07T08:31:04-05:00" level=debug msg="completed challenge" Feb 07 08:31:04 music go-librespot[25868]: time="2026-02-07T08:31:04-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:31:04 music volumio[25576]: info: Initializing connection to go-librespot Websocket Feb 07 08:31:04 music go-librespot[25868]: time="2026-02-07T08:31:04-05:00" level=debug msg="new websocket client" Feb 07 08:31:04 music volumio[25576]: info: Connection to go-librespot Websocket established Feb 07 08:31:04 music go-librespot[25868]: time="2026-02-07T08:31:04-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:80, retrying with a different AP" error="dial tcp 34.158.255.62:80: connect: connection refused" Feb 07 08:31:04 music go-librespot[25868]: time="2026-02-07T08:31:04-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 07 08:31:05 music go-librespot[25868]: time="2026-02-07T08:31:05-05:00" level=debug msg="completed keyexchange" Feb 07 08:31:05 music go-librespot[25868]: time="2026-02-07T08:31:05-05:00" level=debug msg="completed challenge" Feb 07 08:31:05 music go-librespot[25868]: time="2026-02-07T08:31:05-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:31:05 music go-librespot[25868]: time="2026-02-07T08:31:05-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 08:31:05 music volumio[25576]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 07 08:31:05 music volumio[25576]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 07 08:31:05 music volumio[25576]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 07 08:31:05 music volumio[25576]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 07 08:31:05 music volumio[25576]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 07 08:31:05 music volumio[25576]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 07 08:31:05 music volumio[25576]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 07 08:31:05 music volumio[25576]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 07 08:31:05 music volumio[25576]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 07 08:31:05 music volumio[25576]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 07 08:31:05 music volumio[25576]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 07 08:31:05 music volumio[25576]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 07 08:31:05 music volumio[25576]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 07 08:31:05 music volumio[25576]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 07 08:31:05 music volumio[25576]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 07 08:31:05 music volumio[25576]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 07 08:31:05 music volumio[25576]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 07 08:31:05 music volumio[25576]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 07 08:31:05 music volumio[25576]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 07 08:31:05 music volumio[25576]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 07 08:31:05 music volumio[25576]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 07 08:31:05 music volumio[25576]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 07 08:31:05 music volumio[25576]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 07 08:31:05 music volumio[25576]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 07 08:31:05 music volumio[25576]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 07 08:31:05 music volumio[25576]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 07 08:31:05 music volumio[25576]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 07 08:31:05 music volumio[25576]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 07 08:31:05 music volumio[25576]: info: Adding plugin bluetooth to MyMusic Plugins Feb 07 08:31:05 music volumio[25576]: info: Adding plugin multiroom to MyMusic Plugins Feb 07 08:31:05 music volumio[25576]: info: Adding plugin metavolumio to MyMusic Plugins Feb 07 08:31:05 music volumio[25576]: info: Adding plugin cd_controller to MyMusic Plugins Feb 07 08:31:05 music volumio[25576]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 07 08:31:05 music volumio[25576]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 07 08:31:05 music volumio[25576]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 07 08:31:05 music volumio[25576]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 07 08:31:05 music go-librespot[25868]: time="2026-02-07T08:31:05-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.3.63:53560->104.199.65.9:443: read: connection reset by peer" Feb 07 08:31:06 music go-librespot[25868]: time="2026-02-07T08:31:06-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 07 08:31:06 music go-librespot[25868]: time="2026-02-07T08:31:06-05:00" level=debug msg="completed keyexchange" Feb 07 08:31:06 music go-librespot[25868]: time="2026-02-07T08:31:06-05:00" level=debug msg="completed challenge" Feb 07 08:31:06 music go-librespot[25868]: time="2026-02-07T08:31:06-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:31:06 music volumio[25576]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 07 08:31:06 music volumio[25576]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 07 08:31:06 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 08:31:06 music volumio[25576]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 08:31:06 music volumio[25576]: info: Starting MyVolumio Remote Streaming Endpoints Feb 07 08:31:06 music volumio[25576]: info: MyVolumio login type: Token Feb 07 08:31:06 music volumio[25576]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 07 08:31:06 music volumio[25576]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 07 08:31:07 music go-librespot[25868]: time="2026-02-07T08:31:07-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 08:31:07 music go-librespot[25868]: time="2026-02-07T08:31:07-05:00" level=debug msg="completed keyexchange" Feb 07 08:31:07 music go-librespot[25868]: time="2026-02-07T08:31:07-05:00" level=debug msg="completed challenge" Feb 07 08:31:07 music go-librespot[25868]: time="2026-02-07T08:31:07-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:31:07 music go-librespot[25868]: time="2026-02-07T08:31:07-05: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 07 08:31:07 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 08:31:07 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 08:31:07 music volumio[25576]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 07 08:31:07 music volumio[25576]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 07 08:31:07 music volumio[25576]: info: Streaming services startup Feb 07 08:31:07 music volumio[25576]: info: Starting Streaming Daemon Feb 07 08:31:07 music sudo[25878]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 07 08:31:07 music sudo[25878]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:31:07 music volumio[25576]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 07 08:31:07 music sudo[25878]: pam_unix(sudo:session): session closed for user root Feb 07 08:31:07 music volumio[25576]: info: Getting Spotify volume Feb 07 08:31:07 music volumio[25576]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 08:31:07 music volumio[25576]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 08:31:07 music volumio[25576]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 07 08:31:07 music volumio[25576]: errno: -111, Feb 07 08:31:07 music volumio[25576]: code: 'ECONNREFUSED', Feb 07 08:31:07 music volumio[25576]: syscall: 'connect', Feb 07 08:31:07 music volumio[25576]: address: '127.0.0.1', Feb 07 08:31:07 music volumio[25576]: port: 9879, Feb 07 08:31:07 music volumio[25576]: response: undefined Feb 07 08:31:07 music volumio[25576]: } Feb 07 08:31:07 music volumio[25576]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 08:31:08 music sudo[25912]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-07 08:30' Feb 07 08:31:08 music sudo[25912]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:31:08 music sudo[25912]: pam_unix(sudo:session): session closed for user root Feb 07 08:31:09 music volumio-remote-updater[31331]: [2026-02-07 08:31:08] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 07 08:31:09 music volumio-remote-updater[31331]: [2026-02-07 08:31:08] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 07 08:31:09 music systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 07 08:31:09 music systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 07 08:31:09 music systemd[1]: volumio.service: Consumed 26.430s CPU time. Feb 07 08:31:09 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 08:31:09 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 08:31:09 music systemd[1]: volumio.service: Scheduled restart job, restart counter is at 49419. Feb 07 08:31:09 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 08:31:09 music systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 07 08:31:09 music systemd[1]: volumio.service: Consumed 26.430s CPU time. Feb 07 08:31:09 music systemd[1]: Started volumio.service - Volumio Backend Module. Feb 07 08:31:09 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 08:31:10 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 07 08:31:10 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 08:31:10 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 08:31:10 music go-librespot[25939]: go-librespot daemon starting... Feb 07 08:31:10 music go-librespot[25940]: time="2026-02-07T08:31:10-05:00" level=info msg="running go-librespot 0.6.2" Feb 07 08:31:10 music go-librespot[25940]: time="2026-02-07T08:31:10-05:00" level=debug msg="app state loaded" Feb 07 08:31:10 music go-librespot[25940]: time="2026-02-07T08:31:10-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 08:31:10 music go-librespot[25940]: time="2026-02-07T08:31:10-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 08:31:10 music go-librespot[25940]: time="2026-02-07T08:31:10-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 07 08:31:10 music go-librespot[25940]: time="2026-02-07T08:31:10-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 07 08:31:10 music go-librespot[25940]: time="2026-02-07T08:31:10-05:00" level=info msg="zeroconf server listening on port 38985" Feb 07 08:31:11 music go-librespot[25940]: time="2026-02-07T08:31:11-05:00" level=debug msg="obtained new client token: AAC6hwiz+Vi19GoiXjLv4Os87UBTgjSntgYdx7/oPT7TYsUoDZ9WEh/0XRVya36Zn9ZDgI9kLwHNceKFqvWj+qfxawJrjLKCqbWStin7nRzoE/9/OnwnYJPgNUt5yFmfg281rQGTWN2t+GiHHy0ITyGa/r56LOmjCA1lcw5eoy/PYLn2U+vif+pIVh/rL/JMKGoCZ7pXq1yBVRitmY0lkQGFZ7rc5Loai+SfDWpmSg/xqjFEkKSb" Feb 07 08:31:11 music go-librespot[25940]: time="2026-02-07T08:31:11-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 08:31:11 music go-librespot[25940]: time="2026-02-07T08:31:11-05:00" level=debug msg="completed keyexchange" Feb 07 08:31:11 music go-librespot[25940]: time="2026-02-07T08:31:11-05:00" level=debug msg="completed challenge" Feb 07 08:31:11 music go-librespot[25940]: time="2026-02-07T08:31:11-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:31:11 music volumio[25924]: info: ------------------------------------------- Feb 07 08:31:11 music volumio[25924]: info: ----- Volumio3 ---- Feb 07 08:31:11 music volumio[25924]: info: ------------------------------------------- Feb 07 08:31:11 music volumio[25924]: info: ----- System startup ---- Feb 07 08:31:11 music volumio[25924]: info: ------------------------------------------- Feb 07 08:31:11 music go-librespot[25940]: time="2026-02-07T08:31:11-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 08:31:12 music go-librespot[25940]: time="2026-02-07T08:31:12-05:00" level=debug msg="completed keyexchange" Feb 07 08:31:12 music go-librespot[25940]: time="2026-02-07T08:31:12-05:00" level=debug msg="completed challenge" Feb 07 08:31:12 music go-librespot[25940]: time="2026-02-07T08:31:12-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:31:12 music volumio[25924]: info: MYVOLUMIO Environment detected Feb 07 08:31:12 music volumio[25924]: info: Plugin folders cleanup Feb 07 08:31:12 music volumio[25924]: info: Scanning into folder /volumio/app/plugins/ Feb 07 08:31:12 music volumio[25924]: info: Scanning category audio_interface Feb 07 08:31:12 music volumio[25924]: info: Scanning category miscellanea Feb 07 08:31:12 music volumio[25924]: info: Scanning category music_service Feb 07 08:31:12 music volumio[25924]: info: Scanning category plugins.json Feb 07 08:31:12 music volumio[25924]: info: Scanning category system_controller Feb 07 08:31:12 music volumio[25924]: info: Scanning category user_interface Feb 07 08:31:12 music volumio[25924]: info: Scanning into folder /data/plugins/ Feb 07 08:31:12 music volumio[25924]: info: Scanning category music_service Feb 07 08:31:12 music volumio[25924]: info: Plugin folders cleanup completed Feb 07 08:31:12 music volumio[25924]: info: ------------------------------------------- Feb 07 08:31:12 music volumio[25924]: info: ----- Core plugins startup ---- Feb 07 08:31:12 music volumio[25924]: info: ------------------------------------------- Feb 07 08:31:12 music volumio[25924]: info: Loading plugins from folder /volumio/app/plugins/ Feb 07 08:31:12 music volumio[25924]: info: Adding plugin upnp to MyMusic Plugins Feb 07 08:31:12 music volumio[25924]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 07 08:31:12 music volumio[25924]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 07 08:31:12 music volumio[25924]: info: Loading plugins from folder /data/plugins/ Feb 07 08:31:12 music volumio[25924]: info: Loading plugin "system"... Feb 07 08:31:12 music volumio[25924]: info: Loading plugin "appearance"... Feb 07 08:31:12 music go-librespot[25940]: time="2026-02-07T08:31:12-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 07 08:31:12 music go-librespot[25940]: time="2026-02-07T08:31:12-05:00" level=debug msg="completed keyexchange" Feb 07 08:31:12 music go-librespot[25940]: time="2026-02-07T08:31:12-05:00" level=debug msg="completed challenge" Feb 07 08:31:12 music go-librespot[25940]: time="2026-02-07T08:31:12-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:31:13 music go-librespot[25940]: time="2026-02-07T08:31:13-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 07 08:31:13 music volumio[25924]: info: Loading plugin "network"... Feb 07 08:31:13 music volumio[25924]: info: Refreshing Cached IP Addresses Feb 07 08:31:13 music go-librespot[25940]: time="2026-02-07T08:31:13-05:00" level=debug msg="completed keyexchange" Feb 07 08:31:13 music go-librespot[25940]: time="2026-02-07T08:31:13-05:00" level=debug msg="completed challenge" Feb 07 08:31:13 music sudo[25962]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 08:31:13 music sudo[25962]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:31:13 music sudo[25962]: pam_unix(sudo:session): session closed for user root Feb 07 08:31:13 music volumio[25924]: info: Loading plugin "services"... Feb 07 08:31:13 music go-librespot[25940]: time="2026-02-07T08:31:13-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:31:13 music sudo[25964]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 08:31:13 music sudo[25964]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:31:13 music volumio[25924]: info: Loading plugin "alsa_controller"... Feb 07 08:31:13 music sudo[25964]: pam_unix(sudo:session): session closed for user root Feb 07 08:31:13 music sudo[25972]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 07 08:31:13 music sudo[25972]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:31:13 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 08:31:13 music volumio[25924]: info: Loading plugin "wizard"... Feb 07 08:31:13 music volumio[25924]: info: Loading plugin "networkfs"... Feb 07 08:31:13 music volumio[25924]: info: Starting Udev Watcher for removable devices Feb 07 08:31:13 music volumio[25924]: info: Ignoring mount for partition: boot Feb 07 08:31:13 music volumio[25924]: info: Ignoring mount for partition: volumio Feb 07 08:31:13 music volumio[25924]: info: Ignoring mount for partition: volumio_data Feb 07 08:31:13 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 08:31:13 music volumio[25924]: info: Loading plugin "volumio_command_line_client"... Feb 07 08:31:13 music volumio[25924]: info: Loading plugin "upnp"... Feb 07 08:31:13 music volumio[25924]: info: [1770471073655] Starting Upmpd Daemon Feb 07 08:31:13 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 08:31:13 music volumio[25924]: info: Loading plugin "my_music"... Feb 07 08:31:13 music volumio[25924]: info: Loading plugin "mpd"... Feb 07 08:31:14 music volumio-remote-updater[31331]: [2026-02-07 08:31:14] [connect] Successful connection Feb 07 08:31:14 music volumio[25924]: info: Loading plugin "upnp_browser"... Feb 07 08:31:14 music sudo[25972]: pam_unix(sudo:session): session closed for user root Feb 07 08:31:14 music go-librespot[25940]: time="2026-02-07T08:31:14-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 07 08:31:14 music go-librespot[25940]: time="2026-02-07T08:31:14-05:00" level=debug msg="completed keyexchange" Feb 07 08:31:14 music go-librespot[25940]: time="2026-02-07T08:31:14-05:00" level=debug msg="completed challenge" Feb 07 08:31:14 music go-librespot[25940]: time="2026-02-07T08:31:14-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:31:15 music go-librespot[25940]: time="2026-02-07T08:31:15-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 07 08:31:15 music go-librespot[25940]: time="2026-02-07T08:31:15-05:00" level=debug msg="completed keyexchange" Feb 07 08:31:15 music go-librespot[25940]: time="2026-02-07T08:31:15-05:00" level=debug msg="completed challenge" Feb 07 08:31:15 music go-librespot[25940]: time="2026-02-07T08:31:15-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:31:15 music go-librespot[25940]: time="2026-02-07T08:31:15-05: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 07 08:31:15 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 08:31:15 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 08:31:15 music volumio[25924]: info: Starting UPNP Browser Feb 07 08:31:15 music volumio[25924]: info: Loading plugin "alarm-clock"... Feb 07 08:31:15 music volumio[25924]: info: Loading plugin "airplay_emulation"... Feb 07 08:31:15 music volumio[25924]: info: Starting Shairport Sync Feb 07 08:31:15 music volumio[25924]: info: Loading plugin "last_100"... Feb 07 08:31:15 music volumio[25924]: info: Loading plugin "webradio"... Feb 07 08:31:15 music volumio[25924]: info: Loading plugin "i2s_dacs"... Feb 07 08:31:15 music volumio[25924]: info: I2S DAC not set, start Auto-detection Feb 07 08:31:15 music volumio[25924]: info: Loading plugin "volumiodiscovery"... Feb 07 08:31:15 music volumio[25924]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 08:31:15 music volumio[25924]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 08:31:15 music volumio[25924]: *** WARNING *** For more information see Feb 07 08:31:15 music volumio[25924]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 08:31:15 music volumio[25924]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 08:31:15 music volumio[25924]: *** WARNING *** For more information see Feb 07 08:31:15 music node[25924]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 08:31:15 music node[25924]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 08:31:15 music node[25924]: *** WARNING *** For more information see Feb 07 08:31:15 music node[25924]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 08:31:15 music node[25924]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 08:31:15 music node[25924]: *** WARNING *** For more information see Feb 07 08:31:15 music volumio[25924]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 07 08:31:15 music volumio[25924]: info: Discovery: Started advertising with name: music Feb 07 08:31:15 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 08:31:15 music volumio[25924]: info: Loading plugin "spop"... Feb 07 08:31:17 music volumio[25924]: info: Loading plugin "outputs"... Feb 07 08:31:17 music volumio[25924]: info: Loading plugin "albumart"... Feb 07 08:31:17 music volumio[25924]: info: Plugin example_plugin is not enabled Feb 07 08:31:17 music volumio[25924]: info: Loading plugin "inputs"... Feb 07 08:31:17 music volumio[25924]: info: Loading plugin "updater_comm"... Feb 07 08:31:17 music volumio[25924]: info: Plugin mpdemulation is not enabled Feb 07 08:31:17 music volumio[25924]: info: Loading plugin "rest_api"... Feb 07 08:31:17 music volumio[25924]: info: Loading plugin "websocket"... Feb 07 08:31:17 music volumio[25924]: info: Starting Socket.io Server version 1.7.4 Feb 07 08:31:17 music volumio[25924]: info: Loading i18n strings for locale en Feb 07 08:31:17 music volumio[25924]: Updating browse sources language Feb 07 08:31:17 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 08:31:17 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 08:31:17 music volumio[25924]: info: CoreCommandRouter::initPlayerControls Feb 07 08:31:17 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:31:17 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:31:17 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:31:17 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:31:17 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:31:17 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:31:17 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:31:17 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:31:17 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 08:31:17 music volumio[25924]: Express server listening on port 3000 Feb 07 08:31:17 music volumio[25924]: [Metrics] WebUI: 6s 577.61ms Feb 07 08:31:17 music volumio[25924]: info: CoreStateMachine::resetVolumioState Feb 07 08:31:17 music volumio[25924]: info: CoreStateMachine::getcurrentVolume Feb 07 08:31:17 music volumio[25924]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 08:31:17 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 08:31:17 music volumio[25924]: info: Volumio Network Manager: Network status updated: 1 Feb 07 08:31:17 music volumio[25924]: info: VolumeController:: Volume=86 Mute =false Feb 07 08:31:17 music volumio[25924]: info: CoreStateMachine::pushState Feb 07 08:31:17 music volumio[25924]: info: CorePlayQueue::getTrack 0 Feb 07 08:31:17 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 08:31:17 music volumio[25924]: info: CoreCommandRouter::volumioPushState Feb 07 08:31:17 music volumio[25924]: info: CoreStateMachine::updateTrackBlock Feb 07 08:31:17 music volumio[25924]: info: CorePlayQueue::getTrackBlock Feb 07 08:31:17 music volumio[25924]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 08:31:17 music volumio[25998]: Forking 3 albumart workers Feb 07 08:31:17 music volumio[25924]: info: CoreCommandRouter::volumioGetState Feb 07 08:31:17 music volumio[25924]: info: CorePlayQueue::getTrack 0 Feb 07 08:31:17 music volumio-remote-updater[31331]: [2026-02-07 08:31:17] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770471073 101 Feb 07 08:31:17 music volumio[25924]: 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 07 08:31:17 music volumio[25924]: info: Reloading queue from file Feb 07 08:31:17 music volumio[25924]: info: CoreStateMachine::setRepeat null single undefined Feb 07 08:31:17 music volumio[25924]: info: CoreStateMachine::pushState Feb 07 08:31:17 music volumio[25924]: info: CorePlayQueue::getTrack 0 Feb 07 08:31:17 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 08:31:17 music volumio[25924]: info: CoreCommandRouter::volumioPushState Feb 07 08:31:17 music volumio[25924]: info: CoreStateMachine::setRandom null Feb 07 08:31:17 music volumio[25924]: info: CoreStateMachine::pushState Feb 07 08:31:17 music volumio[25924]: info: CorePlayQueue::getTrack 0 Feb 07 08:31:17 music volumio[25924]: info: CoreCommandRouter::volumioPushState Feb 07 08:31:17 music volumio[25924]: info: Setting Device type: Raspberry PI Feb 07 08:31:17 music volumio[25924]: info: Listing playlists Feb 07 08:31:17 music volumio[25924]: info: Listing playlists Feb 07 08:31:17 music volumio[25924]: info: VolumeController:: Volume=86 Mute =false Feb 07 08:31:17 music volumio[25924]: info: CoreStateMachine::pushState Feb 07 08:31:17 music volumio[25924]: info: CorePlayQueue::getTrack 0 Feb 07 08:31:17 music volumio[25924]: info: CoreCommandRouter::volumioPushState Feb 07 08:31:17 music volumio[25924]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 07 08:31:17 music volumio[25924]: info: Discovery: Found device music Feb 07 08:31:18 music volumio[25924]: info: CoreCommandRouter::volumioGetState Feb 07 08:31:18 music volumio[25924]: info: CorePlayQueue::getTrack 0 Feb 07 08:31:18 music volumio[25924]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 07 08:31:18 music volumio[25924]: info: Discovery: Found device music Feb 07 08:31:18 music volumio[25924]: info: CoreCommandRouter::volumioGetState Feb 07 08:31:18 music volumio[25924]: info: CorePlayQueue::getTrack 0 Feb 07 08:31:18 music volumio[25924]: info: Completed loading Core Plugins Feb 07 08:31:18 music volumio[25924]: info: Preparing to generate the ALSA configuration file Feb 07 08:31:18 music volumio[25924]: info: Asound.conf file unchanged, so no further update is needed Feb 07 08:31:18 music volumio[25924]: info: Output device has changed, restarting MPD Feb 07 08:31:18 music volumio[25924]: info: Output device has changed, restarting Shairport Sync Feb 07 08:31:18 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:31:18 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 08:31:18 music sudo[26053]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 08:31:18 music sudo[26053]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:31:18 music sudo[26055]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 08:31:18 music sudo[26055]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:31:18 music sudo[26053]: pam_unix(sudo:session): session closed for user root Feb 07 08:31:18 music volumio[25924]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 08:31:18 music volumio[25924]: info: ___________ START PLUGINS ___________ Feb 07 08:31:18 music volumio[25924]: info: ControllerMpd::onStart: Initializing MPD Feb 07 08:31:18 music volumio[25924]: info: Creating MPD Configuration file Feb 07 08:31:18 music systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 07 08:31:18 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 08:31:18 music volumio[25924]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 08:31:18 music volumio[25924]: info: [1770471078265] CoreMusicLibrary::Adding element Media Servers Feb 07 08:31:18 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 08:31:18 music systemd[1]: mpd.service: Deactivated successfully. Feb 07 08:31:18 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 08:31:18 music systemd[1]: mpd.service: Consumed 4.100s CPU time. Feb 07 08:31:18 music systemd[1]: mpd.socket: Deactivated successfully. Feb 07 08:31:18 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 08:31:18 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 08:31:18 music sudo[26065]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 08:31:18 music sudo[26064]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 08:31:18 music sudo[26064]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:31:18 music volumio[25924]: info: UPNP Browser: Client initialized successfully Feb 07 08:31:18 music sudo[26065]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:31:18 music sudo[26064]: pam_unix(sudo:session): session closed for user root Feb 07 08:31:18 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 08:31:18 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 08:31:18 music systemd[1]: mpd.service: Deactivated successfully. Feb 07 08:31:18 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 08:31:18 music systemd[1]: mpd.socket: Deactivated successfully. Feb 07 08:31:18 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 08:31:18 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 08:31:18 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 08:31:18 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:31:18 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 08:31:18 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 08:31:18 music volumio[25924]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 08:31:18 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:31:18 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 08:31:18 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 07 08:31:18 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 08:31:18 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 08:31:18 music go-librespot[26081]: go-librespot daemon starting... Feb 07 08:31:18 music volumio[25924]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 08:31:18 music volumio[25924]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 08:31:18 music volumio[25924]: info: [1770471078614] CoreMusicLibrary::Adding element Last_100 Feb 07 08:31:18 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 08:31:18 music volumio[25924]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 08:31:18 music volumio[25924]: info: [1770471078620] CoreMusicLibrary::Adding element Webradio Feb 07 08:31:18 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 08:31:18 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 08:31:18 music go-librespot[26082]: time="2026-02-07T08:31:18-05:00" level=info msg="running go-librespot 0.6.2" Feb 07 08:31:18 music go-librespot[26082]: time="2026-02-07T08:31:18-05:00" level=debug msg="app state loaded" Feb 07 08:31:18 music volumio[25924]: info: Initializing BBC Radios Feb 07 08:31:18 music go-librespot[26082]: time="2026-02-07T08:31:18-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 08:31:18 music sudo[26071]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 07 08:31:18 music sudo[26071]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 07 08:31:18 music sudo[26071]: pam_unix(sudo:session): session closed for user root Feb 07 08:31:18 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 08:31:18 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 08:31:18 music volumio[25924]: info: Creating Spotify config file Feb 07 08:31:18 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:31:19 music go-librespot[26082]: time="2026-02-07T08:31:19-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Feb 07 08:31:19 music go-librespot[26082]: time="2026-02-07T08:31:19-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 07 08:31:19 music go-librespot[26082]: time="2026-02-07T08:31:19-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 07 08:31:19 music go-librespot[26082]: time="2026-02-07T08:31:19-05:00" level=info msg="zeroconf server listening on port 41537" Feb 07 08:31:19 music go-librespot[26082]: time="2026-02-07T08:31:19-05:00" level=debug msg="obtained new client token: AADhE/jprCwpdkcbTNnGp2N9SRDeCVi/m9XkjIOBHRqE1LUdOmhXpGXOOVc2XYLVtH7eONNh73XOvYA9y9WRbDsJKky/X/Ip28vT/giw1OYiSQVezSzoSwUQLJttj2yo0i/hX/ilTJISqPDf/sDcGwlCEzVUlZmBdCEOwskYLPv9c7uxYUtEVQdYnG4FakKHQBw+0xQAJKaXdHidK2T7DxhIWtsldiddwxrlyLi0kUKBiVVOwGmUCzo=" Feb 07 08:31:19 music go-librespot[26082]: time="2026-02-07T08:31:19-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 08:31:19 music go-librespot[26082]: time="2026-02-07T08:31:19-05:00" level=debug msg="completed keyexchange" Feb 07 08:31:19 music go-librespot[26082]: time="2026-02-07T08:31:19-05:00" level=debug msg="completed challenge" Feb 07 08:31:19 music volumio[25924]: info: Volumio Calling Home Feb 07 08:31:19 music go-librespot[26082]: time="2026-02-07T08:31:19-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:31:19 music volumio[26015]: Starting albumart workers Feb 07 08:31:19 music volumio[26016]: Starting albumart workers Feb 07 08:31:20 music volumio[26017]: Starting albumart workers Feb 07 08:31:20 music volumio[25924]: info: MPD Permissions set Feb 07 08:31:20 music volumio[25924]: info: MPD Permissions set Feb 07 08:31:20 music go-librespot[26082]: time="2026-02-07T08:31:20-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 08:31:20 music volumio[25924]: info: Volumio called home Feb 07 08:31:20 music volumio[25924]: info: Spotify config file written Feb 07 08:31:20 music volumio[25924]: 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 07 08:31:20 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:31:20 music go-librespot[26082]: time="2026-02-07T08:31:20-05:00" level=debug msg="completed keyexchange" Feb 07 08:31:20 music go-librespot[26082]: time="2026-02-07T08:31:20-05:00" level=debug msg="completed challenge" Feb 07 08:31:20 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:31:20 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:31:20 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:31:20 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:31:20 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:31:20 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:31:20 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:31:20 music sudo[26111]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 07 08:31:20 music sudo[26111]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:31:20 music go-librespot[26082]: time="2026-02-07T08:31:20-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:31:20 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 07 08:31:20 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 07 08:31:20 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 08:31:20 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 08:31:20 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:31:20 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:31:20 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:31:20 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:31:20 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:31:20 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:31:20 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:31:20 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:31:20 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:31:20 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 08:31:20 music go-librespot[26118]: go-librespot daemon starting... Feb 07 08:31:20 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 08:31:20 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 08:31:20 music sudo[26111]: pam_unix(sudo:session): session closed for user root Feb 07 08:31:20 music volumio[25924]: info: No need to fix Spotify hosts Feb 07 08:31:20 music go-librespot[26124]: time="2026-02-07T08:31:20-05:00" level=info msg="running go-librespot 0.6.2" Feb 07 08:31:20 music go-librespot[26124]: time="2026-02-07T08:31:20-05:00" level=debug msg="app state loaded" Feb 07 08:31:20 music go-librespot[26124]: time="2026-02-07T08:31:20-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 08:31:20 music go-librespot[26124]: time="2026-02-07T08:31:20-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 08:31:20 music go-librespot[26124]: time="2026-02-07T08:31:20-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 07 08:31:20 music go-librespot[26124]: time="2026-02-07T08:31:20-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 07 08:31:20 music go-librespot[26124]: time="2026-02-07T08:31:20-05:00" level=info msg="zeroconf server listening on port 34459" Feb 07 08:31:20 music volumio[25924]: info: Starting Shairport Sync Feb 07 08:31:20 music volumio[25924]: info: Starting Shairport Sync Feb 07 08:31:21 music volumio[25924]: info: Starting Shairport Sync Feb 07 08:31:21 music sudo[26144]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 08:31:21 music sudo[26144]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:31:21 music sudo[26150]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 08:31:21 music sudo[26150]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:31:21 music volumio[25924]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 07 08:31:21 music go-librespot[26124]: time="2026-02-07T08:31:21-05:00" level=debug msg="obtained new client token: AAAW+d0IxJvhT0UZHX+zBkRPMaglaElSCzoY2tYjyxvYN/ow7i8c5zt8zzx2XpzV5UgWVZM+PNG/T/IEtSW8XEy7W3AUmd+vNCMdTh3CQzOCUM2J/JxlF4EcDHPq4JytovVDFtH8JOglcxZD3eiAklhj6rVcR89eOAMIDa0iq42/10+zZfwS32x2A2k4afpKJHxMrFIHN0WbPBUpEjvuZmAsBMvv6rrlJnFZ6DUhB1HSfTtjjoAY" Feb 07 08:31:21 music sudo[26153]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 08:31:21 music sudo[26153]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:31:21 music go-librespot[26124]: time="2026-02-07T08:31:21-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.255.62:4070: connect: connection refused" Feb 07 08:31:21 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 07 08:31:21 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 07 08:31:21 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 08:31:21 music systemd[1]: shairport-sync.service: Consumed 1.887s CPU time. Feb 07 08:31:21 music go-librespot[26124]: time="2026-02-07T08:31:21-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 08:31:21 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 08:31:21 music go-librespot[26124]: time="2026-02-07T08:31:21-05:00" level=debug msg="completed keyexchange" Feb 07 08:31:21 music go-librespot[26124]: time="2026-02-07T08:31:21-05:00" level=debug msg="completed challenge" Feb 07 08:31:21 music sudo[26144]: pam_unix(sudo:session): session closed for user root Feb 07 08:31:21 music sudo[26153]: pam_unix(sudo:session): session closed for user root Feb 07 08:31:21 music sudo[26150]: pam_unix(sudo:session): session closed for user root Feb 07 08:31:21 music volumio[25924]: info: Shairport-Sync Started Feb 07 08:31:21 music volumio[25924]: Error adding Membership: Error: addMembership EINVAL Feb 07 08:31:21 music volumio[25924]: info: Shairport-Sync Started Feb 07 08:31:21 music volumio[25924]: info: Shairport-Sync Started Feb 07 08:31:21 music go-librespot[26124]: time="2026-02-07T08:31:21-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:31:21 music volumio[25924]: info: CoreCommandRouter::volumioGetState Feb 07 08:31:21 music volumio[25924]: info: CorePlayQueue::getTrack 0 Feb 07 08:31:21 music go-librespot[26124]: time="2026-02-07T08:31:21-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 07 08:31:22 music go-librespot[26124]: time="2026-02-07T08:31:22-05:00" level=debug msg="completed keyexchange" Feb 07 08:31:22 music go-librespot[26124]: time="2026-02-07T08:31:22-05:00" level=debug msg="completed challenge" Feb 07 08:31:22 music go-librespot[26124]: time="2026-02-07T08:31:22-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:31:22 music volumio[25924]: info: CoreCommandRouter::volumioGetState Feb 07 08:31:22 music volumio[25924]: info: CorePlayQueue::getTrack 0 Feb 07 08:31:22 music go-librespot[26124]: time="2026-02-07T08:31:22-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 07 08:31:22 music go-librespot[26124]: time="2026-02-07T08:31:22-05:00" level=debug msg="completed keyexchange" Feb 07 08:31:22 music go-librespot[26124]: time="2026-02-07T08:31:22-05:00" level=debug msg="completed challenge" Feb 07 08:31:22 music go-librespot[26124]: time="2026-02-07T08:31:22-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:31:22 music mpd[26100]: 2026-02-07T08:31:22 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 07 08:31:22 music systemd[1]: Started mpd.service - Music Player Daemon. Feb 07 08:31:22 music sudo[26065]: pam_unix(sudo:session): session closed for user root Feb 07 08:31:22 music sudo[26055]: pam_unix(sudo:session): session closed for user root Feb 07 08:31:22 music volumio[25924]: info: Completed starting Core Plugins Feb 07 08:31:22 music volumio[25924]: info: ------------------------------------------- Feb 07 08:31:22 music volumio[25924]: info: ----- MyVolumio plugins startup ---- Feb 07 08:31:22 music volumio[25924]: info: ------------------------------------------- Feb 07 08:31:22 music volumio[25924]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 07 08:31:22 music volumio[25924]: error: MPD error: The expression evaluated to a falsy value: Feb 07 08:31:22 music volumio[25924]: assert.ok(self.idling) Feb 07 08:31:22 music volumio[25924]: error: The expression evaluated to a falsy value: Feb 07 08:31:22 music volumio[25924]: assert.ok(self.idling) Feb 07 08:31:22 music volumio[25924]: error: updateQueue error: null Feb 07 08:31:22 music volumio[25924]: info: MPD running with PID26100 Feb 07 08:31:22 music volumio[25924]: ,establishing connection Feb 07 08:31:22 music volumio[25924]: error: updateQueue error: null Feb 07 08:31:23 music go-librespot[26124]: time="2026-02-07T08:31:23-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 07 08:31:23 music go-librespot[26124]: time="2026-02-07T08:31:23-05:00" level=debug msg="completed keyexchange" Feb 07 08:31:23 music go-librespot[26124]: time="2026-02-07T08:31:23-05:00" level=debug msg="completed challenge" Feb 07 08:31:23 music sudo[26198]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 08:31:23 music sudo[26198]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:31:23 music sudo[26200]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 08:31:23 music sudo[26200]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:31:23 music sudo[26198]: pam_unix(sudo:session): session closed for user root Feb 07 08:31:23 music sudo[26200]: pam_unix(sudo:session): session closed for user root Feb 07 08:31:23 music sudo[26202]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 07 08:31:23 music sudo[26202]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:31:23 music sudo[26202]: pam_unix(sudo:session): session closed for user root Feb 07 08:31:23 music volumio[25924]: info: Upmpdcli Daemon Started Feb 07 08:31:23 music go-librespot[26124]: time="2026-02-07T08:31:23-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:31:23 music volumio[25924]: info: go-librespot daemon successfully initialized Feb 07 08:31:24 music go-librespot[26124]: time="2026-02-07T08:31:24-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 07 08:31:24 music go-librespot[26124]: time="2026-02-07T08:31:24-05:00" level=debug msg="completed keyexchange" Feb 07 08:31:24 music go-librespot[26124]: time="2026-02-07T08:31:24-05:00" level=debug msg="completed challenge" Feb 07 08:31:24 music go-librespot[26124]: time="2026-02-07T08:31:24-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:31:25 music go-librespot[26124]: time="2026-02-07T08:31:25-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.255.62:4070: connect: connection refused" Feb 07 08:31:25 music go-librespot[26124]: time="2026-02-07T08:31:25-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 08:31:25 music go-librespot[26124]: time="2026-02-07T08:31:25-05:00" level=debug msg="completed keyexchange" Feb 07 08:31:25 music go-librespot[26124]: time="2026-02-07T08:31:25-05:00" level=debug msg="completed challenge" Feb 07 08:31:25 music go-librespot[26124]: time="2026-02-07T08:31:25-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:31:25 music go-librespot[26124]: time="2026-02-07T08:31:25-05: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 07 08:31:25 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 08:31:25 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 08:31:25 music sudo[26207]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 07 08:31:25 music sudo[26207]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:31:25 music sudo[26209]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 07 08:31:25 music sudo[26209]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:31:25 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 07 08:31:25 music systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 07 08:31:25 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 07 08:31:26 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 07 08:31:26 music sudo[26209]: pam_unix(sudo:session): session closed for user root Feb 07 08:31:26 music sudo[26207]: pam_unix(sudo:session): session closed for user root Feb 07 08:31:26 music mpd_monitor.sh[26212]: MPD Monitor Service: Starting MPD Monitor Service Feb 07 08:31:26 music volumio[25924]: info: Successfully started MPD Monitor Feb 07 08:31:26 music volumio[25924]: info: Successfully started MPD Monitor Feb 07 08:31:26 music volumio[25924]: info: Initializing connection to go-librespot Websocket Feb 07 08:31:26 music volumio[25924]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 08:31:27 music volumio[25924]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 07 08:31:28 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 07 08:31:28 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 08:31:28 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 08:31:28 music go-librespot[26216]: go-librespot daemon starting... Feb 07 08:31:28 music go-librespot[26217]: time="2026-02-07T08:31:28-05:00" level=info msg="running go-librespot 0.6.2" Feb 07 08:31:28 music go-librespot[26217]: time="2026-02-07T08:31:28-05:00" level=debug msg="app state loaded" Feb 07 08:31:28 music go-librespot[26217]: time="2026-02-07T08:31:28-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 08:31:28 music go-librespot[26217]: time="2026-02-07T08:31:28-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 08:31:28 music go-librespot[26217]: time="2026-02-07T08:31:28-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 07 08:31:28 music go-librespot[26217]: time="2026-02-07T08:31:28-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 07 08:31:28 music go-librespot[26217]: time="2026-02-07T08:31:28-05:00" level=info msg="zeroconf server listening on port 36621" Feb 07 08:31:29 music go-librespot[26217]: time="2026-02-07T08:31:29-05:00" level=debug msg="obtained new client token: AAAmS40TVYBleRQuYW6GxJfLEIimX23o1NE7TALPEajntfjZaBqAsxQglJL6dVXZgM8GVtCeidZQJc0Y2+t4LDkhlOl4gLawOHLsQJ3KFuU4aUDYmglODlbXS+P8YeD9cgB3c6HNNDRCBbH3CMvBllgzOAc91FBgs18r5PsJvd4BCLt2ToC5eYOCN4jkUegrPjBSmI7ALowGCqnY+Hlb0+x7e1FsvKgIvBArhHKHF/6y47/57L6U" Feb 07 08:31:29 music go-librespot[26217]: time="2026-02-07T08:31:29-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 08:31:29 music go-librespot[26217]: time="2026-02-07T08:31:29-05:00" level=debug msg="completed keyexchange" Feb 07 08:31:29 music go-librespot[26217]: time="2026-02-07T08:31:29-05:00" level=debug msg="completed challenge" Feb 07 08:31:29 music go-librespot[26217]: time="2026-02-07T08:31:29-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:31:29 music go-librespot[26217]: time="2026-02-07T08:31:29-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.255.62:443: connect: connection refused" Feb 07 08:31:29 music go-librespot[26217]: time="2026-02-07T08:31:29-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 07 08:31:29 music volumio[25924]: info: Initializing connection to go-librespot Websocket Feb 07 08:31:29 music go-librespot[26217]: time="2026-02-07T08:31:29-05:00" level=debug msg="new websocket client" Feb 07 08:31:29 music volumio[25924]: info: Connection to go-librespot Websocket established Feb 07 08:31:29 music go-librespot[26217]: time="2026-02-07T08:31:29-05:00" level=debug msg="completed keyexchange" Feb 07 08:31:29 music go-librespot[26217]: time="2026-02-07T08:31:29-05:00" level=debug msg="completed challenge" Feb 07 08:31:30 music go-librespot[26217]: time="2026-02-07T08:31:30-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:31:30 music go-librespot[26217]: time="2026-02-07T08:31:30-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 07 08:31:30 music go-librespot[26217]: time="2026-02-07T08:31:30-05:00" level=debug msg="completed keyexchange" Feb 07 08:31:30 music go-librespot[26217]: time="2026-02-07T08:31:30-05:00" level=debug msg="completed challenge" Feb 07 08:31:30 music go-librespot[26217]: time="2026-02-07T08:31:30-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:31:31 music volumio[25924]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 07 08:31:31 music volumio[25924]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 07 08:31:31 music volumio[25924]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 07 08:31:31 music volumio[25924]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 07 08:31:31 music volumio[25924]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 07 08:31:31 music volumio[25924]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 07 08:31:31 music volumio[25924]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 07 08:31:31 music volumio[25924]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 07 08:31:31 music volumio[25924]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 07 08:31:31 music volumio[25924]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 07 08:31:31 music volumio[25924]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 07 08:31:31 music volumio[25924]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 07 08:31:31 music volumio[25924]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 07 08:31:31 music volumio[25924]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 07 08:31:31 music volumio[25924]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 07 08:31:31 music volumio[25924]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 07 08:31:31 music volumio[25924]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 07 08:31:31 music volumio[25924]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 07 08:31:31 music volumio[25924]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 07 08:31:31 music volumio[25924]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 07 08:31:31 music volumio[25924]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 07 08:31:31 music volumio[25924]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 07 08:31:31 music volumio[25924]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 07 08:31:31 music volumio[25924]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 07 08:31:31 music volumio[25924]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 07 08:31:31 music volumio[25924]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 07 08:31:31 music volumio[25924]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 07 08:31:31 music volumio[25924]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 07 08:31:31 music volumio[25924]: info: Adding plugin bluetooth to MyMusic Plugins Feb 07 08:31:31 music volumio[25924]: info: Adding plugin multiroom to MyMusic Plugins Feb 07 08:31:31 music volumio[25924]: info: Adding plugin metavolumio to MyMusic Plugins Feb 07 08:31:31 music volumio[25924]: info: Adding plugin cd_controller to MyMusic Plugins Feb 07 08:31:31 music volumio[25924]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 07 08:31:31 music volumio[25924]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 07 08:31:31 music volumio[25924]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 07 08:31:31 music volumio[25924]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 07 08:31:31 music go-librespot[26217]: time="2026-02-07T08:31:31-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 08:31:31 music go-librespot[26217]: time="2026-02-07T08:31:31-05:00" level=debug msg="completed keyexchange" Feb 07 08:31:31 music go-librespot[26217]: time="2026-02-07T08:31:31-05:00" level=debug msg="completed challenge" Feb 07 08:31:31 music go-librespot[26217]: time="2026-02-07T08:31:31-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:31:32 music volumio[25924]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 07 08:31:32 music volumio[25924]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 07 08:31:32 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 08:31:32 music volumio[25924]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 08:31:32 music volumio[25924]: info: Starting MyVolumio Remote Streaming Endpoints Feb 07 08:31:32 music volumio[25924]: info: MyVolumio login type: Token Feb 07 08:31:32 music volumio[25924]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 07 08:31:32 music volumio[25924]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 07 08:31:32 music go-librespot[26217]: time="2026-02-07T08:31:32-05:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:80, retrying with a different AP" error="dial tcp 34.158.1.133:80: connect: connection refused" Feb 07 08:31:32 music go-librespot[26217]: time="2026-02-07T08:31:32-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 08:31:32 music go-librespot[26217]: time="2026-02-07T08:31:32-05:00" level=debug msg="completed keyexchange" Feb 07 08:31:32 music go-librespot[26217]: time="2026-02-07T08:31:32-05:00" level=debug msg="completed challenge" Feb 07 08:31:32 music go-librespot[26217]: time="2026-02-07T08:31:32-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:31:33 music go-librespot[26217]: time="2026-02-07T08:31:33-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 08:31:33 music volumio[25924]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 07 08:31:33 music volumio[25924]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 07 08:31:33 music volumio[25924]: info: Streaming services startup Feb 07 08:31:33 music volumio[25924]: info: Starting Streaming Daemon Feb 07 08:31:33 music sudo[26227]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 07 08:31:33 music sudo[26227]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 08:31:33 music volumio[25924]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 07 08:31:33 music go-librespot[26217]: time="2026-02-07T08:31:33-05:00" level=debug msg="completed keyexchange" Feb 07 08:31:33 music go-librespot[26217]: time="2026-02-07T08:31:33-05:00" level=debug msg="completed challenge" Feb 07 08:31:33 music sudo[26227]: pam_unix(sudo:session): session closed for user root Feb 07 08:31:33 music volumio[25924]: info: Getting Spotify volume Feb 07 08:31:33 music go-librespot[26217]: time="2026-02-07T08:31:33-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 08:31:33 music go-librespot[26217]: time="2026-02-07T08:31:33-05: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 07 08:31:33 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 08:31:33 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 08:31:33 music volumio[25924]: error: Cannot start Volumio Streaming Daemon Feb 07 08:31:33 music volumio[25924]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 07 08:31:33 music volumio[25924]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 07 08:31:33 music volumio[25924]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 08:31:33 music volumio[25924]: Error: socket hang up Feb 07 08:31:33 music volumio[25924]: at connResetException (node:internal/errors:720:14) Feb 07 08:31:33 music volumio[25924]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 07 08:31:33 music volumio[25924]: at Socket.emit (node:events:526:35) Feb 07 08:31:33 music volumio[25924]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 07 08:31:33 music volumio[25924]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 07 08:31:33 music volumio[25924]: code: 'ECONNRESET', Feb 07 08:31:33 music volumio[25924]: response: undefined Feb 07 08:31:33 music volumio[25924]: } Feb 07 08:31:33 music volumio[25924]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 08:31:34 music sudo[26261]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-07 08:30' Feb 07 08:31:34 music sudo[26261]: 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="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"