Feb 07 17:22:00 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 07 17:22:00 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 17:22:00 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 17:22:00 music go-librespot[19356]: go-librespot daemon starting... Feb 07 17:22:00 music go-librespot[19357]: time="2026-02-07T17:22:00-05:00" level=info msg="running go-librespot 0.6.2" Feb 07 17:22:00 music go-librespot[19357]: time="2026-02-07T17:22:00-05:00" level=debug msg="app state loaded" Feb 07 17:22:00 music go-librespot[19357]: time="2026-02-07T17:22:00-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 17:22:00 music go-librespot[19357]: time="2026-02-07T17:22:00-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 17:22:00 music go-librespot[19357]: time="2026-02-07T17:22:00-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 17:22:00 music go-librespot[19357]: time="2026-02-07T17:22:00-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 17:22:00 music go-librespot[19357]: time="2026-02-07T17:22:00-05:00" level=info msg="zeroconf server listening on port 41421" Feb 07 17:22:01 music go-librespot[19357]: time="2026-02-07T17:22:01-05:00" level=debug msg="obtained new client token: AAA6FL+V45JYssF2kVoe73B2VH3fiyFfbKta60rN7NbH5wBgggyrgAelv3BH8tK929MypULyYjvQOC9hz4kZBPIowlJcEBtbmJNux0BCx0W7FoFFvEN3r9OkBNLtw+e5jUNiQf9CZulbCj2F94wrs8BM+RnU3+NGJ+1uZB+mlkmWzqPYS4N4oCBVAWMrV5lvjhbnlilB+b6JvZmZtagetBhLZeM2CogBFLniGJlKy8rt2qGqEdLD" Feb 07 17:22:01 music go-librespot[19357]: time="2026-02-07T17:22:01-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 17:22:01 music go-librespot[19357]: time="2026-02-07T17:22:01-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:01 music go-librespot[19357]: time="2026-02-07T17:22:01-05:00" level=debug msg="completed challenge" Feb 07 17:22:01 music volumio[19340]: info: ------------------------------------------- Feb 07 17:22:01 music volumio[19340]: info: ----- Volumio3 ---- Feb 07 17:22:01 music volumio[19340]: info: ------------------------------------------- Feb 07 17:22:01 music volumio[19340]: info: ----- System startup ---- Feb 07 17:22:01 music volumio[19340]: info: ------------------------------------------- Feb 07 17:22:01 music go-librespot[19357]: time="2026-02-07T17:22:01-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:02 music go-librespot[19357]: time="2026-02-07T17:22:02-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 17:22:02 music volumio[19340]: info: MYVOLUMIO Environment detected Feb 07 17:22:02 music go-librespot[19357]: time="2026-02-07T17:22:02-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:02 music go-librespot[19357]: time="2026-02-07T17:22:02-05:00" level=debug msg="completed challenge" Feb 07 17:22:02 music volumio[19340]: info: Plugin folders cleanup Feb 07 17:22:02 music volumio[19340]: info: Scanning into folder /volumio/app/plugins/ Feb 07 17:22:02 music volumio[19340]: info: Scanning category audio_interface Feb 07 17:22:02 music volumio[19340]: info: Scanning category miscellanea Feb 07 17:22:02 music volumio[19340]: info: Scanning category music_service Feb 07 17:22:02 music volumio[19340]: info: Scanning category plugins.json Feb 07 17:22:02 music volumio[19340]: info: Scanning category system_controller Feb 07 17:22:02 music volumio[19340]: info: Scanning category user_interface Feb 07 17:22:02 music volumio[19340]: info: Scanning into folder /data/plugins/ Feb 07 17:22:02 music volumio[19340]: info: Scanning category music_service Feb 07 17:22:02 music volumio[19340]: info: Plugin folders cleanup completed Feb 07 17:22:02 music volumio[19340]: info: ------------------------------------------- Feb 07 17:22:02 music volumio[19340]: info: ----- Core plugins startup ---- Feb 07 17:22:02 music volumio[19340]: info: ------------------------------------------- Feb 07 17:22:02 music go-librespot[19357]: time="2026-02-07T17:22:02-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:02 music volumio[19340]: info: Loading plugins from folder /volumio/app/plugins/ Feb 07 17:22:02 music volumio[19340]: info: Adding plugin upnp to MyMusic Plugins Feb 07 17:22:02 music volumio[19340]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 07 17:22:02 music volumio[19340]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 07 17:22:02 music volumio[19340]: info: Loading plugins from folder /data/plugins/ Feb 07 17:22:02 music volumio[19340]: info: Loading plugin "system"... Feb 07 17:22:02 music volumio[19340]: info: Loading plugin "appearance"... Feb 07 17:22:02 music go-librespot[19357]: time="2026-02-07T17:22:02-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 07 17:22:02 music go-librespot[19357]: time="2026-02-07T17:22:02-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:02 music go-librespot[19357]: time="2026-02-07T17:22:02-05:00" level=debug msg="completed challenge" Feb 07 17:22:02 music go-librespot[19357]: time="2026-02-07T17:22:02-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:03 music volumio[19340]: info: Loading plugin "network"... Feb 07 17:22:03 music volumio[19340]: info: Refreshing Cached IP Addresses Feb 07 17:22:03 music sudo[19379]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 17:22:03 music sudo[19379]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:03 music sudo[19379]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:03 music sudo[19381]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 17:22:03 music sudo[19381]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:03 music volumio[19340]: info: Loading plugin "services"... Feb 07 17:22:03 music volumio[19340]: info: Loading plugin "alsa_controller"... Feb 07 17:22:03 music sudo[19381]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:03 music sudo[19389]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 07 17:22:03 music sudo[19389]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:03 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 17:22:03 music volumio[19340]: info: Loading plugin "wizard"... Feb 07 17:22:03 music volumio[19340]: info: Loading plugin "networkfs"... Feb 07 17:22:03 music volumio[19340]: info: Starting Udev Watcher for removable devices Feb 07 17:22:03 music volumio[19340]: info: Ignoring mount for partition: boot Feb 07 17:22:03 music volumio[19340]: info: Ignoring mount for partition: volumio Feb 07 17:22:03 music volumio[19340]: info: Ignoring mount for partition: volumio_data Feb 07 17:22:03 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 17:22:03 music volumio[19340]: info: Loading plugin "volumio_command_line_client"... Feb 07 17:22:03 music volumio[19340]: info: Loading plugin "upnp"... Feb 07 17:22:03 music volumio[19340]: info: [1770502923660] Starting Upmpd Daemon Feb 07 17:22:03 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 17:22:03 music volumio[19340]: info: Loading plugin "my_music"... Feb 07 17:22:03 music volumio[19340]: info: Loading plugin "mpd"... Feb 07 17:22:03 music go-librespot[19357]: time="2026-02-07T17:22:03-05:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 17:22:03 music go-librespot[19357]: time="2026-02-07T17:22:03-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:03 music go-librespot[19357]: time="2026-02-07T17:22:03-05:00" level=debug msg="completed challenge" Feb 07 17:22:04 music volumio[19340]: info: Loading plugin "upnp_browser"... Feb 07 17:22:04 music volumio-remote-updater[31331]: [2026-02-07 17:22:04] [connect] Successful connection Feb 07 17:22:04 music sudo[19389]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:04 music go-librespot[19357]: time="2026-02-07T17:22:04-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:04 music go-librespot[19357]: time="2026-02-07T17:22:04-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 17:22:04 music go-librespot[19357]: time="2026-02-07T17:22:04-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:04 music go-librespot[19357]: time="2026-02-07T17:22:04-05:00" level=debug msg="completed challenge" Feb 07 17:22:05 music go-librespot[19357]: time="2026-02-07T17:22:05-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:05 music volumio[19340]: info: Starting UPNP Browser Feb 07 17:22:05 music volumio[19340]: info: Loading plugin "alarm-clock"... Feb 07 17:22:05 music go-librespot[19357]: time="2026-02-07T17:22:05-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 07 17:22:05 music volumio[19340]: info: Loading plugin "airplay_emulation"... Feb 07 17:22:05 music go-librespot[19357]: time="2026-02-07T17:22:05-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:05 music go-librespot[19357]: time="2026-02-07T17:22:05-05:00" level=debug msg="completed challenge" Feb 07 17:22:05 music volumio[19340]: info: Starting Shairport Sync Feb 07 17:22:05 music volumio[19340]: info: Loading plugin "last_100"... Feb 07 17:22:05 music volumio[19340]: info: Loading plugin "webradio"... Feb 07 17:22:05 music volumio[19340]: info: Loading plugin "i2s_dacs"... Feb 07 17:22:05 music go-librespot[19357]: time="2026-02-07T17:22:05-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:05 music go-librespot[19357]: time="2026-02-07T17:22:05-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 17:22:05 music volumio[19340]: info: I2S DAC not set, start Auto-detection Feb 07 17:22:05 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 17:22:05 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 17:22:05 music volumio[19340]: info: Loading plugin "volumiodiscovery"... Feb 07 17:22:05 music volumio[19340]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 17:22:05 music volumio[19340]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 17:22:05 music volumio[19340]: *** WARNING *** For more information see Feb 07 17:22:05 music volumio[19340]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 17:22:05 music volumio[19340]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 17:22:05 music volumio[19340]: *** WARNING *** For more information see Feb 07 17:22:05 music node[19340]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 17:22:05 music node[19340]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 17:22:05 music node[19340]: *** WARNING *** For more information see Feb 07 17:22:05 music node[19340]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 17:22:05 music node[19340]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 17:22:05 music systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Feb 07 17:22:05 music node[19340]: *** WARNING *** For more information see Feb 07 17:22:05 music volumio[19340]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 07 17:22:05 music volumio[19340]: info: Discovery: Started advertising with name: music Feb 07 17:22:06 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 17:22:06 music volumio[19340]: info: Loading plugin "spop"... Feb 07 17:22:07 music volumio[19340]: info: Loading plugin "outputs"... Feb 07 17:22:07 music volumio[19340]: info: Loading plugin "albumart"... Feb 07 17:22:07 music volumio[19340]: info: Plugin example_plugin is not enabled Feb 07 17:22:07 music volumio[19340]: info: Loading plugin "inputs"... Feb 07 17:22:07 music volumio[19340]: info: Loading plugin "updater_comm"... Feb 07 17:22:07 music systemd[1]: setdatetime-helper.service: Deactivated successfully. Feb 07 17:22:07 music systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Feb 07 17:22:07 music systemd[1]: setdatetime-helper.service: Consumed 1.110s CPU time. Feb 07 17:22:07 music volumio[19340]: info: Plugin mpdemulation is not enabled Feb 07 17:22:07 music volumio[19340]: info: Loading plugin "rest_api"... Feb 07 17:22:07 music volumio[19340]: info: Loading plugin "websocket"... Feb 07 17:22:07 music volumio[19340]: info: Starting Socket.io Server version 1.7.4 Feb 07 17:22:07 music volumio[19340]: info: Loading i18n strings for locale en Feb 07 17:22:07 music volumio[19340]: Updating browse sources language Feb 07 17:22:07 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 17:22:07 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 17:22:07 music volumio[19340]: info: CoreCommandRouter::initPlayerControls Feb 07 17:22:07 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:07 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:07 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:07 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:07 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:07 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:07 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:07 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:07 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 17:22:07 music volumio[19340]: Express server listening on port 3000 Feb 07 17:22:07 music volumio[19340]: [Metrics] WebUI: 6s 843.15ms Feb 07 17:22:07 music volumio[19340]: info: CoreStateMachine::resetVolumioState Feb 07 17:22:07 music volumio[19340]: info: CoreStateMachine::getcurrentVolume Feb 07 17:22:07 music volumio[19340]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 17:22:07 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 17:22:07 music volumio[19340]: info: Volumio Network Manager: Network status updated: 1 Feb 07 17:22:07 music volumio-remote-updater[31331]: [2026-02-07 17:22:07] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770502924 101 Feb 07 17:22:07 music volumio[19435]: Forking 3 albumart workers Feb 07 17:22:07 music volumio[19340]: 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 17:22:07 music volumio[19340]: info: VolumeController:: Volume=86 Mute =false Feb 07 17:22:07 music volumio[19340]: info: CoreStateMachine::pushState Feb 07 17:22:07 music volumio[19340]: info: CorePlayQueue::getTrack 0 Feb 07 17:22:07 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 17:22:07 music volumio[19340]: info: CoreCommandRouter::volumioPushState Feb 07 17:22:07 music volumio[19340]: info: CoreStateMachine::updateTrackBlock Feb 07 17:22:07 music volumio[19340]: info: CorePlayQueue::getTrackBlock Feb 07 17:22:07 music volumio[19340]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 17:22:08 music volumio[19340]: info: Reloading queue from file Feb 07 17:22:08 music volumio[19340]: info: CoreCommandRouter::volumioGetState Feb 07 17:22:08 music volumio[19340]: info: CorePlayQueue::getTrack 0 Feb 07 17:22:08 music volumio[19340]: info: CoreStateMachine::setRepeat null single undefined Feb 07 17:22:08 music volumio[19340]: info: CoreStateMachine::pushState Feb 07 17:22:08 music volumio[19340]: info: CorePlayQueue::getTrack 0 Feb 07 17:22:08 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 17:22:08 music volumio[19340]: info: CoreCommandRouter::volumioPushState Feb 07 17:22:08 music volumio[19340]: info: CoreStateMachine::setRandom null Feb 07 17:22:08 music volumio[19340]: info: CoreStateMachine::pushState Feb 07 17:22:08 music volumio[19340]: info: CorePlayQueue::getTrack 0 Feb 07 17:22:08 music volumio[19340]: info: CoreCommandRouter::volumioPushState Feb 07 17:22:08 music volumio[19340]: info: Setting Device type: Raspberry PI Feb 07 17:22:08 music volumio[19340]: info: Listing playlists Feb 07 17:22:08 music volumio[19340]: info: Listing playlists Feb 07 17:22:08 music volumio[19340]: info: VolumeController:: Volume=86 Mute =false Feb 07 17:22:08 music volumio[19340]: info: CoreStateMachine::pushState Feb 07 17:22:08 music volumio[19340]: info: CorePlayQueue::getTrack 0 Feb 07 17:22:08 music volumio[19340]: info: CoreCommandRouter::volumioPushState Feb 07 17:22:08 music volumio[19340]: info: Completed loading Core Plugins Feb 07 17:22:08 music volumio[19340]: info: Preparing to generate the ALSA configuration file Feb 07 17:22:08 music volumio[19340]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 07 17:22:08 music volumio[19340]: info: Discovery: Found device music Feb 07 17:22:08 music volumio[19340]: info: CoreCommandRouter::volumioGetState Feb 07 17:22:08 music volumio[19340]: info: CorePlayQueue::getTrack 0 Feb 07 17:22:08 music volumio[19340]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 07 17:22:08 music volumio[19340]: info: Discovery: Found device music Feb 07 17:22:08 music volumio[19340]: info: CoreCommandRouter::volumioGetState Feb 07 17:22:08 music volumio[19340]: info: CorePlayQueue::getTrack 0 Feb 07 17:22:08 music volumio[19340]: info: Asound.conf file unchanged, so no further update is needed Feb 07 17:22:08 music volumio[19340]: info: Output device has changed, restarting MPD Feb 07 17:22:08 music volumio[19340]: info: Output device has changed, restarting Shairport Sync Feb 07 17:22:08 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:08 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 17:22:08 music sudo[19494]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 17:22:08 music sudo[19494]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:08 music volumio[19340]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 17:22:08 music volumio[19340]: info: ___________ START PLUGINS ___________ Feb 07 17:22:08 music sudo[19494]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:08 music volumio[19340]: info: ControllerMpd::onStart: Initializing MPD Feb 07 17:22:08 music volumio[19340]: info: Creating MPD Configuration file Feb 07 17:22:08 music sudo[19496]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 17:22:08 music sudo[19496]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:08 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 17:22:08 music volumio[19340]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 17:22:08 music volumio[19340]: info: [1770502928445] CoreMusicLibrary::Adding element Media Servers Feb 07 17:22:08 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 17:22:08 music volumio[19340]: info: UPNP Browser: Client initialized successfully Feb 07 17:22:08 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:08 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 17:22:08 music sudo[19504]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 17:22:08 music sudo[19504]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:08 music systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 07 17:22:08 music sudo[19506]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 17:22:08 music sudo[19506]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:08 music sudo[19504]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:08 music volumio[19340]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 17:22:08 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:08 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 17:22:08 music systemd[1]: mpd.service: Deactivated successfully. Feb 07 17:22:08 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 17:22:08 music systemd[1]: mpd.service: Consumed 4.203s CPU time. Feb 07 17:22:08 music systemd[1]: mpd.socket: Deactivated successfully. Feb 07 17:22:08 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 17:22:08 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 17:22:08 music volumio[19340]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 17:22:08 music volumio[19340]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 17:22:08 music volumio[19340]: info: [1770502928635] CoreMusicLibrary::Adding element Last_100 Feb 07 17:22:08 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 17:22:08 music volumio[19340]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 17:22:08 music volumio[19340]: info: [1770502928640] CoreMusicLibrary::Adding element Webradio Feb 07 17:22:08 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 17:22:08 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 17:22:08 music volumio[19340]: info: Initializing BBC Radios Feb 07 17:22:08 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 17:22:08 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 17:22:08 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 17:22:08 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 17:22:08 music volumio[19340]: info: Creating Spotify config file Feb 07 17:22:08 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:08 music sudo[19521]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 07 17:22:08 music sudo[19521]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 07 17:22:08 music sudo[19521]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:09 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 07 17:22:09 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 17:22:09 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 17:22:09 music go-librespot[19534]: go-librespot daemon starting... Feb 07 17:22:09 music go-librespot[19535]: time="2026-02-07T17:22:09-05:00" level=info msg="running go-librespot 0.6.2" Feb 07 17:22:09 music volumio[19340]: info: Volumio Calling Home Feb 07 17:22:09 music go-librespot[19535]: time="2026-02-07T17:22:09-05:00" level=info msg="zeroconf server listening on port 46351" Feb 07 17:22:09 music volumio[19455]: Starting albumart workers Feb 07 17:22:09 music volumio[19340]: info: MPD Permissions set Feb 07 17:22:09 music volumio[19340]: info: MPD Permissions set Feb 07 17:22:09 music volumio[19340]: info: Spotify config file written Feb 07 17:22:09 music volumio[19340]: 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 17:22:09 music sudo[19549]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 07 17:22:09 music sudo[19549]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:09 music volumio[19340]: info: Volumio called home Feb 07 17:22:09 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:09 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:09 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:09 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:09 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:09 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:09 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:09 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:10 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 17:22:10 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:10 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:10 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:10 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:10 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:10 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:10 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:10 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:10 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:10 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 07 17:22:10 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 07 17:22:10 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 17:22:10 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 17:22:10 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:10 music volumio[19340]: info: No need to fix Spotify hosts Feb 07 17:22:10 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 17:22:10 music go-librespot[19561]: go-librespot daemon starting... Feb 07 17:22:10 music sudo[19549]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:10 music go-librespot[19562]: time="2026-02-07T17:22:10-05:00" level=info msg="running go-librespot 0.6.2" Feb 07 17:22:10 music go-librespot[19562]: time="2026-02-07T17:22:10-05:00" level=debug msg="app state loaded" Feb 07 17:22:10 music volumio[19456]: Starting albumart workers Feb 07 17:22:10 music go-librespot[19562]: time="2026-02-07T17:22:10-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 17:22:10 music volumio[19457]: Starting albumart workers Feb 07 17:22:10 music go-librespot[19562]: time="2026-02-07T17:22: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-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 17:22:10 music go-librespot[19562]: time="2026-02-07T17:22:10-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 17:22:10 music go-librespot[19562]: time="2026-02-07T17:22:10-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 17:22:10 music go-librespot[19562]: time="2026-02-07T17:22:10-05:00" level=info msg="zeroconf server listening on port 37951" Feb 07 17:22:10 music volumio[19340]: info: Starting Shairport Sync Feb 07 17:22:10 music volumio[19340]: info: Starting Shairport Sync Feb 07 17:22:10 music volumio[19340]: info: Starting Shairport Sync Feb 07 17:22:10 music sudo[19575]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 17:22:10 music sudo[19575]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:10 music sudo[19577]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 17:22:10 music sudo[19577]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:10 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 07 17:22:10 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 07 17:22:10 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 17:22:10 music systemd[1]: shairport-sync.service: Consumed 1.876s CPU time. Feb 07 17:22:10 music go-librespot[19562]: time="2026-02-07T17:22:10-05:00" level=debug msg="obtained new client token: AABFlFfT+5iYijat2HVLK1/5aQEisVrM4Op/YAk3ik6yLhBFFEJqk4FGvmiUoRdcLZ0WFvp71JP3SJDVW7bK+8tziSEJDvzmK8b1ZJEKXsQ+SSK/7r7/wY4VTsI7aQQOJ1amzWCLcw0C/FriwHclpe79u5KMdht9X6owgLaSVaWguJRgB2T3zUgsASTwllq4zlfrbOwaWQOOCV9cpotRQl98bAQG5sQylJrYBhWhy2KcDMtP+Z1QsVg=" Feb 07 17:22:10 music sudo[19580]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 17:22:10 music volumio[19340]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 07 17:22:10 music sudo[19580]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:10 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 17:22:10 music go-librespot[19562]: time="2026-02-07T17:22:10-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 17:22:10 music sudo[19575]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:10 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 07 17:22:10 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 07 17:22:10 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 17:22:11 music go-librespot[19562]: time="2026-02-07T17:22:11-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:11 music go-librespot[19562]: time="2026-02-07T17:22:11-05:00" level=debug msg="completed challenge" Feb 07 17:22:11 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 17:22:11 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 07 17:22:11 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 07 17:22:11 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 17:22:11 music sudo[19577]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:11 music go-librespot[19562]: time="2026-02-07T17:22:11-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:11 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 17:22:11 music sudo[19580]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:11 music volumio[19340]: info: Shairport-Sync Started Feb 07 17:22:11 music volumio[19340]: Error adding Membership: Error: addMembership EINVAL Feb 07 17:22:11 music volumio[19340]: info: Shairport-Sync Started Feb 07 17:22:11 music volumio[19340]: info: Shairport-Sync Started Feb 07 17:22:11 music volumio[19340]: info: CoreCommandRouter::volumioGetState Feb 07 17:22:11 music volumio[19340]: info: CorePlayQueue::getTrack 0 Feb 07 17:22:11 music go-librespot[19562]: time="2026-02-07T17:22:11-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 17:22:11 music go-librespot[19562]: time="2026-02-07T17:22:11-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:11 music go-librespot[19562]: time="2026-02-07T17:22:11-05:00" level=debug msg="completed challenge" Feb 07 17:22:11 music go-librespot[19562]: time="2026-02-07T17:22:11-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:12 music go-librespot[19562]: time="2026-02-07T17:22:12-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 07 17:22:12 music go-librespot[19562]: time="2026-02-07T17:22:12-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:12 music go-librespot[19562]: time="2026-02-07T17:22:12-05:00" level=debug msg="completed challenge" Feb 07 17:22:12 music go-librespot[19562]: time="2026-02-07T17:22:12-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:13 music mpd[19533]: 2026-02-07T17:22:13 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 07 17:22:13 music systemd[1]: Started mpd.service - Music Player Daemon. Feb 07 17:22:13 music sudo[19506]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:13 music sudo[19496]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:13 music volumio[19340]: info: Completed starting Core Plugins Feb 07 17:22:13 music volumio[19340]: info: ------------------------------------------- Feb 07 17:22:13 music volumio[19340]: info: ----- MyVolumio plugins startup ---- Feb 07 17:22:13 music volumio[19340]: info: ------------------------------------------- Feb 07 17:22:13 music volumio[19340]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 07 17:22:13 music go-librespot[19562]: time="2026-02-07T17:22:13-05:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 07 17:22:13 music volumio[19340]: error: MPD error: The expression evaluated to a falsy value: Feb 07 17:22:13 music volumio[19340]: assert.ok(self.idling) Feb 07 17:22:13 music volumio[19340]: error: The expression evaluated to a falsy value: Feb 07 17:22:13 music volumio[19340]: assert.ok(self.idling) Feb 07 17:22:13 music volumio[19340]: error: updateQueue error: null Feb 07 17:22:13 music volumio[19340]: info: MPD running with PID19533 Feb 07 17:22:13 music volumio[19340]: ,establishing connection Feb 07 17:22:13 music volumio[19340]: error: updateQueue error: null Feb 07 17:22:13 music go-librespot[19562]: time="2026-02-07T17:22:13-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 17:22:13 music go-librespot[19562]: time="2026-02-07T17:22:13-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:13 music go-librespot[19562]: time="2026-02-07T17:22:13-05:00" level=debug msg="completed challenge" Feb 07 17:22:13 music go-librespot[19562]: time="2026-02-07T17:22:13-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:13 music volumio[19340]: info: go-librespot daemon successfully initialized Feb 07 17:22:13 music sudo[19638]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 17:22:13 music sudo[19638]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:13 music sudo[19640]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 17:22:13 music sudo[19640]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:13 music sudo[19638]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:13 music sudo[19640]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:13 music sudo[19643]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 07 17:22:13 music sudo[19643]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:13 music sudo[19643]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:13 music volumio[19340]: info: Upmpdcli Daemon Started Feb 07 17:22:14 music go-librespot[19562]: time="2026-02-07T17:22:14-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 07 17:22:14 music go-librespot[19562]: time="2026-02-07T17:22:14-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:14 music go-librespot[19562]: time="2026-02-07T17:22:14-05:00" level=debug msg="completed challenge" Feb 07 17:22:14 music go-librespot[19562]: time="2026-02-07T17:22:14-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:15 music go-librespot[19562]: time="2026-02-07T17:22:15-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 17:22:15 music go-librespot[19562]: time="2026-02-07T17:22:15-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:15 music go-librespot[19562]: time="2026-02-07T17:22:15-05:00" level=debug msg="completed challenge" Feb 07 17:22:15 music go-librespot[19562]: time="2026-02-07T17:22:15-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:15 music go-librespot[19562]: time="2026-02-07T17:22: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 17:22:15 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 17:22:15 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 17:22:15 music volumio[19340]: info: CoreCommandRouter::volumioGetState Feb 07 17:22:15 music volumio[19340]: info: CorePlayQueue::getTrack 0 Feb 07 17:22:16 music sudo[19647]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 07 17:22:16 music sudo[19647]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:16 music sudo[19649]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 07 17:22:16 music sudo[19649]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:16 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 07 17:22:16 music systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 07 17:22:16 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 07 17:22:16 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 07 17:22:16 music sudo[19647]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:16 music sudo[19649]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:16 music volumio[19340]: info: Successfully started MPD Monitor Feb 07 17:22:16 music mpd_monitor.sh[19652]: MPD Monitor Service: Starting MPD Monitor Service Feb 07 17:22:16 music volumio[19340]: info: Successfully started MPD Monitor Feb 07 17:22:16 music volumio[19340]: info: Initializing connection to go-librespot Websocket Feb 07 17:22:16 music volumio[19340]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 17:22:18 music volumio[19340]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 07 17:22:18 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 07 17:22:18 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 17:22:18 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 17:22:18 music go-librespot[19656]: go-librespot daemon starting... Feb 07 17:22:18 music go-librespot[19657]: time="2026-02-07T17:22:18-05:00" level=info msg="running go-librespot 0.6.2" Feb 07 17:22:18 music go-librespot[19657]: time="2026-02-07T17:22:18-05:00" level=debug msg="app state loaded" Feb 07 17:22:18 music go-librespot[19657]: time="2026-02-07T17:22:18-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 17:22:18 music go-librespot[19657]: time="2026-02-07T17:22:18-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 17:22:18 music go-librespot[19657]: time="2026-02-07T17:22:18-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 17:22:18 music go-librespot[19657]: time="2026-02-07T17:22:18-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 17:22:18 music go-librespot[19657]: time="2026-02-07T17:22:18-05:00" level=info msg="zeroconf server listening on port 39925" Feb 07 17:22:18 music go-librespot[19657]: time="2026-02-07T17:22:18-05:00" level=debug msg="obtained new client token: AAAB4RBCxpT+WUznZ4FOk+6kB8R7pgflu3kUhh04dTDVEjqwhcchEcGZJjYK0m+jzurdXfUCFN0ffpFVYOxa3Ri4LwbU3rVWB2uHyExP66M4a1ixdn09bS6ty8LO06lUPigjz3sIpnx88H03rONustxkx7xXneYeswVulhXvYUPjDA5CA4WJTpTHVwrT+QdhRpQqf3lPwW01KihdmGQxywy97eXrB815+shWkG58uW1O8va4FpQ4XfY=" Feb 07 17:22:18 music go-librespot[19657]: time="2026-02-07T17:22:18-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 17:22:19 music go-librespot[19657]: time="2026-02-07T17:22:19-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:19 music go-librespot[19657]: time="2026-02-07T17:22:19-05:00" level=debug msg="completed challenge" Feb 07 17:22:19 music go-librespot[19657]: time="2026-02-07T17:22:19-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:19 music go-librespot[19657]: time="2026-02-07T17:22:19-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 17:22:19 music volumio[19340]: info: Initializing connection to go-librespot Websocket Feb 07 17:22:19 music go-librespot[19657]: time="2026-02-07T17:22:19-05:00" level=debug msg="new websocket client" Feb 07 17:22:19 music volumio[19340]: info: Connection to go-librespot Websocket established Feb 07 17:22:19 music go-librespot[19657]: time="2026-02-07T17:22:19-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:19 music go-librespot[19657]: time="2026-02-07T17:22:19-05:00" level=debug msg="completed challenge" Feb 07 17:22:19 music go-librespot[19657]: time="2026-02-07T17:22:19-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:20 music go-librespot[19657]: time="2026-02-07T17:22:20-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 17:22:20 music go-librespot[19657]: time="2026-02-07T17:22:20-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 07 17:22:20 music go-librespot[19657]: time="2026-02-07T17:22:20-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:20 music go-librespot[19657]: time="2026-02-07T17:22:20-05:00" level=debug msg="completed challenge" Feb 07 17:22:20 music go-librespot[19657]: time="2026-02-07T17:22:20-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:21 music go-librespot[19657]: time="2026-02-07T17:22:21-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 17:22:21 music go-librespot[19657]: time="2026-02-07T17:22:21-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:21 music go-librespot[19657]: time="2026-02-07T17:22:21-05:00" level=debug msg="completed challenge" Feb 07 17:22:21 music go-librespot[19657]: time="2026-02-07T17:22:21-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:21 music volumio[19340]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 07 17:22:21 music volumio[19340]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 07 17:22:21 music volumio[19340]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 07 17:22:21 music volumio[19340]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 07 17:22:21 music volumio[19340]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 07 17:22:21 music volumio[19340]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 07 17:22:21 music volumio[19340]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 07 17:22:21 music volumio[19340]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 07 17:22:21 music volumio[19340]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 07 17:22:21 music volumio[19340]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 07 17:22:21 music volumio[19340]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 07 17:22:21 music volumio[19340]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 07 17:22:21 music volumio[19340]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 07 17:22:21 music volumio[19340]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 07 17:22:21 music volumio[19340]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 07 17:22:21 music volumio[19340]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 07 17:22:21 music volumio[19340]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 07 17:22:21 music volumio[19340]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 07 17:22:21 music volumio[19340]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 07 17:22:21 music volumio[19340]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 07 17:22:21 music volumio[19340]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 07 17:22:21 music volumio[19340]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 07 17:22:21 music volumio[19340]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 07 17:22:21 music volumio[19340]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 07 17:22:21 music volumio[19340]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 07 17:22:21 music volumio[19340]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 07 17:22:21 music volumio[19340]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 07 17:22:21 music volumio[19340]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 07 17:22:21 music volumio[19340]: info: Adding plugin bluetooth to MyMusic Plugins Feb 07 17:22:21 music volumio[19340]: info: Adding plugin multiroom to MyMusic Plugins Feb 07 17:22:21 music volumio[19340]: info: Adding plugin metavolumio to MyMusic Plugins Feb 07 17:22:21 music volumio[19340]: info: Adding plugin cd_controller to MyMusic Plugins Feb 07 17:22:21 music volumio[19340]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 07 17:22:21 music volumio[19340]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 07 17:22:21 music volumio[19340]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 07 17:22:21 music volumio[19340]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 07 17:22:21 music go-librespot[19657]: time="2026-02-07T17:22:21-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 17:22:22 music go-librespot[19657]: time="2026-02-07T17:22:22-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 17:22:22 music go-librespot[19657]: time="2026-02-07T17:22:22-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:22 music go-librespot[19657]: time="2026-02-07T17:22:22-05:00" level=debug msg="completed challenge" Feb 07 17:22:22 music go-librespot[19657]: time="2026-02-07T17:22:22-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:22 music volumio[19340]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 07 17:22:22 music volumio[19340]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 07 17:22:22 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 17:22:22 music volumio[19340]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 17:22:22 music volumio[19340]: info: Starting MyVolumio Remote Streaming Endpoints Feb 07 17:22:22 music volumio[19340]: info: MyVolumio login type: Token Feb 07 17:22:22 music volumio[19340]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 07 17:22:22 music volumio[19340]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 07 17:22:22 music go-librespot[19657]: time="2026-02-07T17:22:22-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 17:22:22 music go-librespot[19657]: time="2026-02-07T17:22:22-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:22 music go-librespot[19657]: time="2026-02-07T17:22:22-05:00" level=debug msg="completed challenge" Feb 07 17:22:22 music go-librespot[19657]: time="2026-02-07T17:22:22-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:22 music go-librespot[19657]: time="2026-02-07T17:22:22-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 17:22:22 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 17:22:22 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 17:22:23 music volumio[19340]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 07 17:22:23 music volumio[19340]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 07 17:22:23 music volumio[19340]: info: Streaming services startup Feb 07 17:22:23 music volumio[19340]: info: Starting Streaming Daemon Feb 07 17:22:23 music sudo[19667]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 07 17:22:23 music sudo[19667]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:23 music volumio[19340]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 07 17:22:23 music sudo[19667]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:23 music volumio[19340]: info: Getting Spotify volume Feb 07 17:22:23 music volumio[19340]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 17:22:23 music volumio[19340]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 17:22:23 music volumio[19340]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 07 17:22:23 music volumio[19340]: errno: -111, Feb 07 17:22:23 music volumio[19340]: code: 'ECONNREFUSED', Feb 07 17:22:23 music volumio[19340]: syscall: 'connect', Feb 07 17:22:23 music volumio[19340]: address: '127.0.0.1', Feb 07 17:22:23 music volumio[19340]: port: 9879, Feb 07 17:22:23 music volumio[19340]: response: undefined Feb 07 17:22:23 music volumio[19340]: } Feb 07 17:22:23 music volumio[19340]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 17:22:24 music sudo[19702]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-07 17:21' Feb 07 17:22:24 music sudo[19702]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:24 music sudo[19702]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:24 music systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 07 17:22:24 music volumio-remote-updater[31331]: [2026-02-07 17:22:24] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 07 17:22:24 music volumio-remote-updater[31331]: [2026-02-07 17:22:24] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 07 17:22:24 music systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 07 17:22:24 music systemd[1]: volumio.service: Consumed 26.487s CPU time. Feb 07 17:22:24 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 17:22:24 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 17:22:25 music systemd[1]: volumio.service: Scheduled restart job, restart counter is at 50059. Feb 07 17:22:25 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 17:22:25 music systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 07 17:22:25 music systemd[1]: volumio.service: Consumed 26.487s CPU time. Feb 07 17:22:25 music systemd[1]: Started volumio.service - Volumio Backend Module. Feb 07 17:22:25 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 17:22:26 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 07 17:22:26 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 17:22:26 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 17:22:26 music go-librespot[19729]: go-librespot daemon starting... Feb 07 17:22:26 music go-librespot[19730]: time="2026-02-07T17:22:26-05:00" level=info msg="running go-librespot 0.6.2" Feb 07 17:22:26 music go-librespot[19730]: time="2026-02-07T17:22:26-05:00" level=debug msg="app state loaded" Feb 07 17:22:26 music go-librespot[19730]: time="2026-02-07T17:22:26-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 17:22:26 music go-librespot[19730]: time="2026-02-07T17:22:26-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 17:22:26 music go-librespot[19730]: time="2026-02-07T17:22:26-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 17:22:26 music go-librespot[19730]: time="2026-02-07T17:22:26-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 17:22:26 music go-librespot[19730]: time="2026-02-07T17:22:26-05:00" level=info msg="zeroconf server listening on port 33627" Feb 07 17:22:26 music go-librespot[19730]: time="2026-02-07T17:22:26-05:00" level=debug msg="obtained new client token: AADvxKBVd5eMAWav63JDeE/LRYzm4rwNNwJD1MxLnHTiZpN4cBGsDRTYmoyQxVCMWaKcsGtReWSoxSvKCIKdtswti7Z5o/Wscfe245Q1FBJvvVAilwWIvZx+qYirCM6jKwWD/SNYuPT05RGQJZ/BbohhsA1IJZuxhlUMKERZOAtt8Z5qbKGWWtQCHn2AZsfrtZmX9zZgo4VP5PdDCS22gxGC3i2+yzKjXgxq3kxx3qZtO68ELUHnfLo=" Feb 07 17:22:26 music go-librespot[19730]: time="2026-02-07T17:22:26-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 17:22:26 music go-librespot[19730]: time="2026-02-07T17:22:26-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:26 music go-librespot[19730]: time="2026-02-07T17:22:26-05:00" level=debug msg="completed challenge" Feb 07 17:22:26 music go-librespot[19730]: time="2026-02-07T17:22:26-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:27 music volumio[19714]: info: ------------------------------------------- Feb 07 17:22:27 music volumio[19714]: info: ----- Volumio3 ---- Feb 07 17:22:27 music volumio[19714]: info: ------------------------------------------- Feb 07 17:22:27 music volumio[19714]: info: ----- System startup ---- Feb 07 17:22:27 music volumio[19714]: info: ------------------------------------------- Feb 07 17:22:27 music go-librespot[19730]: time="2026-02-07T17:22:27-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 17:22:27 music go-librespot[19730]: time="2026-02-07T17:22:27-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:27 music go-librespot[19730]: time="2026-02-07T17:22:27-05:00" level=debug msg="completed challenge" Feb 07 17:22:27 music go-librespot[19730]: time="2026-02-07T17:22:27-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:27 music volumio[19714]: info: MYVOLUMIO Environment detected Feb 07 17:22:28 music volumio[19714]: info: Plugin folders cleanup Feb 07 17:22:28 music volumio[19714]: info: Scanning into folder /volumio/app/plugins/ Feb 07 17:22:28 music volumio[19714]: info: Scanning category audio_interface Feb 07 17:22:28 music volumio[19714]: info: Scanning category miscellanea Feb 07 17:22:28 music volumio[19714]: info: Scanning category music_service Feb 07 17:22:28 music volumio[19714]: info: Scanning category plugins.json Feb 07 17:22:28 music volumio[19714]: info: Scanning category system_controller Feb 07 17:22:28 music volumio[19714]: info: Scanning category user_interface Feb 07 17:22:28 music volumio[19714]: info: Scanning into folder /data/plugins/ Feb 07 17:22:28 music volumio[19714]: info: Scanning category music_service Feb 07 17:22:28 music volumio[19714]: info: Plugin folders cleanup completed Feb 07 17:22:28 music volumio[19714]: info: ------------------------------------------- Feb 07 17:22:28 music volumio[19714]: info: ----- Core plugins startup ---- Feb 07 17:22:28 music volumio[19714]: info: ------------------------------------------- Feb 07 17:22:28 music volumio[19714]: info: Loading plugins from folder /volumio/app/plugins/ Feb 07 17:22:28 music volumio[19714]: info: Adding plugin upnp to MyMusic Plugins Feb 07 17:22:28 music volumio[19714]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 07 17:22:28 music volumio[19714]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 07 17:22:28 music volumio[19714]: info: Loading plugins from folder /data/plugins/ Feb 07 17:22:28 music volumio[19714]: info: Loading plugin "system"... Feb 07 17:22:28 music volumio[19714]: info: Loading plugin "appearance"... Feb 07 17:22:28 music go-librespot[19730]: time="2026-02-07T17:22:28-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 07 17:22:28 music go-librespot[19730]: time="2026-02-07T17:22:28-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:28 music go-librespot[19730]: time="2026-02-07T17:22:28-05:00" level=debug msg="completed challenge" Feb 07 17:22:28 music go-librespot[19730]: time="2026-02-07T17:22:28-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:29 music go-librespot[19730]: time="2026-02-07T17:22:29-05:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 17:22:29 music volumio[19714]: info: Loading plugin "network"... Feb 07 17:22:29 music volumio[19714]: info: Refreshing Cached IP Addresses Feb 07 17:22:29 music go-librespot[19730]: time="2026-02-07T17:22:29-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:29 music go-librespot[19730]: time="2026-02-07T17:22:29-05:00" level=debug msg="completed challenge" Feb 07 17:22:29 music sudo[19752]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 17:22:29 music sudo[19752]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:29 music sudo[19754]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 17:22:29 music sudo[19754]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:29 music volumio[19714]: info: Loading plugin "services"... Feb 07 17:22:29 music sudo[19752]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:29 music sudo[19754]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:29 music volumio[19714]: info: Loading plugin "alsa_controller"... Feb 07 17:22:29 music sudo[19761]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 07 17:22:29 music sudo[19761]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:29 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 17:22:29 music volumio[19714]: info: Loading plugin "wizard"... Feb 07 17:22:29 music volumio[19714]: info: Loading plugin "networkfs"... Feb 07 17:22:29 music volumio[19714]: info: Starting Udev Watcher for removable devices Feb 07 17:22:29 music volumio[19714]: info: Ignoring mount for partition: boot Feb 07 17:22:29 music volumio[19714]: info: Ignoring mount for partition: volumio Feb 07 17:22:29 music volumio[19714]: info: Ignoring mount for partition: volumio_data Feb 07 17:22:29 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 17:22:29 music volumio[19714]: info: Loading plugin "volumio_command_line_client"... Feb 07 17:22:29 music volumio[19714]: info: Loading plugin "upnp"... Feb 07 17:22:29 music volumio[19714]: info: [1770502949439] Starting Upmpd Daemon Feb 07 17:22:29 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 17:22:29 music volumio[19714]: info: Loading plugin "my_music"... Feb 07 17:22:29 music go-librespot[19730]: time="2026-02-07T17:22:29-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:29 music volumio[19714]: info: Loading plugin "mpd"... Feb 07 17:22:29 music volumio-remote-updater[31331]: [2026-02-07 17:22:29] [connect] Successful connection Feb 07 17:22:29 music volumio[19714]: info: Loading plugin "upnp_browser"... Feb 07 17:22:29 music sudo[19761]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:30 music go-librespot[19730]: time="2026-02-07T17:22:30-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 17:22:30 music go-librespot[19730]: time="2026-02-07T17:22:30-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:30 music go-librespot[19730]: time="2026-02-07T17:22:30-05:00" level=debug msg="completed challenge" Feb 07 17:22:30 music go-librespot[19730]: time="2026-02-07T17:22:30-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:31 music go-librespot[19730]: time="2026-02-07T17:22:31-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 07 17:22:31 music go-librespot[19730]: time="2026-02-07T17:22:31-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:31 music go-librespot[19730]: time="2026-02-07T17:22:31-05:00" level=debug msg="completed challenge" Feb 07 17:22:31 music go-librespot[19730]: time="2026-02-07T17:22:31-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:31 music go-librespot[19730]: time="2026-02-07T17:22:31-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 17:22:31 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 17:22:31 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 17:22:31 music volumio[19714]: info: Starting UPNP Browser Feb 07 17:22:31 music volumio[19714]: info: Loading plugin "alarm-clock"... Feb 07 17:22:31 music volumio[19714]: info: Loading plugin "airplay_emulation"... Feb 07 17:22:31 music volumio[19714]: info: Starting Shairport Sync Feb 07 17:22:31 music volumio[19714]: info: Loading plugin "last_100"... Feb 07 17:22:31 music volumio[19714]: info: Loading plugin "webradio"... Feb 07 17:22:31 music volumio[19714]: info: Loading plugin "i2s_dacs"... Feb 07 17:22:31 music volumio[19714]: info: I2S DAC not set, start Auto-detection Feb 07 17:22:31 music volumio[19714]: info: Loading plugin "volumiodiscovery"... Feb 07 17:22:31 music volumio[19714]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 17:22:31 music volumio[19714]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 17:22:31 music volumio[19714]: *** WARNING *** For more information see Feb 07 17:22:31 music volumio[19714]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 17:22:31 music volumio[19714]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 17:22:31 music volumio[19714]: *** WARNING *** For more information see Feb 07 17:22:31 music node[19714]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 17:22:31 music node[19714]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 17:22:31 music node[19714]: *** WARNING *** For more information see Feb 07 17:22:31 music node[19714]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 17:22:31 music node[19714]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 17:22:31 music node[19714]: *** WARNING *** For more information see Feb 07 17:22:31 music volumio[19714]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 07 17:22:31 music volumio[19714]: info: Discovery: Started advertising with name: music Feb 07 17:22:31 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 17:22:31 music volumio[19714]: info: Loading plugin "spop"... Feb 07 17:22:32 music volumio[19714]: info: Loading plugin "outputs"... Feb 07 17:22:32 music volumio[19714]: info: Loading plugin "albumart"... Feb 07 17:22:32 music volumio[19714]: info: Plugin example_plugin is not enabled Feb 07 17:22:32 music volumio[19714]: info: Loading plugin "inputs"... Feb 07 17:22:32 music volumio[19714]: info: Loading plugin "updater_comm"... Feb 07 17:22:33 music volumio[19714]: info: Plugin mpdemulation is not enabled Feb 07 17:22:33 music volumio[19714]: info: Loading plugin "rest_api"... Feb 07 17:22:33 music volumio[19714]: info: Loading plugin "websocket"... Feb 07 17:22:33 music volumio[19714]: info: Starting Socket.io Server version 1.7.4 Feb 07 17:22:33 music volumio[19714]: info: Loading i18n strings for locale en Feb 07 17:22:33 music volumio[19714]: Updating browse sources language Feb 07 17:22:33 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 17:22:33 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 17:22:33 music volumio[19714]: info: CoreCommandRouter::initPlayerControls Feb 07 17:22:33 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:33 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:33 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:33 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:33 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:33 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:33 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:33 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:33 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 17:22:33 music volumio[19714]: Express server listening on port 3000 Feb 07 17:22:33 music volumio[19714]: [Metrics] WebUI: 6s 556.50ms Feb 07 17:22:33 music volumio[19714]: info: CoreStateMachine::resetVolumioState Feb 07 17:22:33 music volumio[19714]: info: CoreStateMachine::getcurrentVolume Feb 07 17:22:33 music volumio[19714]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 17:22:33 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 17:22:33 music volumio[19714]: info: Volumio Network Manager: Network status updated: 1 Feb 07 17:22:33 music volumio-remote-updater[31331]: [2026-02-07 17:22:33] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770502949 101 Feb 07 17:22:33 music volumio[19787]: Forking 3 albumart workers Feb 07 17:22:33 music volumio[19714]: 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 17:22:33 music volumio[19714]: info: VolumeController:: Volume=86 Mute =false Feb 07 17:22:33 music volumio[19714]: info: CoreStateMachine::pushState Feb 07 17:22:33 music volumio[19714]: info: CorePlayQueue::getTrack 0 Feb 07 17:22:33 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 17:22:33 music volumio[19714]: info: CoreCommandRouter::volumioPushState Feb 07 17:22:33 music volumio[19714]: info: CoreStateMachine::updateTrackBlock Feb 07 17:22:33 music volumio[19714]: info: CorePlayQueue::getTrackBlock Feb 07 17:22:33 music volumio[19714]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 17:22:33 music volumio[19714]: info: Reloading queue from file Feb 07 17:22:33 music volumio[19714]: info: CoreStateMachine::setRepeat null single undefined Feb 07 17:22:33 music volumio[19714]: info: CoreStateMachine::pushState Feb 07 17:22:33 music volumio[19714]: info: CorePlayQueue::getTrack 0 Feb 07 17:22:33 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 17:22:33 music volumio[19714]: info: CoreCommandRouter::volumioPushState Feb 07 17:22:33 music volumio[19714]: info: CoreStateMachine::setRandom null Feb 07 17:22:33 music volumio[19714]: info: CoreStateMachine::pushState Feb 07 17:22:33 music volumio[19714]: info: CorePlayQueue::getTrack 0 Feb 07 17:22:33 music volumio[19714]: info: CoreCommandRouter::volumioPushState Feb 07 17:22:33 music volumio[19714]: info: Setting Device type: Raspberry PI Feb 07 17:22:33 music volumio[19714]: info: VolumeController:: Volume=86 Mute =false Feb 07 17:22:33 music volumio[19714]: info: CoreStateMachine::pushState Feb 07 17:22:33 music volumio[19714]: info: CorePlayQueue::getTrack 0 Feb 07 17:22:33 music volumio[19714]: info: CoreCommandRouter::volumioPushState Feb 07 17:22:33 music volumio[19714]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 07 17:22:33 music volumio[19714]: info: Discovery: Found device music Feb 07 17:22:33 music volumio[19714]: info: CoreCommandRouter::volumioGetState Feb 07 17:22:33 music volumio[19714]: info: CorePlayQueue::getTrack 0 Feb 07 17:22:33 music volumio[19714]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 07 17:22:33 music volumio[19714]: info: Discovery: Found device music Feb 07 17:22:33 music volumio[19714]: info: CoreCommandRouter::volumioGetState Feb 07 17:22:33 music volumio[19714]: info: CorePlayQueue::getTrack 0 Feb 07 17:22:33 music volumio[19714]: info: Completed loading Core Plugins Feb 07 17:22:33 music volumio[19714]: info: Preparing to generate the ALSA configuration file Feb 07 17:22:33 music volumio[19714]: info: Asound.conf file unchanged, so no further update is needed Feb 07 17:22:33 music volumio[19714]: info: Output device has changed, restarting MPD Feb 07 17:22:33 music volumio[19714]: info: Output device has changed, restarting Shairport Sync Feb 07 17:22:33 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:33 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 17:22:33 music sudo[19842]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 17:22:33 music sudo[19842]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:33 music sudo[19842]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:33 music sudo[19844]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 17:22:33 music sudo[19844]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:33 music volumio[19714]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 17:22:33 music volumio[19714]: info: ___________ START PLUGINS ___________ Feb 07 17:22:33 music volumio[19714]: info: ControllerMpd::onStart: Initializing MPD Feb 07 17:22:33 music volumio[19714]: info: Creating MPD Configuration file Feb 07 17:22:33 music systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 07 17:22:33 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 17:22:33 music volumio[19714]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 17:22:33 music volumio[19714]: info: [1770502953926] CoreMusicLibrary::Adding element Media Servers Feb 07 17:22:33 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 17:22:33 music sudo[19852]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 17:22:33 music volumio[19714]: info: UPNP Browser: Client initialized successfully Feb 07 17:22:33 music systemd[1]: mpd.service: Deactivated successfully. Feb 07 17:22:33 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 17:22:33 music systemd[1]: mpd.service: Consumed 4.109s CPU time. Feb 07 17:22:33 music sudo[19852]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:33 music systemd[1]: mpd.socket: Deactivated successfully. Feb 07 17:22:33 music sudo[19852]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:33 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 17:22:33 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 17:22:33 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:33 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 17:22:34 music sudo[19854]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 17:22:34 music sudo[19854]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:34 music volumio[19714]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 17:22:34 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:34 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 17:22:34 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 17:22:34 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 17:22:34 music systemd[1]: mpd.service: Deactivated successfully. Feb 07 17:22:34 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 17:22:34 music systemd[1]: mpd.socket: Deactivated successfully. Feb 07 17:22:34 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 17:22:34 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 17:22:34 music volumio[19714]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 17:22:34 music volumio[19714]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 17:22:34 music volumio[19714]: info: [1770502954095] CoreMusicLibrary::Adding element Last_100 Feb 07 17:22:34 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 17:22:34 music volumio[19714]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 17:22:34 music volumio[19714]: info: [1770502954099] CoreMusicLibrary::Adding element Webradio Feb 07 17:22:34 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 17:22:34 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 17:22:34 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 17:22:34 music volumio[19714]: info: Initializing BBC Radios Feb 07 17:22:34 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 17:22:34 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 17:22:34 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 17:22:34 music volumio[19714]: info: Creating Spotify config file Feb 07 17:22:34 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:34 music sudo[19868]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 07 17:22:34 music sudo[19868]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 07 17:22:34 music sudo[19868]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:34 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 07 17:22:34 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 17:22:34 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 17:22:34 music go-librespot[19884]: go-librespot daemon starting... Feb 07 17:22:34 music go-librespot[19885]: time="2026-02-07T17:22:34-05:00" level=info msg="running go-librespot 0.6.2" Feb 07 17:22:34 music volumio[19714]: info: Volumio Calling Home Feb 07 17:22:35 music go-librespot[19885]: time="2026-02-07T17:22:35-05:00" level=info msg="zeroconf server listening on port 34939" Feb 07 17:22:35 music volumio[19803]: Starting albumart workers Feb 07 17:22:35 music volumio[19714]: info: MPD Permissions set Feb 07 17:22:35 music volumio[19714]: info: MPD Permissions set Feb 07 17:22:35 music volumio[19714]: info: Volumio called home Feb 07 17:22:35 music volumio[19714]: info: Spotify config file written Feb 07 17:22:35 music volumio[19714]: info: CoreCommandRouter::volumioGetState Feb 07 17:22:35 music volumio[19714]: info: CorePlayQueue::getTrack 0 Feb 07 17:22:35 music volumio[19805]: Starting albumart workers Feb 07 17:22:35 music sudo[19898]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 07 17:22:35 music sudo[19898]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:35 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 07 17:22:35 music systemd[1]: go-librespot-daemon.service: Killing process 19888 (go-librespot) with signal SIGKILL. Feb 07 17:22:35 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 07 17:22:35 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 17:22:35 music volumio[19804]: Starting albumart workers Feb 07 17:22:35 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 17:22:35 music sudo[19898]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:35 music go-librespot[19900]: go-librespot daemon starting... Feb 07 17:22:35 music go-librespot[19901]: time="2026-02-07T17:22:35-05:00" level=info msg="running go-librespot 0.6.2" Feb 07 17:22:35 music go-librespot[19901]: time="2026-02-07T17:22:35-05:00" level=debug msg="app state loaded" Feb 07 17:22:35 music go-librespot[19901]: time="2026-02-07T17:22:35-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 17:22:35 music volumio[19714]: 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 17:22:35 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:35 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:35 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:35 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:35 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:36 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:36 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:36 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:36 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 17:22:36 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:36 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:36 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:36 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:36 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:36 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:36 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:36 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:36 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:36 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 17:22:36 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:36 music volumio[19714]: info: No need to fix Spotify hosts Feb 07 17:22:36 music go-librespot[19901]: time="2026-02-07T17:22:36-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 17:22:36 music go-librespot[19901]: time="2026-02-07T17:22:36-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 17:22:36 music go-librespot[19901]: time="2026-02-07T17:22:36-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 17:22:36 music go-librespot[19901]: time="2026-02-07T17:22:36-05:00" level=info msg="zeroconf server listening on port 39807" Feb 07 17:22:36 music go-librespot[19901]: time="2026-02-07T17:22:36-05:00" level=debug msg="obtained new client token: AADdHIKP4mxRelQvaBoXSvUGLmYZRZPscGNSoW67rk2iw1WszVULZwSUd6MuRg5Iw2oXxSdFieOrKYu/ems0M5a+yR9TxysOqxqtfoIKxyTWQJa4c0c5J/ml4saapQWH25u7j/uU3FUurVMdQ05mYmcutTY37F5xwLGWdXt+hSw1CJ/DZMbpAI1VU+q9UQmcBwpXwkevJ0Peyiv/6LY6xco5VkbYRTgZMEfognflp++bNvnFQ+++zw8=" Feb 07 17:22:36 music go-librespot[19901]: time="2026-02-07T17:22:36-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 17:22:36 music go-librespot[19901]: time="2026-02-07T17:22:36-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:36 music go-librespot[19901]: time="2026-02-07T17:22:36-05:00" level=debug msg="completed challenge" Feb 07 17:22:36 music go-librespot[19901]: time="2026-02-07T17:22:36-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:36 music volumio[19714]: info: Listing playlists Feb 07 17:22:36 music volumio[19714]: info: Listing playlists Feb 07 17:22:36 music volumio[19714]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 07 17:22:36 music volumio[19714]: info: Starting Shairport Sync Feb 07 17:22:36 music volumio[19714]: info: Starting Shairport Sync Feb 07 17:22:36 music sudo[19936]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 17:22:36 music sudo[19936]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:36 music volumio[19714]: info: Starting Shairport Sync Feb 07 17:22:36 music sudo[19939]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 17:22:36 music sudo[19939]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:36 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 07 17:22:37 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 07 17:22:37 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 17:22:37 music systemd[1]: shairport-sync.service: Consumed 1.805s CPU time. Feb 07 17:22:37 music sudo[19941]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 17:22:37 music sudo[19941]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:37 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 17:22:37 music volumio[19714]: info: CoreCommandRouter::volumioGetState Feb 07 17:22:37 music volumio[19714]: info: CorePlayQueue::getTrack 0 Feb 07 17:22:37 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 07 17:22:37 music sudo[19936]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:37 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 07 17:22:37 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 17:22:37 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 17:22:37 music sudo[19939]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:37 music sudo[19941]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:37 music volumio[19714]: info: Shairport-Sync Started Feb 07 17:22:37 music volumio[19714]: Error adding Membership: Error: addMembership EINVAL Feb 07 17:22:37 music volumio[19714]: info: Shairport-Sync Started Feb 07 17:22:37 music volumio[19714]: info: Shairport-Sync Started Feb 07 17:22:37 music go-librespot[19901]: time="2026-02-07T17:22:37-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 17:22:37 music go-librespot[19901]: time="2026-02-07T17:22:37-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:37 music go-librespot[19901]: time="2026-02-07T17:22:37-05:00" level=debug msg="completed challenge" Feb 07 17:22:37 music go-librespot[19901]: time="2026-02-07T17:22:37-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:38 music go-librespot[19901]: time="2026-02-07T17:22:38-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 07 17:22:38 music go-librespot[19901]: time="2026-02-07T17:22:38-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:38 music go-librespot[19901]: time="2026-02-07T17:22:38-05:00" level=debug msg="completed challenge" Feb 07 17:22:38 music go-librespot[19901]: time="2026-02-07T17:22:38-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:38 music mpd[19883]: 2026-02-07T17:22:38 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 07 17:22:38 music systemd[1]: Started mpd.service - Music Player Daemon. Feb 07 17:22:38 music sudo[19844]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:38 music sudo[19854]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:38 music volumio[19714]: info: Completed starting Core Plugins Feb 07 17:22:38 music volumio[19714]: info: ------------------------------------------- Feb 07 17:22:38 music volumio[19714]: info: ----- MyVolumio plugins startup ---- Feb 07 17:22:38 music volumio[19714]: info: ------------------------------------------- Feb 07 17:22:38 music volumio[19714]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 07 17:22:38 music volumio[19714]: error: MPD error: The expression evaluated to a falsy value: Feb 07 17:22:38 music volumio[19714]: assert.ok(self.idling) Feb 07 17:22:38 music volumio[19714]: error: The expression evaluated to a falsy value: Feb 07 17:22:38 music volumio[19714]: assert.ok(self.idling) Feb 07 17:22:38 music volumio[19714]: error: updateQueue error: null Feb 07 17:22:38 music volumio[19714]: info: MPD running with PID19883 Feb 07 17:22:38 music volumio[19714]: ,establishing connection Feb 07 17:22:38 music go-librespot[19901]: time="2026-02-07T17:22:38-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 07 17:22:38 music volumio[19714]: error: updateQueue error: null Feb 07 17:22:38 music go-librespot[19901]: time="2026-02-07T17:22:38-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:38 music go-librespot[19901]: time="2026-02-07T17:22:38-05:00" level=debug msg="completed challenge" Feb 07 17:22:38 music go-librespot[19901]: time="2026-02-07T17:22:38-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:39 music sudo[19996]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 17:22:39 music sudo[19996]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:39 music sudo[19996]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:39 music sudo[19998]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 17:22:39 music sudo[19998]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:39 music sudo[19998]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:39 music sudo[20000]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 07 17:22:39 music sudo[20000]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:39 music sudo[20000]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:39 music volumio[19714]: info: Upmpdcli Daemon Started Feb 07 17:22:39 music go-librespot[19901]: time="2026-02-07T17:22:39-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 07 17:22:39 music go-librespot[19901]: time="2026-02-07T17:22:39-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:39 music go-librespot[19901]: time="2026-02-07T17:22:39-05:00" level=debug msg="completed challenge" Feb 07 17:22:39 music volumio[19714]: info: go-librespot daemon successfully initialized Feb 07 17:22:40 music go-librespot[19901]: time="2026-02-07T17:22:40-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:40 music go-librespot[19901]: time="2026-02-07T17:22:40-05:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:80, retrying with a different AP" error="dial tcp 104.199.65.9:80: connect: connection refused" Feb 07 17:22:40 music go-librespot[19901]: time="2026-02-07T17:22:40-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 17:22:40 music go-librespot[19901]: time="2026-02-07T17:22:40-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:40 music go-librespot[19901]: time="2026-02-07T17:22:40-05:00" level=debug msg="completed challenge" Feb 07 17:22:40 music go-librespot[19901]: time="2026-02-07T17:22:40-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:40 music go-librespot[19901]: time="2026-02-07T17:22:40-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 17:22:40 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 17:22:40 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 17:22:41 music sudo[20005]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 07 17:22:41 music sudo[20005]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:41 music sudo[20007]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 07 17:22:41 music sudo[20007]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:41 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 07 17:22:41 music systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 07 17:22:41 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 07 17:22:41 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 07 17:22:41 music sudo[20007]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:41 music sudo[20005]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:41 music mpd_monitor.sh[20010]: MPD Monitor Service: Starting MPD Monitor Service Feb 07 17:22:41 music volumio[19714]: info: Successfully started MPD Monitor Feb 07 17:22:41 music volumio[19714]: info: Successfully started MPD Monitor Feb 07 17:22:42 music volumio[19714]: info: Initializing connection to go-librespot Websocket Feb 07 17:22:42 music volumio[19714]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 17:22:43 music volumio[19714]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 07 17:22:44 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 07 17:22:44 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 17:22:44 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 17:22:44 music go-librespot[20014]: go-librespot daemon starting... Feb 07 17:22:44 music go-librespot[20015]: time="2026-02-07T17:22:44-05:00" level=info msg="running go-librespot 0.6.2" Feb 07 17:22:44 music go-librespot[20015]: time="2026-02-07T17:22:44-05:00" level=debug msg="app state loaded" Feb 07 17:22:44 music go-librespot[20015]: time="2026-02-07T17:22:44-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 17:22:44 music go-librespot[20015]: time="2026-02-07T17:22:44-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 17:22:44 music go-librespot[20015]: time="2026-02-07T17:22:44-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 17:22:44 music go-librespot[20015]: time="2026-02-07T17:22:44-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 17:22:44 music go-librespot[20015]: time="2026-02-07T17:22:44-05:00" level=info msg="zeroconf server listening on port 41439" Feb 07 17:22:44 music go-librespot[20015]: time="2026-02-07T17:22:44-05:00" level=debug msg="obtained new client token: AACujcrVIIZHm4vRlOKTcFN14d+hEn4CLy+6RudfYZd9jkyIpKyaTvvaZhMW9kKi5NTpW7kam7d2cw0z2UK/yLVmDOnztuBYOgzF/0MiH8KifLHWZS+LJClFfjYn54KrfUn4TSNhpoF7WWmDZjn7LFemFHnuAju0qwlr7B1RQNrUMJIi5enim+ML7SGlvxW9It0k6mR9zKKw2nYspTyua8XrXMUXfCssek9rHAkoJ6vYtp3A2HeY/Z8=" Feb 07 17:22:44 music go-librespot[20015]: time="2026-02-07T17:22:44-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 17:22:44 music go-librespot[20015]: time="2026-02-07T17:22:44-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 17:22:44 music go-librespot[20015]: time="2026-02-07T17:22:44-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:44 music go-librespot[20015]: time="2026-02-07T17:22:44-05:00" level=debug msg="completed challenge" Feb 07 17:22:44 music go-librespot[20015]: time="2026-02-07T17:22:44-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:45 music volumio[19714]: info: CoreCommandRouter::volumioGetState Feb 07 17:22:45 music volumio[19714]: info: CorePlayQueue::getTrack 0 Feb 07 17:22:45 music go-librespot[20015]: time="2026-02-07T17:22:45-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 07 17:22:45 music go-librespot[20015]: time="2026-02-07T17:22:45-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:45 music go-librespot[20015]: time="2026-02-07T17:22:45-05:00" level=debug msg="completed challenge" Feb 07 17:22:45 music go-librespot[20015]: time="2026-02-07T17:22:45-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:45 music volumio[19714]: info: Initializing connection to go-librespot Websocket Feb 07 17:22:45 music go-librespot[20015]: time="2026-02-07T17:22:45-05:00" level=debug msg="new websocket client" Feb 07 17:22:45 music volumio[19714]: info: Connection to go-librespot Websocket established Feb 07 17:22:46 music go-librespot[20015]: time="2026-02-07T17:22:46-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 07 17:22:46 music go-librespot[20015]: time="2026-02-07T17:22:46-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:46 music go-librespot[20015]: time="2026-02-07T17:22:46-05:00" level=debug msg="completed challenge" Feb 07 17:22:46 music go-librespot[20015]: time="2026-02-07T17:22:46-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:46 music go-librespot[20015]: time="2026-02-07T17:22:46-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 17:22:46 music volumio[19714]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 07 17:22:46 music volumio[19714]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 07 17:22:46 music volumio[19714]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 07 17:22:46 music volumio[19714]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 07 17:22:46 music volumio[19714]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 07 17:22:46 music volumio[19714]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 07 17:22:46 music volumio[19714]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 07 17:22:46 music volumio[19714]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 07 17:22:46 music volumio[19714]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 07 17:22:46 music volumio[19714]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 07 17:22:46 music volumio[19714]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 07 17:22:46 music volumio[19714]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 07 17:22:46 music volumio[19714]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 07 17:22:46 music volumio[19714]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 07 17:22:46 music volumio[19714]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 07 17:22:46 music volumio[19714]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 07 17:22:46 music volumio[19714]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 07 17:22:46 music volumio[19714]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 07 17:22:46 music volumio[19714]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 07 17:22:46 music volumio[19714]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 07 17:22:46 music volumio[19714]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 07 17:22:46 music volumio[19714]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 07 17:22:46 music volumio[19714]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 07 17:22:46 music volumio[19714]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 07 17:22:46 music volumio[19714]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 07 17:22:46 music volumio[19714]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 07 17:22:46 music volumio[19714]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 07 17:22:46 music volumio[19714]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 07 17:22:46 music volumio[19714]: info: Adding plugin bluetooth to MyMusic Plugins Feb 07 17:22:46 music go-librespot[20015]: time="2026-02-07T17:22:46-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:46 music go-librespot[20015]: time="2026-02-07T17:22:46-05:00" level=debug msg="completed challenge" Feb 07 17:22:46 music volumio[19714]: info: Adding plugin multiroom to MyMusic Plugins Feb 07 17:22:46 music volumio[19714]: info: Adding plugin metavolumio to MyMusic Plugins Feb 07 17:22:46 music volumio[19714]: info: Adding plugin cd_controller to MyMusic Plugins Feb 07 17:22:46 music volumio[19714]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 07 17:22:46 music volumio[19714]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 07 17:22:46 music volumio[19714]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 07 17:22:46 music volumio[19714]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 07 17:22:47 music go-librespot[20015]: time="2026-02-07T17:22:47-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:47 music go-librespot[20015]: time="2026-02-07T17:22:47-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 07 17:22:47 music go-librespot[20015]: time="2026-02-07T17:22:47-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:47 music go-librespot[20015]: time="2026-02-07T17:22:47-05:00" level=debug msg="completed challenge" Feb 07 17:22:47 music go-librespot[20015]: time="2026-02-07T17:22:47-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:48 music volumio[19714]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 07 17:22:48 music volumio[19714]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 07 17:22:48 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 17:22:48 music volumio[19714]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 17:22:48 music volumio[19714]: info: Starting MyVolumio Remote Streaming Endpoints Feb 07 17:22:48 music volumio[19714]: info: MyVolumio login type: Token Feb 07 17:22:48 music volumio[19714]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 07 17:22:48 music volumio[19714]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 07 17:22:48 music go-librespot[20015]: time="2026-02-07T17:22:48-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 17:22:48 music go-librespot[20015]: time="2026-02-07T17:22:48-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:48 music go-librespot[20015]: time="2026-02-07T17:22:48-05:00" level=debug msg="completed challenge" Feb 07 17:22:48 music go-librespot[20015]: time="2026-02-07T17:22:48-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:48 music go-librespot[20015]: time="2026-02-07T17:22:48-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 17:22:48 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 17:22:48 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 17:22:49 music volumio[19714]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 07 17:22:49 music volumio[19714]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 07 17:22:49 music volumio[19714]: info: Streaming services startup Feb 07 17:22:49 music volumio[19714]: info: Starting Streaming Daemon Feb 07 17:22:49 music sudo[20025]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 07 17:22:49 music sudo[20025]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:49 music volumio[19714]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 07 17:22:49 music sudo[20025]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:49 music volumio[19714]: info: Getting Spotify volume Feb 07 17:22:49 music volumio[19714]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 17:22:49 music volumio[19714]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 17:22:49 music volumio[19714]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 07 17:22:49 music volumio[19714]: errno: -111, Feb 07 17:22:49 music volumio[19714]: code: 'ECONNREFUSED', Feb 07 17:22:49 music volumio[19714]: syscall: 'connect', Feb 07 17:22:49 music volumio[19714]: address: '127.0.0.1', Feb 07 17:22:49 music volumio[19714]: port: 9879, Feb 07 17:22:49 music volumio[19714]: response: undefined Feb 07 17:22:49 music volumio[19714]: } Feb 07 17:22:49 music volumio[19714]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 17:22:49 music sudo[20060]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-07 17:21' Feb 07 17:22:49 music sudo[20060]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:50 music sudo[20060]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:50 music volumio-remote-updater[31331]: [2026-02-07 17:22:50] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 07 17:22:50 music volumio-remote-updater[31331]: [2026-02-07 17:22:50] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 07 17:22:50 music systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 07 17:22:50 music systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 07 17:22:50 music systemd[1]: volumio.service: Consumed 26.494s CPU time. Feb 07 17:22:50 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 17:22:50 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 17:22:50 music systemd[1]: volumio.service: Scheduled restart job, restart counter is at 50060. Feb 07 17:22:50 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 17:22:50 music systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 07 17:22:50 music systemd[1]: volumio.service: Consumed 26.494s CPU time. Feb 07 17:22:50 music systemd[1]: Started volumio.service - Volumio Backend Module. Feb 07 17:22:50 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 17:22:51 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 07 17:22:51 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 17:22:51 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 17:22:51 music go-librespot[20087]: go-librespot daemon starting... Feb 07 17:22:51 music go-librespot[20088]: time="2026-02-07T17:22:51-05:00" level=info msg="running go-librespot 0.6.2" Feb 07 17:22:51 music go-librespot[20088]: time="2026-02-07T17:22:51-05:00" level=debug msg="app state loaded" Feb 07 17:22:51 music go-librespot[20088]: time="2026-02-07T17:22:51-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 17:22:52 music go-librespot[20088]: time="2026-02-07T17:22:52-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 17:22:52 music go-librespot[20088]: time="2026-02-07T17:22:52-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 17:22:52 music go-librespot[20088]: time="2026-02-07T17:22:52-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 17:22:52 music go-librespot[20088]: time="2026-02-07T17:22:52-05:00" level=info msg="zeroconf server listening on port 43205" Feb 07 17:22:52 music go-librespot[20088]: time="2026-02-07T17:22:52-05:00" level=debug msg="obtained new client token: AAA1i+51W9x5MF0uEUkXVobY02qt1s1rxanm8lJT0lzzO9wPSdtgvSqeBgiuMvRxDp8v7oKdEJ1G/+CcWb5A+g3o2XW6hWASF7/8I/0KCaYSN0q9yG/TF5TtNf4bdhMl6lVxGwB1/81n9yzx5xbgNJJAkRUTH1BRgTXcpgOgLxuX48OP5st/ZoRS8Om/sYZUdQe4X/1FeYbiJeTkKUzQrvF3kuDIEnNqDyco/ZcJL0JZfxbfT4N94io=" Feb 07 17:22:52 music go-librespot[20088]: time="2026-02-07T17:22:52-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 17:22:52 music go-librespot[20088]: time="2026-02-07T17:22:52-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:52 music go-librespot[20088]: time="2026-02-07T17:22:52-05:00" level=debug msg="completed challenge" Feb 07 17:22:52 music go-librespot[20088]: time="2026-02-07T17:22:52-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:52 music volumio[20072]: info: ------------------------------------------- Feb 07 17:22:52 music volumio[20072]: info: ----- Volumio3 ---- Feb 07 17:22:52 music volumio[20072]: info: ------------------------------------------- Feb 07 17:22:52 music volumio[20072]: info: ----- System startup ---- Feb 07 17:22:52 music volumio[20072]: info: ------------------------------------------- Feb 07 17:22:53 music go-librespot[20088]: time="2026-02-07T17:22:53-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 17:22:53 music go-librespot[20088]: time="2026-02-07T17:22:53-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:53 music go-librespot[20088]: time="2026-02-07T17:22:53-05:00" level=debug msg="completed challenge" Feb 07 17:22:53 music go-librespot[20088]: time="2026-02-07T17:22:53-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:53 music volumio[20072]: info: MYVOLUMIO Environment detected Feb 07 17:22:53 music volumio[20072]: info: Plugin folders cleanup Feb 07 17:22:53 music volumio[20072]: info: Scanning into folder /volumio/app/plugins/ Feb 07 17:22:53 music volumio[20072]: info: Scanning category audio_interface Feb 07 17:22:53 music volumio[20072]: info: Scanning category miscellanea Feb 07 17:22:53 music volumio[20072]: info: Scanning category music_service Feb 07 17:22:53 music volumio[20072]: info: Scanning category plugins.json Feb 07 17:22:53 music volumio[20072]: info: Scanning category system_controller Feb 07 17:22:53 music volumio[20072]: info: Scanning category user_interface Feb 07 17:22:53 music volumio[20072]: info: Scanning into folder /data/plugins/ Feb 07 17:22:53 music volumio[20072]: info: Scanning category music_service Feb 07 17:22:53 music volumio[20072]: info: Plugin folders cleanup completed Feb 07 17:22:53 music volumio[20072]: info: ------------------------------------------- Feb 07 17:22:53 music volumio[20072]: info: ----- Core plugins startup ---- Feb 07 17:22:53 music volumio[20072]: info: ------------------------------------------- Feb 07 17:22:53 music volumio[20072]: info: Loading plugins from folder /volumio/app/plugins/ Feb 07 17:22:53 music volumio[20072]: info: Adding plugin upnp to MyMusic Plugins Feb 07 17:22:53 music volumio[20072]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 07 17:22:53 music volumio[20072]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 07 17:22:53 music volumio[20072]: info: Loading plugins from folder /data/plugins/ Feb 07 17:22:53 music volumio[20072]: info: Loading plugin "system"... Feb 07 17:22:53 music volumio[20072]: info: Loading plugin "appearance"... Feb 07 17:22:53 music go-librespot[20088]: time="2026-02-07T17:22:53-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 07 17:22:54 music go-librespot[20088]: time="2026-02-07T17:22:54-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:54 music go-librespot[20088]: time="2026-02-07T17:22:54-05:00" level=debug msg="completed challenge" Feb 07 17:22:54 music go-librespot[20088]: time="2026-02-07T17:22:54-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:54 music go-librespot[20088]: time="2026-02-07T17:22:54-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 07 17:22:54 music volumio[20072]: info: Loading plugin "network"... Feb 07 17:22:54 music volumio[20072]: info: Refreshing Cached IP Addresses Feb 07 17:22:54 music sudo[20110]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 17:22:54 music go-librespot[20088]: time="2026-02-07T17:22:54-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:54 music go-librespot[20088]: time="2026-02-07T17:22:54-05:00" level=debug msg="completed challenge" Feb 07 17:22:54 music sudo[20110]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:54 music sudo[20110]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:54 music sudo[20112]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 17:22:54 music sudo[20112]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:54 music volumio[20072]: info: Loading plugin "services"... Feb 07 17:22:54 music sudo[20112]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:54 music volumio[20072]: info: Loading plugin "alsa_controller"... Feb 07 17:22:54 music sudo[20120]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 07 17:22:54 music sudo[20120]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:54 music go-librespot[20088]: time="2026-02-07T17:22:54-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:54 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 17:22:54 music volumio[20072]: info: Loading plugin "wizard"... Feb 07 17:22:54 music volumio[20072]: info: Loading plugin "networkfs"... Feb 07 17:22:54 music volumio[20072]: info: Starting Udev Watcher for removable devices Feb 07 17:22:54 music volumio[20072]: info: Ignoring mount for partition: boot Feb 07 17:22:54 music volumio[20072]: info: Ignoring mount for partition: volumio Feb 07 17:22:54 music volumio[20072]: info: Ignoring mount for partition: volumio_data Feb 07 17:22:54 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 17:22:54 music volumio[20072]: info: Loading plugin "volumio_command_line_client"... Feb 07 17:22:54 music volumio[20072]: info: Loading plugin "upnp"... Feb 07 17:22:54 music volumio[20072]: info: [1770502974899] Starting Upmpd Daemon Feb 07 17:22:54 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 17:22:54 music volumio[20072]: info: Loading plugin "my_music"... Feb 07 17:22:54 music volumio[20072]: info: Loading plugin "mpd"... Feb 07 17:22:55 music volumio[20072]: info: Loading plugin "upnp_browser"... Feb 07 17:22:55 music volumio-remote-updater[31331]: [2026-02-07 17:22:55] [connect] Successful connection Feb 07 17:22:55 music sudo[20120]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:55 music go-librespot[20088]: time="2026-02-07T17:22:55-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 17:22:55 music go-librespot[20088]: time="2026-02-07T17:22:55-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:55 music go-librespot[20088]: time="2026-02-07T17:22:55-05:00" level=debug msg="completed challenge" Feb 07 17:22:55 music go-librespot[20088]: time="2026-02-07T17:22:55-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:56 music go-librespot[20088]: time="2026-02-07T17:22:56-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 07 17:22:56 music go-librespot[20088]: time="2026-02-07T17:22:56-05:00" level=debug msg="completed keyexchange" Feb 07 17:22:56 music go-librespot[20088]: time="2026-02-07T17:22:56-05:00" level=debug msg="completed challenge" Feb 07 17:22:56 music go-librespot[20088]: time="2026-02-07T17:22:56-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:22:56 music go-librespot[20088]: time="2026-02-07T17:22:56-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 17:22:56 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 17:22:56 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 17:22:56 music volumio[20072]: info: Starting UPNP Browser Feb 07 17:22:56 music volumio[20072]: info: Loading plugin "alarm-clock"... Feb 07 17:22:56 music volumio[20072]: info: Loading plugin "airplay_emulation"... Feb 07 17:22:57 music volumio[20072]: info: Starting Shairport Sync Feb 07 17:22:57 music volumio[20072]: info: Loading plugin "last_100"... Feb 07 17:22:57 music volumio[20072]: info: Loading plugin "webradio"... Feb 07 17:22:57 music volumio[20072]: info: Loading plugin "i2s_dacs"... Feb 07 17:22:57 music volumio[20072]: info: I2S DAC not set, start Auto-detection Feb 07 17:22:57 music volumio[20072]: info: Loading plugin "volumiodiscovery"... Feb 07 17:22:57 music volumio[20072]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 17:22:57 music volumio[20072]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 17:22:57 music volumio[20072]: *** WARNING *** For more information see Feb 07 17:22:57 music volumio[20072]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 17:22:57 music volumio[20072]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 17:22:57 music volumio[20072]: *** WARNING *** For more information see Feb 07 17:22:57 music node[20072]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 17:22:57 music node[20072]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 17:22:57 music node[20072]: *** WARNING *** For more information see Feb 07 17:22:57 music node[20072]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 17:22:57 music node[20072]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 17:22:57 music node[20072]: *** WARNING *** For more information see Feb 07 17:22:57 music volumio[20072]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 07 17:22:57 music volumio[20072]: info: Discovery: Started advertising with name: music Feb 07 17:22:57 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 17:22:57 music volumio[20072]: info: Loading plugin "spop"... Feb 07 17:22:58 music volumio[20072]: info: Loading plugin "outputs"... Feb 07 17:22:58 music volumio[20072]: info: Loading plugin "albumart"... Feb 07 17:22:58 music volumio[20072]: info: Plugin example_plugin is not enabled Feb 07 17:22:58 music volumio[20072]: info: Loading plugin "inputs"... Feb 07 17:22:58 music volumio[20072]: info: Loading plugin "updater_comm"... Feb 07 17:22:58 music volumio[20072]: info: Plugin mpdemulation is not enabled Feb 07 17:22:58 music volumio[20072]: info: Loading plugin "rest_api"... Feb 07 17:22:58 music volumio[20072]: info: Loading plugin "websocket"... Feb 07 17:22:58 music volumio[20072]: info: Starting Socket.io Server version 1.7.4 Feb 07 17:22:58 music volumio[20072]: info: Loading i18n strings for locale en Feb 07 17:22:58 music volumio[20072]: Updating browse sources language Feb 07 17:22:58 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 17:22:58 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 17:22:58 music volumio[20072]: info: CoreCommandRouter::initPlayerControls Feb 07 17:22:58 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:58 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:58 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:58 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:58 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:58 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:58 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:58 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:58 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 17:22:58 music volumio[20072]: Express server listening on port 3000 Feb 07 17:22:58 music volumio[20072]: [Metrics] WebUI: 6s 597.99ms Feb 07 17:22:58 music volumio[20072]: info: CoreStateMachine::resetVolumioState Feb 07 17:22:58 music volumio[20072]: info: CoreStateMachine::getcurrentVolume Feb 07 17:22:58 music volumio[20072]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 17:22:58 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 17:22:58 music volumio[20072]: info: Volumio Network Manager: Network status updated: 1 Feb 07 17:22:58 music volumio[20145]: Forking 3 albumart workers Feb 07 17:22:58 music volumio[20072]: info: CoreCommandRouter::volumioGetState Feb 07 17:22:58 music volumio[20072]: info: CorePlayQueue::getTrack 0 Feb 07 17:22:58 music volumio-remote-updater[31331]: [2026-02-07 17:22:58] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770502975 101 Feb 07 17:22:59 music volumio[20072]: 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 17:22:59 music volumio[20072]: info: VolumeController:: Volume=86 Mute =false Feb 07 17:22:59 music volumio[20072]: info: CoreStateMachine::pushState Feb 07 17:22:59 music volumio[20072]: info: CorePlayQueue::getTrack 0 Feb 07 17:22:59 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 17:22:59 music volumio[20072]: info: CoreCommandRouter::volumioPushState Feb 07 17:22:59 music volumio[20072]: info: CoreStateMachine::updateTrackBlock Feb 07 17:22:59 music volumio[20072]: info: CorePlayQueue::getTrackBlock Feb 07 17:22:59 music volumio[20072]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 17:22:59 music volumio[20072]: info: Reloading queue from file Feb 07 17:22:59 music volumio[20072]: info: CoreStateMachine::setRepeat null single undefined Feb 07 17:22:59 music volumio[20072]: info: CoreStateMachine::pushState Feb 07 17:22:59 music volumio[20072]: info: CorePlayQueue::getTrack 0 Feb 07 17:22:59 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 17:22:59 music volumio[20072]: info: CoreCommandRouter::volumioPushState Feb 07 17:22:59 music volumio[20072]: info: CoreStateMachine::setRandom null Feb 07 17:22:59 music volumio[20072]: info: CoreStateMachine::pushState Feb 07 17:22:59 music volumio[20072]: info: CorePlayQueue::getTrack 0 Feb 07 17:22:59 music volumio[20072]: info: CoreCommandRouter::volumioPushState Feb 07 17:22:59 music volumio[20072]: info: Setting Device type: Raspberry PI Feb 07 17:22:59 music volumio[20072]: info: Listing playlists Feb 07 17:22:59 music volumio[20072]: info: Listing playlists Feb 07 17:22:59 music volumio[20072]: info: VolumeController:: Volume=86 Mute =false Feb 07 17:22:59 music volumio[20072]: info: CoreStateMachine::pushState Feb 07 17:22:59 music volumio[20072]: info: CorePlayQueue::getTrack 0 Feb 07 17:22:59 music volumio[20072]: info: CoreCommandRouter::volumioPushState Feb 07 17:22:59 music volumio[20072]: info: Completed loading Core Plugins Feb 07 17:22:59 music volumio[20072]: info: Preparing to generate the ALSA configuration file Feb 07 17:22:59 music volumio[20072]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 07 17:22:59 music volumio[20072]: info: Discovery: Found device music Feb 07 17:22:59 music volumio[20072]: info: CoreCommandRouter::volumioGetState Feb 07 17:22:59 music volumio[20072]: info: CorePlayQueue::getTrack 0 Feb 07 17:22:59 music volumio[20072]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 07 17:22:59 music volumio[20072]: info: Discovery: Found device music Feb 07 17:22:59 music volumio[20072]: info: CoreCommandRouter::volumioGetState Feb 07 17:22:59 music volumio[20072]: info: CorePlayQueue::getTrack 0 Feb 07 17:22:59 music volumio[20072]: info: Asound.conf file unchanged, so no further update is needed Feb 07 17:22:59 music volumio[20072]: info: Output device has changed, restarting MPD Feb 07 17:22:59 music volumio[20072]: info: Output device has changed, restarting Shairport Sync Feb 07 17:22:59 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:59 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 17:22:59 music sudo[20200]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 17:22:59 music sudo[20200]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:59 music sudo[20200]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:59 music sudo[20202]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 17:22:59 music sudo[20202]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:59 music volumio[20072]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 17:22:59 music volumio[20072]: info: ___________ START PLUGINS ___________ Feb 07 17:22:59 music volumio[20072]: info: ControllerMpd::onStart: Initializing MPD Feb 07 17:22:59 music volumio[20072]: info: Creating MPD Configuration file Feb 07 17:22:59 music systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 07 17:22:59 music sudo[20210]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 17:22:59 music sudo[20210]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:59 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 17:22:59 music systemd[1]: mpd.service: Deactivated successfully. Feb 07 17:22:59 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 17:22:59 music systemd[1]: mpd.service: Consumed 4.240s CPU time. Feb 07 17:22:59 music sudo[20210]: pam_unix(sudo:session): session closed for user root Feb 07 17:22:59 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 07 17:22:59 music systemd[1]: mpd.socket: Deactivated successfully. Feb 07 17:22:59 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 17:22:59 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 17:22:59 music volumio[20072]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 17:22:59 music volumio[20072]: info: [1770502979541] CoreMusicLibrary::Adding element Media Servers Feb 07 17:22:59 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 17:22:59 music sudo[20213]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 17:22:59 music sudo[20213]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:22:59 music volumio[20072]: info: UPNP Browser: Client initialized successfully Feb 07 17:22:59 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 17:22:59 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 17:22:59 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 17:22:59 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:59 music go-librespot[20216]: go-librespot daemon starting... Feb 07 17:22:59 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 17:22:59 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 17:22:59 music systemd[1]: mpd.service: Deactivated successfully. Feb 07 17:22:59 music go-librespot[20217]: time="2026-02-07T17:22:59-05:00" level=info msg="running go-librespot 0.6.2" Feb 07 17:22:59 music go-librespot[20217]: time="2026-02-07T17:22:59-05:00" level=debug msg="app state loaded" Feb 07 17:22:59 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 17:22:59 music systemd[1]: mpd.socket: Deactivated successfully. Feb 07 17:22:59 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 17:22:59 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 17:22:59 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 17:22:59 music volumio[20072]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 17:22:59 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:22:59 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 17:22:59 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 17:22:59 music go-librespot[20217]: time="2026-02-07T17:22:59-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 17:22:59 music volumio[20072]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 17:22:59 music volumio[20072]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 17:22:59 music volumio[20072]: info: [1770502979779] CoreMusicLibrary::Adding element Last_100 Feb 07 17:22:59 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 17:22:59 music volumio[20072]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 17:22:59 music volumio[20072]: info: [1770502979785] CoreMusicLibrary::Adding element Webradio Feb 07 17:22:59 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 17:22:59 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 17:22:59 music volumio[20072]: info: Initializing BBC Radios Feb 07 17:23:00 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 17:23:00 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 17:23:00 music sudo[20231]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 07 17:23:00 music sudo[20231]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 07 17:23:00 music sudo[20231]: pam_unix(sudo:session): session closed for user root Feb 07 17:23:00 music volumio[20072]: info: Creating Spotify config file Feb 07 17:23:00 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:00 music go-librespot[20217]: time="2026-02-07T17:23:00-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 17:23:00 music go-librespot[20217]: time="2026-02-07T17:23:00-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 17:23:00 music go-librespot[20217]: time="2026-02-07T17:23:00-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 17:23:00 music go-librespot[20217]: time="2026-02-07T17:23:00-05:00" level=info msg="zeroconf server listening on port 37579" Feb 07 17:23:00 music go-librespot[20217]: time="2026-02-07T17:23:00-05:00" level=debug msg="obtained new client token: AAC6uweIt+Gm7xncUZ4b0LqWKqc47aSjJPHQXYiEPkTvIYabZMvzw/dRJ+el68MtQioXSLoXfOKfEzFrKkI1YwBi3dr6JRgPrqE+kmEqFlRqTgWCj/+wcXpafT0jFg4yBnyGQG1HoNwxx5QHiiA8OjsvcB27KM8K2QsX8AUWrg+meAYNtN0jX9rq08n7/ykIOj3zgVDjS4rUArepJTbpOhR2KtN56Xn9Lv3S9wOQBMqn4wXKo0s21KA=" Feb 07 17:23:00 music go-librespot[20217]: time="2026-02-07T17:23:00-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 17:23:00 music go-librespot[20217]: time="2026-02-07T17:23:00-05:00" level=debug msg="completed keyexchange" Feb 07 17:23:00 music go-librespot[20217]: time="2026-02-07T17:23:00-05:00" level=debug msg="completed challenge" Feb 07 17:23:00 music volumio[20072]: info: Volumio Calling Home Feb 07 17:23:00 music go-librespot[20217]: time="2026-02-07T17:23:00-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:23:00 music volumio[20163]: Starting albumart workers Feb 07 17:23:01 music volumio[20072]: info: MPD Permissions set Feb 07 17:23:01 music volumio[20072]: info: MPD Permissions set Feb 07 17:23:01 music volumio[20072]: info: Spotify config file written Feb 07 17:23:01 music sudo[20256]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 07 17:23:01 music sudo[20256]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:23:01 music volumio[20161]: Starting albumart workers Feb 07 17:23:01 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 07 17:23:01 music systemd[1]: go-librespot-daemon.service: Killing process 20249 (go-librespot) with signal SIGKILL. Feb 07 17:23:01 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 07 17:23:01 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 17:23:01 music volumio[20072]: 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 17:23:01 music volumio[20072]: info: Volumio called home Feb 07 17:23:01 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:01 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 17:23:01 music go-librespot[20258]: go-librespot daemon starting... Feb 07 17:23:01 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:01 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:01 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:01 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:01 music sudo[20256]: pam_unix(sudo:session): session closed for user root Feb 07 17:23:01 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:01 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:01 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:01 music go-librespot[20259]: time="2026-02-07T17:23:01-05:00" level=info msg="running go-librespot 0.6.2" Feb 07 17:23:01 music go-librespot[20259]: time="2026-02-07T17:23:01-05:00" level=debug msg="app state loaded" Feb 07 17:23:01 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 17:23:01 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:01 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:01 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:01 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:01 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:01 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:01 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:01 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:01 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:01 music go-librespot[20259]: time="2026-02-07T17:23:01-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 17:23:01 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 17:23:01 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:01 music volumio[20162]: Starting albumart workers Feb 07 17:23:01 music volumio[20072]: info: No need to fix Spotify hosts Feb 07 17:23:01 music go-librespot[20259]: time="2026-02-07T17:23: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 17:23:01 music go-librespot[20259]: time="2026-02-07T17:23: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 17:23:01 music go-librespot[20259]: time="2026-02-07T17:23: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 17:23:01 music go-librespot[20259]: time="2026-02-07T17:23:01-05:00" level=info msg="zeroconf server listening on port 40229" Feb 07 17:23:01 music go-librespot[20259]: time="2026-02-07T17:23:01-05:00" level=debug msg="obtained new client token: AADvsE+giissRmyVT/8llNpH5mk2ppiBF0ifElnActHgdAv1bkEVKONxGYqmJfFvlFx3rRJXcSD2YPdSHxkm/1QF1zCAMx1MiQhznlrq6SKJImWGRGuxhzcN2AdgcoCx3kizQ/3uZGhqNZFOFxGbs5vmb+/1LC97rgzzbntRnr37Gbu0zJ2Cb6rFKrLcyqMj9eTxq39BRfo5gUBVVmOltbWAQMIHGN3aPBdOu8rztj6Nm4IwoFVsPDg=" Feb 07 17:23:02 music go-librespot[20259]: time="2026-02-07T17:23:02-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 17:23:02 music go-librespot[20259]: time="2026-02-07T17:23:02-05:00" level=debug msg="completed keyexchange" Feb 07 17:23:02 music go-librespot[20259]: time="2026-02-07T17:23:02-05:00" level=debug msg="completed challenge" Feb 07 17:23:02 music go-librespot[20259]: time="2026-02-07T17:23:02-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:23:02 music volumio[20072]: info: Starting Shairport Sync Feb 07 17:23:02 music volumio[20072]: info: Starting Shairport Sync Feb 07 17:23:02 music volumio[20072]: info: Starting Shairport Sync Feb 07 17:23:02 music volumio[20072]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 07 17:23:02 music sudo[20293]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 17:23:02 music sudo[20293]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:23:02 music sudo[20297]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 17:23:02 music sudo[20297]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:23:02 music sudo[20295]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 17:23:02 music sudo[20295]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:23:02 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 07 17:23:02 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 07 17:23:02 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 17:23:02 music systemd[1]: shairport-sync.service: Consumed 1.880s CPU time. Feb 07 17:23:02 music volumio[20072]: info: CoreCommandRouter::volumioGetState Feb 07 17:23:02 music volumio[20072]: info: CorePlayQueue::getTrack 0 Feb 07 17:23:02 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 17:23:02 music sudo[20293]: pam_unix(sudo:session): session closed for user root Feb 07 17:23:02 music volumio[20072]: info: Shairport-Sync Started Feb 07 17:23:02 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 07 17:23:02 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 07 17:23:02 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 17:23:02 music volumio[20072]: Error adding Membership: Error: addMembership EINVAL Feb 07 17:23:02 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 17:23:02 music sudo[20297]: pam_unix(sudo:session): session closed for user root Feb 07 17:23:02 music volumio[20072]: info: Shairport-Sync Started Feb 07 17:23:02 music sudo[20295]: pam_unix(sudo:session): session closed for user root Feb 07 17:23:02 music volumio[20072]: info: Shairport-Sync Started Feb 07 17:23:02 music go-librespot[20259]: time="2026-02-07T17:23:02-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 17:23:02 music go-librespot[20259]: time="2026-02-07T17:23:02-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 07 17:23:02 music go-librespot[20259]: time="2026-02-07T17:23:02-05:00" level=debug msg="completed keyexchange" Feb 07 17:23:02 music go-librespot[20259]: time="2026-02-07T17:23:02-05:00" level=debug msg="completed challenge" Feb 07 17:23:02 music go-librespot[20259]: time="2026-02-07T17:23:02-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:23:03 music go-librespot[20259]: time="2026-02-07T17:23:03-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 07 17:23:03 music go-librespot[20259]: time="2026-02-07T17:23:03-05:00" level=debug msg="completed keyexchange" Feb 07 17:23:03 music go-librespot[20259]: time="2026-02-07T17:23:03-05:00" level=debug msg="completed challenge" Feb 07 17:23:03 music go-librespot[20259]: time="2026-02-07T17:23:03-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:23:04 music mpd[20251]: 2026-02-07T17:23:04 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 07 17:23:04 music systemd[1]: Started mpd.service - Music Player Daemon. Feb 07 17:23:04 music sudo[20213]: pam_unix(sudo:session): session closed for user root Feb 07 17:23:04 music sudo[20202]: pam_unix(sudo:session): session closed for user root Feb 07 17:23:04 music volumio[20072]: info: Completed starting Core Plugins Feb 07 17:23:04 music volumio[20072]: info: ------------------------------------------- Feb 07 17:23:04 music volumio[20072]: info: ----- MyVolumio plugins startup ---- Feb 07 17:23:04 music volumio[20072]: info: ------------------------------------------- Feb 07 17:23:04 music volumio[20072]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 07 17:23:04 music volumio[20072]: error: MPD error: The expression evaluated to a falsy value: Feb 07 17:23:04 music volumio[20072]: assert.ok(self.idling) Feb 07 17:23:04 music volumio[20072]: error: The expression evaluated to a falsy value: Feb 07 17:23:04 music volumio[20072]: assert.ok(self.idling) Feb 07 17:23:04 music volumio[20072]: error: updateQueue error: null Feb 07 17:23:04 music volumio[20072]: info: MPD running with PID20251 Feb 07 17:23:04 music volumio[20072]: ,establishing connection Feb 07 17:23:04 music volumio[20072]: error: updateQueue error: null Feb 07 17:23:04 music go-librespot[20259]: time="2026-02-07T17:23:04-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 07 17:23:04 music go-librespot[20259]: time="2026-02-07T17:23:04-05:00" level=debug msg="completed keyexchange" Feb 07 17:23:04 music go-librespot[20259]: time="2026-02-07T17:23:04-05:00" level=debug msg="completed challenge" Feb 07 17:23:04 music go-librespot[20259]: time="2026-02-07T17:23:04-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:23:04 music sudo[20344]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 17:23:04 music sudo[20344]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:23:04 music sudo[20344]: pam_unix(sudo:session): session closed for user root Feb 07 17:23:04 music sudo[20346]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 17:23:04 music sudo[20346]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:23:04 music sudo[20346]: pam_unix(sudo:session): session closed for user root Feb 07 17:23:04 music sudo[20349]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 07 17:23:04 music sudo[20349]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:23:04 music sudo[20349]: pam_unix(sudo:session): session closed for user root Feb 07 17:23:05 music volumio[20072]: info: Upmpdcli Daemon Started Feb 07 17:23:05 music volumio[20072]: info: CoreCommandRouter::volumioGetState Feb 07 17:23:05 music volumio[20072]: info: CorePlayQueue::getTrack 0 Feb 07 17:23:05 music volumio[20072]: info: go-librespot daemon successfully initialized Feb 07 17:23:05 music go-librespot[20259]: time="2026-02-07T17:23:05-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 07 17:23:05 music go-librespot[20259]: time="2026-02-07T17:23:05-05:00" level=debug msg="completed keyexchange" Feb 07 17:23:05 music go-librespot[20259]: time="2026-02-07T17:23:05-05:00" level=debug msg="completed challenge" Feb 07 17:23:05 music go-librespot[20259]: time="2026-02-07T17:23:05-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:23:06 music go-librespot[20259]: time="2026-02-07T17:23:06-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 17:23:06 music go-librespot[20259]: time="2026-02-07T17:23:06-05:00" level=debug msg="completed keyexchange" Feb 07 17:23:06 music go-librespot[20259]: time="2026-02-07T17:23:06-05:00" level=debug msg="completed challenge" Feb 07 17:23:06 music go-librespot[20259]: time="2026-02-07T17:23:06-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:23:06 music go-librespot[20259]: time="2026-02-07T17:23:06-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 17:23:06 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 17:23:06 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 17:23:07 music sudo[20353]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 07 17:23:07 music sudo[20353]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:23:07 music sudo[20355]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 07 17:23:07 music sudo[20355]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:23:07 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 07 17:23:07 music systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 07 17:23:07 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 07 17:23:07 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 07 17:23:07 music sudo[20353]: pam_unix(sudo:session): session closed for user root Feb 07 17:23:07 music volumio[20072]: info: Successfully started MPD Monitor Feb 07 17:23:07 music mpd_monitor.sh[20358]: MPD Monitor Service: Starting MPD Monitor Service Feb 07 17:23:07 music sudo[20355]: pam_unix(sudo:session): session closed for user root Feb 07 17:23:07 music volumio[20072]: info: Successfully started MPD Monitor Feb 07 17:23:08 music volumio[20072]: info: Initializing connection to go-librespot Websocket Feb 07 17:23:08 music volumio[20072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 17:23:09 music volumio[20072]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 07 17:23:09 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 07 17:23:09 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 17:23:09 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 17:23:09 music go-librespot[20362]: go-librespot daemon starting... Feb 07 17:23:09 music go-librespot[20363]: time="2026-02-07T17:23:09-05:00" level=info msg="running go-librespot 0.6.2" Feb 07 17:23:09 music go-librespot[20363]: time="2026-02-07T17:23:09-05:00" level=debug msg="app state loaded" Feb 07 17:23:09 music go-librespot[20363]: time="2026-02-07T17:23:09-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 17:23:09 music go-librespot[20363]: time="2026-02-07T17:23:09-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 17:23:09 music go-librespot[20363]: time="2026-02-07T17:23:09-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 17:23:09 music go-librespot[20363]: time="2026-02-07T17:23:09-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 17:23:09 music go-librespot[20363]: time="2026-02-07T17:23:09-05:00" level=info msg="zeroconf server listening on port 39987" Feb 07 17:23:10 music go-librespot[20363]: time="2026-02-07T17:23:10-05:00" level=debug msg="obtained new client token: AACQu23xS9+KQo7isG8aszcVLjD14XwwjT0/8DfFjaR7dPg7FqMzXBD7EHMdOoTaUbefGmeDGMY4kgMcJIyNHZlJDapOa2/HAcqRAsD0fLbgQcrFrHz1lnN2KChfmocFtJ02BurhoA3Et7ICNZ84+/ldNphFcGYLyFH/tH2ILz/dqjDmwRm0bEvd3/C+fsmMbzdbw0MA0vco+PXn39MCvj3IvSudPEwda76wSGCwgVg2O5tTKKuW" Feb 07 17:23:10 music go-librespot[20363]: time="2026-02-07T17:23:10-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 17:23:10 music go-librespot[20363]: time="2026-02-07T17:23:10-05:00" level=debug msg="completed keyexchange" Feb 07 17:23:10 music go-librespot[20363]: time="2026-02-07T17:23:10-05:00" level=debug msg="completed challenge" Feb 07 17:23:10 music go-librespot[20363]: time="2026-02-07T17:23:10-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:23:10 music go-librespot[20363]: time="2026-02-07T17:23:10-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 17:23:10 music go-librespot[20363]: time="2026-02-07T17:23:10-05:00" level=debug msg="completed keyexchange" Feb 07 17:23:10 music go-librespot[20363]: time="2026-02-07T17:23:10-05:00" level=debug msg="completed challenge" Feb 07 17:23:11 music go-librespot[20363]: time="2026-02-07T17:23:11-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:23:11 music volumio[20072]: info: Initializing connection to go-librespot Websocket Feb 07 17:23:11 music go-librespot[20363]: time="2026-02-07T17:23:11-05:00" level=debug msg="new websocket client" Feb 07 17:23:11 music volumio[20072]: info: Connection to go-librespot Websocket established Feb 07 17:23:11 music go-librespot[20363]: time="2026-02-07T17:23:11-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 07 17:23:11 music go-librespot[20363]: time="2026-02-07T17:23:11-05:00" level=debug msg="completed keyexchange" Feb 07 17:23:11 music go-librespot[20363]: time="2026-02-07T17:23:11-05:00" level=debug msg="completed challenge" Feb 07 17:23:11 music go-librespot[20363]: time="2026-02-07T17:23:11-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:23:12 music go-librespot[20363]: time="2026-02-07T17:23:12-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 07 17:23:12 music go-librespot[20363]: time="2026-02-07T17:23:12-05:00" level=debug msg="completed keyexchange" Feb 07 17:23:12 music go-librespot[20363]: time="2026-02-07T17:23:12-05:00" level=debug msg="completed challenge" Feb 07 17:23:12 music volumio[20072]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 07 17:23:12 music volumio[20072]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 07 17:23:12 music volumio[20072]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 07 17:23:12 music volumio[20072]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 07 17:23:12 music go-librespot[20363]: time="2026-02-07T17:23:12-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:23:12 music volumio[20072]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 07 17:23:12 music volumio[20072]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 07 17:23:12 music volumio[20072]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 07 17:23:12 music volumio[20072]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 07 17:23:12 music volumio[20072]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 07 17:23:12 music volumio[20072]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 07 17:23:12 music volumio[20072]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 07 17:23:12 music volumio[20072]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 07 17:23:12 music volumio[20072]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 07 17:23:12 music volumio[20072]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 07 17:23:12 music volumio[20072]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 07 17:23:12 music volumio[20072]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 07 17:23:12 music volumio[20072]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 07 17:23:12 music volumio[20072]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 07 17:23:12 music volumio[20072]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 07 17:23:12 music volumio[20072]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 07 17:23:12 music volumio[20072]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 07 17:23:12 music volumio[20072]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 07 17:23:12 music volumio[20072]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 07 17:23:12 music volumio[20072]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 07 17:23:12 music volumio[20072]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 07 17:23:12 music volumio[20072]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 07 17:23:12 music volumio[20072]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 07 17:23:12 music volumio[20072]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 07 17:23:12 music volumio[20072]: info: Adding plugin bluetooth to MyMusic Plugins Feb 07 17:23:12 music volumio[20072]: info: Adding plugin multiroom to MyMusic Plugins Feb 07 17:23:12 music volumio[20072]: info: Adding plugin metavolumio to MyMusic Plugins Feb 07 17:23:12 music volumio[20072]: info: Adding plugin cd_controller to MyMusic Plugins Feb 07 17:23:12 music volumio[20072]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 07 17:23:12 music volumio[20072]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 07 17:23:12 music volumio[20072]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 07 17:23:12 music volumio[20072]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 07 17:23:13 music go-librespot[20363]: time="2026-02-07T17:23:13-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 07 17:23:13 music go-librespot[20363]: time="2026-02-07T17:23:13-05:00" level=debug msg="completed keyexchange" Feb 07 17:23:13 music go-librespot[20363]: time="2026-02-07T17:23:13-05:00" level=debug msg="completed challenge" Feb 07 17:23:13 music go-librespot[20363]: time="2026-02-07T17:23:13-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:23:13 music volumio[20072]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 07 17:23:13 music volumio[20072]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 07 17:23:13 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 17:23:13 music volumio[20072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 17:23:13 music volumio[20072]: info: Starting MyVolumio Remote Streaming Endpoints Feb 07 17:23:13 music volumio[20072]: info: MyVolumio login type: Token Feb 07 17:23:13 music volumio[20072]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 07 17:23:13 music volumio[20072]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 07 17:23:14 music go-librespot[20363]: time="2026-02-07T17:23:14-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 07 17:23:14 music go-librespot[20363]: time="2026-02-07T17:23:14-05:00" level=debug msg="completed keyexchange" Feb 07 17:23:14 music go-librespot[20363]: time="2026-02-07T17:23:14-05:00" level=debug msg="completed challenge" Feb 07 17:23:14 music go-librespot[20363]: time="2026-02-07T17:23:14-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:23:14 music go-librespot[20363]: time="2026-02-07T17:23:14-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 17:23:14 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 17:23:14 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 17:23:14 music volumio[20072]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 07 17:23:14 music volumio[20072]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 07 17:23:14 music volumio[20072]: info: Streaming services startup Feb 07 17:23:14 music volumio[20072]: info: Starting Streaming Daemon Feb 07 17:23:14 music sudo[20373]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 07 17:23:14 music sudo[20373]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:23:14 music volumio[20072]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 07 17:23:14 music sudo[20373]: pam_unix(sudo:session): session closed for user root Feb 07 17:23:14 music volumio[20072]: info: Getting Spotify volume Feb 07 17:23:14 music volumio[20072]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 17:23:14 music volumio[20072]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 17:23:14 music volumio[20072]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 07 17:23:14 music volumio[20072]: errno: -111, Feb 07 17:23:14 music volumio[20072]: code: 'ECONNREFUSED', Feb 07 17:23:14 music volumio[20072]: syscall: 'connect', Feb 07 17:23:14 music volumio[20072]: address: '127.0.0.1', Feb 07 17:23:14 music volumio[20072]: port: 9879, Feb 07 17:23:14 music volumio[20072]: response: undefined Feb 07 17:23:14 music volumio[20072]: } Feb 07 17:23:14 music volumio[20072]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 17:23:15 music sudo[20407]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-07 17:22' Feb 07 17:23:15 music sudo[20407]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:23:15 music sudo[20407]: pam_unix(sudo:session): session closed for user root Feb 07 17:23:15 music volumio-remote-updater[31331]: [2026-02-07 17:23:15] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 07 17:23:15 music volumio-remote-updater[31331]: [2026-02-07 17:23:15] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 07 17:23:15 music systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 07 17:23:15 music systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 07 17:23:15 music systemd[1]: volumio.service: Consumed 26.497s CPU time. Feb 07 17:23:15 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 17:23:15 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 17:23:16 music systemd[1]: volumio.service: Scheduled restart job, restart counter is at 50061. Feb 07 17:23:16 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 17:23:16 music systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 07 17:23:16 music systemd[1]: volumio.service: Consumed 26.497s CPU time. Feb 07 17:23:16 music systemd[1]: Started volumio.service - Volumio Backend Module. Feb 07 17:23:16 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 17:23:17 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 07 17:23:17 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 17:23:17 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 17:23:17 music go-librespot[20436]: go-librespot daemon starting... Feb 07 17:23:17 music go-librespot[20437]: time="2026-02-07T17:23:17-05:00" level=info msg="running go-librespot 0.6.2" Feb 07 17:23:17 music go-librespot[20437]: time="2026-02-07T17:23:17-05:00" level=debug msg="app state loaded" Feb 07 17:23:17 music go-librespot[20437]: time="2026-02-07T17:23:17-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 17:23:17 music go-librespot[20437]: time="2026-02-07T17:23:17-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 17:23:17 music go-librespot[20437]: time="2026-02-07T17:23:17-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 17:23:17 music go-librespot[20437]: time="2026-02-07T17:23:17-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 17:23:18 music go-librespot[20437]: time="2026-02-07T17:23:18-05:00" level=info msg="zeroconf server listening on port 41913" Feb 07 17:23:18 music volumio[20421]: info: ------------------------------------------- Feb 07 17:23:18 music volumio[20421]: info: ----- Volumio3 ---- Feb 07 17:23:18 music volumio[20421]: info: ------------------------------------------- Feb 07 17:23:18 music volumio[20421]: info: ----- System startup ---- Feb 07 17:23:18 music volumio[20421]: info: ------------------------------------------- Feb 07 17:23:18 music go-librespot[20437]: time="2026-02-07T17:23:18-05:00" level=debug msg="obtained new client token: AABpTkEMRlj0ByXwtlCDL9I7akMLERKRC6u8dvSEdtAPWdgsiIT8iOtldvQyW0UZRM7qP718wlLqnVJUHvsKaVSVriY4lNv2ggOSXBoMZ96hIW4bVlbSSEbPNyzHZARU2vftD2n0pacHH1WxISHIlFkp+S1IvRPKZvTUrJSKAta5rIGpGXc0jbKqGPwBZvct2+VAowidzPLR1lBXWh6QrzgscwCKuPSJG/QgdcbE32dp7icqzNS7" Feb 07 17:23:18 music go-librespot[20437]: time="2026-02-07T17:23:18-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 17:23:18 music go-librespot[20437]: time="2026-02-07T17:23:18-05:00" level=debug msg="completed keyexchange" Feb 07 17:23:18 music go-librespot[20437]: time="2026-02-07T17:23:18-05:00" level=debug msg="completed challenge" Feb 07 17:23:18 music go-librespot[20437]: time="2026-02-07T17:23:18-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:23:18 music volumio[20421]: info: MYVOLUMIO Environment detected Feb 07 17:23:18 music go-librespot[20437]: time="2026-02-07T17:23:18-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 17:23:18 music volumio[20421]: info: Plugin folders cleanup Feb 07 17:23:18 music volumio[20421]: info: Scanning into folder /volumio/app/plugins/ Feb 07 17:23:18 music volumio[20421]: info: Scanning category audio_interface Feb 07 17:23:18 music volumio[20421]: info: Scanning category miscellanea Feb 07 17:23:18 music volumio[20421]: info: Scanning category music_service Feb 07 17:23:18 music volumio[20421]: info: Scanning category plugins.json Feb 07 17:23:18 music volumio[20421]: info: Scanning category system_controller Feb 07 17:23:18 music volumio[20421]: info: Scanning category user_interface Feb 07 17:23:18 music volumio[20421]: info: Scanning into folder /data/plugins/ Feb 07 17:23:18 music volumio[20421]: info: Scanning category music_service Feb 07 17:23:18 music volumio[20421]: info: Plugin folders cleanup completed Feb 07 17:23:18 music volumio[20421]: info: ------------------------------------------- Feb 07 17:23:18 music volumio[20421]: info: ----- Core plugins startup ---- Feb 07 17:23:18 music volumio[20421]: info: ------------------------------------------- Feb 07 17:23:18 music volumio[20421]: info: Loading plugins from folder /volumio/app/plugins/ Feb 07 17:23:19 music volumio[20421]: info: Adding plugin upnp to MyMusic Plugins Feb 07 17:23:19 music volumio[20421]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 07 17:23:19 music volumio[20421]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 07 17:23:19 music volumio[20421]: info: Loading plugins from folder /data/plugins/ Feb 07 17:23:19 music volumio[20421]: info: Loading plugin "system"... Feb 07 17:23:19 music go-librespot[20437]: time="2026-02-07T17:23:19-05:00" level=debug msg="completed keyexchange" Feb 07 17:23:19 music go-librespot[20437]: time="2026-02-07T17:23:19-05:00" level=debug msg="completed challenge" Feb 07 17:23:19 music volumio[20421]: info: Loading plugin "appearance"... Feb 07 17:23:19 music go-librespot[20437]: time="2026-02-07T17:23:19-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:23:19 music go-librespot[20437]: time="2026-02-07T17:23:19-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 07 17:23:19 music go-librespot[20437]: time="2026-02-07T17:23:19-05:00" level=debug msg="completed keyexchange" Feb 07 17:23:19 music go-librespot[20437]: time="2026-02-07T17:23:19-05:00" level=debug msg="completed challenge" Feb 07 17:23:19 music go-librespot[20437]: time="2026-02-07T17:23:19-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:23:20 music volumio[20421]: info: Loading plugin "network"... Feb 07 17:23:20 music volumio[20421]: info: Refreshing Cached IP Addresses Feb 07 17:23:20 music sudo[20459]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 17:23:20 music sudo[20459]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:23:20 music sudo[20461]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 17:23:20 music sudo[20461]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:23:20 music volumio[20421]: info: Loading plugin "services"... Feb 07 17:23:20 music volumio[20421]: info: Loading plugin "alsa_controller"... Feb 07 17:23:20 music sudo[20459]: pam_unix(sudo:session): session closed for user root Feb 07 17:23:20 music sudo[20461]: pam_unix(sudo:session): session closed for user root Feb 07 17:23:20 music sudo[20468]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 07 17:23:20 music sudo[20468]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:23:20 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 17:23:20 music volumio[20421]: info: Loading plugin "wizard"... Feb 07 17:23:20 music volumio[20421]: info: Loading plugin "networkfs"... Feb 07 17:23:20 music volumio[20421]: info: Starting Udev Watcher for removable devices Feb 07 17:23:20 music go-librespot[20437]: time="2026-02-07T17:23:20-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 07 17:23:20 music volumio[20421]: info: Ignoring mount for partition: boot Feb 07 17:23:20 music volumio[20421]: info: Ignoring mount for partition: volumio Feb 07 17:23:20 music volumio[20421]: info: Ignoring mount for partition: volumio_data Feb 07 17:23:20 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 17:23:20 music volumio[20421]: info: Loading plugin "volumio_command_line_client"... Feb 07 17:23:20 music volumio[20421]: info: Loading plugin "upnp"... Feb 07 17:23:20 music volumio[20421]: info: [1770503000375] Starting Upmpd Daemon Feb 07 17:23:20 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 17:23:20 music volumio[20421]: info: Loading plugin "my_music"... Feb 07 17:23:20 music volumio[20421]: info: Loading plugin "mpd"... Feb 07 17:23:20 music go-librespot[20437]: time="2026-02-07T17:23:20-05:00" level=debug msg="completed keyexchange" Feb 07 17:23:20 music go-librespot[20437]: time="2026-02-07T17:23:20-05:00" level=debug msg="completed challenge" Feb 07 17:23:20 music go-librespot[20437]: time="2026-02-07T17:23:20-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:23:20 music volumio-remote-updater[31331]: [2026-02-07 17:23:20] [connect] Successful connection Feb 07 17:23:20 music volumio[20421]: info: Loading plugin "upnp_browser"... Feb 07 17:23:20 music sudo[20468]: pam_unix(sudo:session): session closed for user root Feb 07 17:23:21 music go-librespot[20437]: time="2026-02-07T17:23:21-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 07 17:23:21 music go-librespot[20437]: time="2026-02-07T17:23:21-05:00" level=debug msg="completed keyexchange" Feb 07 17:23:21 music go-librespot[20437]: time="2026-02-07T17:23:21-05:00" level=debug msg="completed challenge" Feb 07 17:23:21 music go-librespot[20437]: time="2026-02-07T17:23:21-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:23:22 music go-librespot[20437]: time="2026-02-07T17:23:22-05:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 17:23:22 music volumio[20421]: info: Starting UPNP Browser Feb 07 17:23:22 music volumio[20421]: info: Loading plugin "alarm-clock"... Feb 07 17:23:22 music go-librespot[20437]: time="2026-02-07T17:23:22-05:00" level=debug msg="completed keyexchange" Feb 07 17:23:22 music go-librespot[20437]: time="2026-02-07T17:23:22-05:00" level=debug msg="completed challenge" Feb 07 17:23:22 music volumio[20421]: info: Loading plugin "airplay_emulation"... Feb 07 17:23:22 music volumio[20421]: info: Starting Shairport Sync Feb 07 17:23:22 music volumio[20421]: info: Loading plugin "last_100"... Feb 07 17:23:22 music volumio[20421]: info: Loading plugin "webradio"... Feb 07 17:23:22 music go-librespot[20437]: time="2026-02-07T17:23:22-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:23:22 music go-librespot[20437]: time="2026-02-07T17:23:22-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 17:23:22 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 17:23:22 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 17:23:22 music volumio[20421]: info: Loading plugin "i2s_dacs"... Feb 07 17:23:22 music volumio[20421]: info: I2S DAC not set, start Auto-detection Feb 07 17:23:22 music volumio[20421]: info: Loading plugin "volumiodiscovery"... Feb 07 17:23:22 music volumio[20421]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 17:23:22 music volumio[20421]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 17:23:22 music volumio[20421]: *** WARNING *** For more information see Feb 07 17:23:22 music volumio[20421]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 17:23:22 music volumio[20421]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 17:23:22 music volumio[20421]: *** WARNING *** For more information see Feb 07 17:23:22 music node[20421]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 17:23:22 music node[20421]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 17:23:22 music node[20421]: *** WARNING *** For more information see Feb 07 17:23:22 music node[20421]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 17:23:22 music node[20421]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 17:23:22 music node[20421]: *** WARNING *** For more information see Feb 07 17:23:22 music volumio[20421]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 07 17:23:22 music volumio[20421]: info: Discovery: Started advertising with name: music Feb 07 17:23:22 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 17:23:22 music volumio[20421]: info: Loading plugin "spop"... Feb 07 17:23:23 music volumio[20421]: info: Loading plugin "outputs"... Feb 07 17:23:23 music volumio[20421]: info: Loading plugin "albumart"... Feb 07 17:23:23 music volumio[20421]: info: Plugin example_plugin is not enabled Feb 07 17:23:23 music volumio[20421]: info: Loading plugin "inputs"... Feb 07 17:23:23 music volumio[20421]: info: Loading plugin "updater_comm"... Feb 07 17:23:23 music volumio[20421]: info: Plugin mpdemulation is not enabled Feb 07 17:23:23 music volumio[20421]: info: Loading plugin "rest_api"... Feb 07 17:23:23 music volumio[20421]: info: Loading plugin "websocket"... Feb 07 17:23:23 music volumio[20421]: info: Starting Socket.io Server version 1.7.4 Feb 07 17:23:23 music volumio[20421]: info: Loading i18n strings for locale en Feb 07 17:23:24 music volumio[20421]: Updating browse sources language Feb 07 17:23:24 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 17:23:24 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 17:23:24 music volumio[20421]: info: CoreCommandRouter::initPlayerControls Feb 07 17:23:24 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:24 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:24 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:24 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:24 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:24 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:24 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:24 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:24 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 17:23:24 music volumio[20421]: Express server listening on port 3000 Feb 07 17:23:24 music volumio[20421]: [Metrics] WebUI: 6s 620.94ms Feb 07 17:23:24 music volumio[20421]: info: CoreStateMachine::resetVolumioState Feb 07 17:23:24 music volumio[20421]: info: CoreStateMachine::getcurrentVolume Feb 07 17:23:24 music volumio[20421]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 17:23:24 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 17:23:24 music volumio[20421]: info: Volumio Network Manager: Network status updated: 1 Feb 07 17:23:24 music volumio-remote-updater[31331]: [2026-02-07 17:23:24] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770503000 101 Feb 07 17:23:24 music volumio[20494]: Forking 3 albumart workers Feb 07 17:23:24 music volumio[20421]: 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 17:23:24 music volumio[20421]: info: VolumeController:: Volume=86 Mute =false Feb 07 17:23:24 music volumio[20421]: info: CoreStateMachine::pushState Feb 07 17:23:24 music volumio[20421]: info: CorePlayQueue::getTrack 0 Feb 07 17:23:24 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 17:23:24 music volumio[20421]: info: CoreCommandRouter::volumioPushState Feb 07 17:23:24 music volumio[20421]: info: CoreStateMachine::updateTrackBlock Feb 07 17:23:24 music volumio[20421]: info: CorePlayQueue::getTrackBlock Feb 07 17:23:24 music volumio[20421]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 17:23:24 music volumio[20421]: info: Reloading queue from file Feb 07 17:23:24 music volumio[20421]: info: CoreStateMachine::setRepeat null single undefined Feb 07 17:23:24 music volumio[20421]: info: CoreStateMachine::pushState Feb 07 17:23:24 music volumio[20421]: info: CorePlayQueue::getTrack 0 Feb 07 17:23:24 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 17:23:24 music volumio[20421]: info: CoreCommandRouter::volumioPushState Feb 07 17:23:24 music volumio[20421]: info: CoreStateMachine::setRandom null Feb 07 17:23:24 music volumio[20421]: info: CoreStateMachine::pushState Feb 07 17:23:24 music volumio[20421]: info: CorePlayQueue::getTrack 0 Feb 07 17:23:24 music volumio[20421]: info: CoreCommandRouter::volumioPushState Feb 07 17:23:24 music volumio[20421]: info: Setting Device type: Raspberry PI Feb 07 17:23:24 music volumio[20421]: info: VolumeController:: Volume=86 Mute =false Feb 07 17:23:24 music volumio[20421]: info: CoreStateMachine::pushState Feb 07 17:23:24 music volumio[20421]: info: CorePlayQueue::getTrack 0 Feb 07 17:23:24 music volumio[20421]: info: CoreCommandRouter::volumioPushState Feb 07 17:23:24 music volumio[20421]: info: Completed loading Core Plugins Feb 07 17:23:24 music volumio[20421]: info: Preparing to generate the ALSA configuration file Feb 07 17:23:24 music volumio[20421]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 07 17:23:24 music volumio[20421]: info: Discovery: Found device music Feb 07 17:23:24 music volumio[20421]: info: CoreCommandRouter::volumioGetState Feb 07 17:23:24 music volumio[20421]: info: CorePlayQueue::getTrack 0 Feb 07 17:23:24 music volumio[20421]: info: Asound.conf file unchanged, so no further update is needed Feb 07 17:23:24 music volumio[20421]: info: Output device has changed, restarting MPD Feb 07 17:23:24 music volumio[20421]: info: Output device has changed, restarting Shairport Sync Feb 07 17:23:24 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:24 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 17:23:24 music sudo[20550]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 17:23:24 music sudo[20550]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:23:24 music sudo[20550]: pam_unix(sudo:session): session closed for user root Feb 07 17:23:24 music sudo[20551]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 17:23:24 music sudo[20551]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:23:24 music volumio[20421]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 17:23:24 music volumio[20421]: info: ___________ START PLUGINS ___________ Feb 07 17:23:24 music volumio[20421]: info: ControllerMpd::onStart: Initializing MPD Feb 07 17:23:24 music volumio[20421]: info: Creating MPD Configuration file Feb 07 17:23:24 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 17:23:24 music volumio[20421]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 17:23:24 music volumio[20421]: info: [1770503004844] CoreMusicLibrary::Adding element Media Servers Feb 07 17:23:24 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 17:23:24 music volumio[20421]: info: UPNP Browser: Client initialized successfully Feb 07 17:23:24 music systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 07 17:23:24 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:24 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 17:23:24 music sudo[20561]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 17:23:24 music sudo[20561]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:23:24 music sudo[20559]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 17:23:24 music volumio[20421]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 17:23:24 music sudo[20559]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:23:24 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:24 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 17:23:24 music systemd[1]: mpd.service: Deactivated successfully. Feb 07 17:23:24 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 17:23:24 music systemd[1]: mpd.service: Consumed 4.181s CPU time. Feb 07 17:23:24 music systemd[1]: mpd.socket: Deactivated successfully. Feb 07 17:23:24 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 17:23:24 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 17:23:24 music sudo[20559]: pam_unix(sudo:session): session closed for user root Feb 07 17:23:25 music volumio[20421]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 17:23:25 music volumio[20421]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 17:23:25 music volumio[20421]: info: [1770503005009] CoreMusicLibrary::Adding element Last_100 Feb 07 17:23:25 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 17:23:25 music volumio[20421]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 17:23:25 music volumio[20421]: info: [1770503005021] CoreMusicLibrary::Adding element Webradio Feb 07 17:23:25 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 17:23:25 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 17:23:25 music volumio[20421]: info: Initializing BBC Radios Feb 07 17:23:25 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 17:23:25 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 17:23:25 music systemd[1]: mpd.service: Deactivated successfully. Feb 07 17:23:25 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 17:23:25 music systemd[1]: mpd.socket: Deactivated successfully. Feb 07 17:23:25 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 17:23:25 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 17:23:25 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 17:23:25 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 17:23:25 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 17:23:25 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 17:23:25 music volumio[20421]: info: Creating Spotify config file Feb 07 17:23:25 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:25 music sudo[20588]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 07 17:23:25 music sudo[20588]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 07 17:23:25 music sudo[20588]: pam_unix(sudo:session): session closed for user root Feb 07 17:23:25 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 07 17:23:25 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 17:23:25 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 17:23:25 music go-librespot[20591]: go-librespot daemon starting... Feb 07 17:23:25 music go-librespot[20592]: time="2026-02-07T17:23:25-05:00" level=info msg="running go-librespot 0.6.2" Feb 07 17:23:25 music volumio[20421]: info: Volumio Calling Home Feb 07 17:23:26 music go-librespot[20592]: time="2026-02-07T17:23:26-05:00" level=info msg="zeroconf server listening on port 33919" Feb 07 17:23:26 music volumio[20509]: Starting albumart workers Feb 07 17:23:26 music volumio[20511]: Starting albumart workers Feb 07 17:23:26 music volumio[20510]: Starting albumart workers Feb 07 17:23:26 music volumio[20421]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 07 17:23:26 music volumio[20421]: info: Discovery: Found device music Feb 07 17:23:26 music volumio[20421]: info: CoreCommandRouter::volumioGetState Feb 07 17:23:26 music volumio[20421]: info: CorePlayQueue::getTrack 0 Feb 07 17:23:26 music volumio[20421]: info: MPD Permissions set Feb 07 17:23:26 music volumio[20421]: info: MPD Permissions set Feb 07 17:23:26 music volumio[20421]: info: Spotify config file written Feb 07 17:23:26 music volumio[20421]: info: CoreCommandRouter::volumioGetState Feb 07 17:23:26 music volumio[20421]: info: CorePlayQueue::getTrack 0 Feb 07 17:23:26 music sudo[20605]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 07 17:23:26 music sudo[20605]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:23:26 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 07 17:23:26 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 07 17:23:26 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 17:23:27 music volumio[20421]: 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 17:23:27 music volumio[20421]: info: Volumio called home Feb 07 17:23:27 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 17:23:27 music go-librespot[20607]: go-librespot daemon starting... Feb 07 17:23:27 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:27 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:27 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:27 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:27 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:27 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:27 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:27 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:27 music sudo[20605]: pam_unix(sudo:session): session closed for user root Feb 07 17:23:27 music go-librespot[20608]: time="2026-02-07T17:23:27-05:00" level=info msg="running go-librespot 0.6.2" Feb 07 17:23:27 music go-librespot[20608]: time="2026-02-07T17:23:27-05:00" level=debug msg="app state loaded" Feb 07 17:23:27 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 17:23:27 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:27 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:27 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:27 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:27 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:27 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:27 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:27 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:27 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:27 music go-librespot[20608]: time="2026-02-07T17:23:27-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 17:23:27 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 17:23:27 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 17:23:27 music volumio[20421]: info: No need to fix Spotify hosts Feb 07 17:23:27 music go-librespot[20608]: time="2026-02-07T17:23:27-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 17:23:27 music go-librespot[20608]: time="2026-02-07T17:23:27-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 17:23:27 music go-librespot[20608]: time="2026-02-07T17:23:27-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 17:23:27 music go-librespot[20608]: time="2026-02-07T17:23:27-05:00" level=info msg="zeroconf server listening on port 42911" Feb 07 17:23:27 music volumio[20421]: info: Listing playlists Feb 07 17:23:27 music volumio[20421]: info: Listing playlists Feb 07 17:23:27 music go-librespot[20608]: time="2026-02-07T17:23:27-05:00" level=debug msg="obtained new client token: AAAozUeu9lHkj5VkGrMIoe8B8hd04W+g6r1MdXoc51+eC0ASQWHzQ1jyLoHULYMGFiog7qzrGDFwAahRqqxbNkTYjKZ5okApB6+/Ml4zSypX/02TRQJISPDsecLfSXraaoz8LPswN2FJkzQOs3LbxYHpX6p2WLoD4N57KYL7lt9CtJ3SGyWDNFutmRoz32hWGjuQI5FmUkBFwaX0S0M3F6ZISRkLcFoin/UvZCHVtu1Z7jhrgmR7u2U=" Feb 07 17:23:27 music go-librespot[20608]: time="2026-02-07T17:23:27-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 17:23:27 music volumio[20421]: info: Starting Shairport Sync Feb 07 17:23:27 music go-librespot[20608]: time="2026-02-07T17:23:27-05:00" level=debug msg="completed keyexchange" Feb 07 17:23:27 music go-librespot[20608]: time="2026-02-07T17:23:27-05:00" level=debug msg="completed challenge" Feb 07 17:23:27 music volumio[20421]: info: Starting Shairport Sync Feb 07 17:23:27 music volumio[20421]: info: Starting Shairport Sync Feb 07 17:23:27 music sudo[20648]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 17:23:28 music sudo[20648]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:23:28 music volumio[20421]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 07 17:23:28 music sudo[20652]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 17:23:28 music sudo[20652]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:23:28 music go-librespot[20608]: time="2026-02-07T17:23:28-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:23:28 music sudo[20650]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 17:23:28 music sudo[20650]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:23:28 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 07 17:23:28 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 07 17:23:28 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 17:23:28 music systemd[1]: shairport-sync.service: Consumed 1.874s CPU time. Feb 07 17:23:28 music volumio[20421]: info: CoreCommandRouter::volumioGetState Feb 07 17:23:28 music volumio[20421]: info: CorePlayQueue::getTrack 0 Feb 07 17:23:28 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 17:23:28 music sudo[20652]: pam_unix(sudo:session): session closed for user root Feb 07 17:23:28 music sudo[20648]: pam_unix(sudo:session): session closed for user root Feb 07 17:23:28 music sudo[20650]: pam_unix(sudo:session): session closed for user root Feb 07 17:23:28 music volumio[20421]: info: Shairport-Sync Started Feb 07 17:23:28 music volumio[20421]: Error adding Membership: Error: addMembership EINVAL Feb 07 17:23:28 music volumio[20421]: info: Shairport-Sync Started Feb 07 17:23:28 music volumio[20421]: info: Shairport-Sync Started Feb 07 17:23:28 music go-librespot[20608]: time="2026-02-07T17:23:28-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 17:23:28 music go-librespot[20608]: time="2026-02-07T17:23:28-05:00" level=debug msg="completed keyexchange" Feb 07 17:23:28 music go-librespot[20608]: time="2026-02-07T17:23:28-05:00" level=debug msg="completed challenge" Feb 07 17:23:28 music go-librespot[20608]: time="2026-02-07T17:23:28-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:23:29 music go-librespot[20608]: time="2026-02-07T17:23:29-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 07 17:23:29 music go-librespot[20608]: time="2026-02-07T17:23:29-05:00" level=debug msg="completed keyexchange" Feb 07 17:23:29 music go-librespot[20608]: time="2026-02-07T17:23:29-05:00" level=debug msg="completed challenge" Feb 07 17:23:29 music go-librespot[20608]: time="2026-02-07T17:23:29-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:23:29 music mpd[20590]: 2026-02-07T17:23:29 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 07 17:23:29 music systemd[1]: Started mpd.service - Music Player Daemon. Feb 07 17:23:29 music sudo[20551]: pam_unix(sudo:session): session closed for user root Feb 07 17:23:29 music sudo[20561]: pam_unix(sudo:session): session closed for user root Feb 07 17:23:29 music volumio[20421]: info: Completed starting Core Plugins Feb 07 17:23:29 music volumio[20421]: info: ------------------------------------------- Feb 07 17:23:29 music volumio[20421]: info: ----- MyVolumio plugins startup ---- Feb 07 17:23:29 music volumio[20421]: info: ------------------------------------------- Feb 07 17:23:29 music volumio[20421]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 07 17:23:29 music volumio[20421]: error: MPD error: The expression evaluated to a falsy value: Feb 07 17:23:29 music volumio[20421]: assert.ok(self.idling) Feb 07 17:23:29 music volumio[20421]: error: The expression evaluated to a falsy value: Feb 07 17:23:29 music volumio[20421]: assert.ok(self.idling) Feb 07 17:23:29 music volumio[20421]: info: MPD running with PID20590 Feb 07 17:23:29 music volumio[20421]: ,establishing connection Feb 07 17:23:29 music volumio[20421]: error: updateQueue error: null Feb 07 17:23:29 music volumio[20421]: error: updateQueue error: null Feb 07 17:23:29 music go-librespot[20608]: time="2026-02-07T17:23:29-05:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Feb 07 17:23:30 music go-librespot[20608]: time="2026-02-07T17:23:30-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 17:23:30 music go-librespot[20608]: time="2026-02-07T17:23:30-05:00" level=debug msg="completed keyexchange" Feb 07 17:23:30 music go-librespot[20608]: time="2026-02-07T17:23:30-05:00" level=debug msg="completed challenge" Feb 07 17:23:30 music go-librespot[20608]: time="2026-02-07T17:23:30-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:23:30 music sudo[20692]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 17:23:30 music sudo[20692]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:23:30 music sudo[20692]: pam_unix(sudo:session): session closed for user root Feb 07 17:23:30 music sudo[20694]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 17:23:30 music sudo[20694]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:23:30 music sudo[20694]: pam_unix(sudo:session): session closed for user root Feb 07 17:23:30 music sudo[20697]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 07 17:23:30 music sudo[20697]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:23:30 music sudo[20697]: pam_unix(sudo:session): session closed for user root Feb 07 17:23:30 music volumio[20421]: info: Upmpdcli Daemon Started Feb 07 17:23:30 music volumio[20421]: info: go-librespot daemon successfully initialized Feb 07 17:23:30 music go-librespot[20608]: time="2026-02-07T17:23:30-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 07 17:23:31 music go-librespot[20608]: time="2026-02-07T17:23:31-05:00" level=debug msg="completed keyexchange" Feb 07 17:23:31 music go-librespot[20608]: time="2026-02-07T17:23:31-05:00" level=debug msg="completed challenge" Feb 07 17:23:32 music go-librespot[20608]: time="2026-02-07T17:23:32-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:23:32 music sudo[20701]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 07 17:23:32 music sudo[20701]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:23:32 music sudo[20703]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 07 17:23:32 music sudo[20703]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:23:32 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 07 17:23:32 music systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 07 17:23:32 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 07 17:23:32 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 07 17:23:32 music sudo[20701]: pam_unix(sudo:session): session closed for user root Feb 07 17:23:32 music sudo[20703]: pam_unix(sudo:session): session closed for user root Feb 07 17:23:32 music mpd_monitor.sh[20706]: MPD Monitor Service: Starting MPD Monitor Service Feb 07 17:23:32 music volumio[20421]: info: Successfully started MPD Monitor Feb 07 17:23:32 music volumio[20421]: info: Successfully started MPD Monitor Feb 07 17:23:32 music go-librespot[20608]: time="2026-02-07T17:23:32-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 17:23:33 music go-librespot[20608]: time="2026-02-07T17:23:33-05:00" level=debug msg="completed keyexchange" Feb 07 17:23:33 music go-librespot[20608]: time="2026-02-07T17:23:33-05:00" level=debug msg="completed challenge" Feb 07 17:23:33 music go-librespot[20608]: time="2026-02-07T17:23:33-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:23:33 music go-librespot[20608]: time="2026-02-07T17:23: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 17:23:33 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 17:23:33 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 17:23:33 music volumio[20421]: info: Initializing connection to go-librespot Websocket Feb 07 17:23:33 music volumio[20421]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 17:23:34 music volumio[20421]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 07 17:23:35 music volumio[20421]: info: CoreCommandRouter::volumioGetState Feb 07 17:23:35 music volumio[20421]: info: CorePlayQueue::getTrack 0 Feb 07 17:23:36 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 07 17:23:36 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 17:23:36 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 17:23:36 music go-librespot[20710]: go-librespot daemon starting... Feb 07 17:23:36 music go-librespot[20711]: time="2026-02-07T17:23:36-05:00" level=info msg="running go-librespot 0.6.2" Feb 07 17:23:36 music go-librespot[20711]: time="2026-02-07T17:23:36-05:00" level=debug msg="app state loaded" Feb 07 17:23:36 music go-librespot[20711]: time="2026-02-07T17:23:36-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 17:23:36 music go-librespot[20711]: time="2026-02-07T17:23:36-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 17:23:36 music go-librespot[20711]: time="2026-02-07T17:23:36-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 17:23:36 music go-librespot[20711]: time="2026-02-07T17:23:36-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 17:23:36 music go-librespot[20711]: time="2026-02-07T17:23:36-05:00" level=info msg="zeroconf server listening on port 34973" Feb 07 17:23:36 music go-librespot[20711]: time="2026-02-07T17:23:36-05:00" level=debug msg="obtained new client token: AAARWbi+dx5hdyOYVJMBsh9y39ZxpAqZpTvN+oAx3iGVQQtXqOUbVWv4+SILvPslV2QyhWhzv7N/TdXnm1pV2+3tvdpiO79OqtJyexldbgqqDiVtO5PiqTBu2dKoBT1fpoxGYrhfdI0d3ST9kCEQsBmtyWV6NZUfv/oTDWv4KFsQtAfVnDxtFVLCc9kMhes2yHSHnMxSs6AGYdhKk6T3mVpsZSOVor/54kYHbCasm+Y6IctGqw3xCiY=" Feb 07 17:23:36 music go-librespot[20711]: time="2026-02-07T17:23:36-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 17:23:36 music volumio[20421]: info: Initializing connection to go-librespot Websocket Feb 07 17:23:36 music go-librespot[20711]: time="2026-02-07T17:23:36-05:00" level=debug msg="new websocket client" Feb 07 17:23:36 music volumio[20421]: info: Connection to go-librespot Websocket established Feb 07 17:23:37 music go-librespot[20711]: time="2026-02-07T17:23:37-05:00" level=debug msg="completed keyexchange" Feb 07 17:23:37 music go-librespot[20711]: time="2026-02-07T17:23:37-05:00" level=debug msg="completed challenge" Feb 07 17:23:37 music go-librespot[20711]: time="2026-02-07T17:23:37-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:23:37 music go-librespot[20711]: time="2026-02-07T17:23:37-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 17:23:37 music go-librespot[20711]: time="2026-02-07T17:23:37-05:00" level=debug msg="completed keyexchange" Feb 07 17:23:37 music go-librespot[20711]: time="2026-02-07T17:23:37-05:00" level=debug msg="completed challenge" Feb 07 17:23:37 music go-librespot[20711]: time="2026-02-07T17:23:37-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:23:37 music volumio[20421]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 07 17:23:37 music volumio[20421]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 07 17:23:37 music volumio[20421]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 07 17:23:37 music volumio[20421]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 07 17:23:37 music volumio[20421]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 07 17:23:37 music volumio[20421]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 07 17:23:37 music volumio[20421]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 07 17:23:37 music volumio[20421]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 07 17:23:37 music volumio[20421]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 07 17:23:37 music volumio[20421]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 07 17:23:37 music volumio[20421]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 07 17:23:37 music volumio[20421]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 07 17:23:37 music volumio[20421]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 07 17:23:37 music volumio[20421]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 07 17:23:37 music volumio[20421]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 07 17:23:37 music volumio[20421]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 07 17:23:37 music volumio[20421]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 07 17:23:37 music volumio[20421]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 07 17:23:37 music volumio[20421]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 07 17:23:37 music volumio[20421]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 07 17:23:37 music volumio[20421]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 07 17:23:37 music volumio[20421]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 07 17:23:37 music volumio[20421]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 07 17:23:37 music volumio[20421]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 07 17:23:37 music volumio[20421]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 07 17:23:37 music volumio[20421]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 07 17:23:37 music volumio[20421]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 07 17:23:37 music volumio[20421]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 07 17:23:37 music volumio[20421]: info: Adding plugin bluetooth to MyMusic Plugins Feb 07 17:23:37 music volumio[20421]: info: Adding plugin multiroom to MyMusic Plugins Feb 07 17:23:37 music volumio[20421]: info: Adding plugin metavolumio to MyMusic Plugins Feb 07 17:23:37 music volumio[20421]: info: Adding plugin cd_controller to MyMusic Plugins Feb 07 17:23:37 music volumio[20421]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 07 17:23:37 music volumio[20421]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 07 17:23:37 music volumio[20421]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 07 17:23:37 music volumio[20421]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 07 17:23:38 music go-librespot[20711]: time="2026-02-07T17:23:38-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 17:23:38 music go-librespot[20711]: time="2026-02-07T17:23:38-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 07 17:23:38 music go-librespot[20711]: time="2026-02-07T17:23:38-05:00" level=debug msg="completed keyexchange" Feb 07 17:23:38 music go-librespot[20711]: time="2026-02-07T17:23:38-05:00" level=debug msg="completed challenge" Feb 07 17:23:38 music go-librespot[20711]: time="2026-02-07T17:23:38-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:23:38 music volumio[20421]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 07 17:23:38 music volumio[20421]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 07 17:23:38 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 17:23:38 music volumio[20421]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 17:23:38 music volumio[20421]: info: Starting MyVolumio Remote Streaming Endpoints Feb 07 17:23:39 music volumio[20421]: info: MyVolumio login type: Token Feb 07 17:23:39 music volumio[20421]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 07 17:23:39 music volumio[20421]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 07 17:23:39 music go-librespot[20711]: time="2026-02-07T17:23:39-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 07 17:23:39 music go-librespot[20711]: time="2026-02-07T17:23:39-05:00" level=debug msg="completed keyexchange" Feb 07 17:23:39 music go-librespot[20711]: time="2026-02-07T17:23:39-05:00" level=debug msg="completed challenge" Feb 07 17:23:39 music go-librespot[20711]: time="2026-02-07T17:23:39-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:23:39 music volumio[20421]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 07 17:23:39 music volumio[20421]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 07 17:23:39 music volumio[20421]: info: Streaming services startup Feb 07 17:23:39 music volumio[20421]: info: Starting Streaming Daemon Feb 07 17:23:39 music sudo[20721]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 07 17:23:39 music sudo[20721]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:23:40 music volumio[20421]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 07 17:23:40 music sudo[20721]: pam_unix(sudo:session): session closed for user root Feb 07 17:23:40 music volumio[20421]: info: Getting Spotify volume Feb 07 17:23:40 music volumio[20421]: error: Cannot start Volumio Streaming Daemon Feb 07 17:23:40 music volumio[20421]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 07 17:23:40 music volumio[20421]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 07 17:23:40 music volumio[20421]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 07 17:23:40 music go-librespot[20711]: time="2026-02-07T17:23:40-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 07 17:23:40 music volumio[20421]: info: CoreCommandRouter::volumioGetState Feb 07 17:23:40 music volumio[20421]: info: CorePlayQueue::getTrack 0 Feb 07 17:23:40 music volumio[20421]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Feb 07 17:23:40 music volumio[20421]: SPOTIFY: SPOTIFY VOLUME undefined Feb 07 17:23:40 music volumio[20421]: SPOTIFY: VOLUMIO VOLUME 86 Feb 07 17:23:40 music volumio[20421]: info: Aligning Spotify Volume to Volumio Volume Feb 07 17:23:40 music volumio[20421]: info: CoreCommandRouter::volumioGetState Feb 07 17:23:40 music volumio[20421]: info: CorePlayQueue::getTrack 0 Feb 07 17:23:40 music volumio[20421]: info: Setting Spotify Volume from Volumio: 86 Feb 07 17:23:40 music go-librespot[20711]: time="2026-02-07T17:23:40-05:00" level=debug msg="completed keyexchange" Feb 07 17:23:40 music go-librespot[20711]: time="2026-02-07T17:23:40-05:00" level=debug msg="completed challenge" Feb 07 17:23:40 music go-librespot[20711]: time="2026-02-07T17:23:40-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:23:40 music volumio[20421]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 07 17:23:40 music volumio[20421]: info: MyVolumio token set successfully Feb 07 17:23:40 music volumio[20421]: info: MYVOLUMIO: Adding device Feb 07 17:23:40 music volumio[20421]: info: MYVOLUMIO: Evaluating Server Feb 07 17:23:41 music go-librespot[20711]: time="2026-02-07T17:23:41-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 17:23:41 music volumio[20421]: info: MyVolumio status changed Feb 07 17:23:41 music volumio[20421]: info: Streaming services startup Feb 07 17:23:41 music volumio[20421]: info: Starting Streaming Daemon Feb 07 17:23:41 music volumio[20421]: info: Removing browser output: myVolumio user plan is not superstar Feb 07 17:23:41 music volumio[20421]: info: Removing audio output: Feb 07 17:23:41 music volumio[20421]: info: Stoppping Tunnel 1 Feb 07 17:23:41 music go-librespot[20711]: time="2026-02-07T17:23:41-05:00" level=debug msg="completed keyexchange" Feb 07 17:23:41 music go-librespot[20711]: time="2026-02-07T17:23:41-05:00" level=debug msg="completed challenge" Feb 07 17:23:41 music sudo[20763]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 07 17:23:41 music sudo[20763]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:23:41 music sudo[20765]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 07 17:23:41 music sudo[20765]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 17:23:41 music go-librespot[20711]: time="2026-02-07T17:23:41-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 17:23:41 music go-librespot[20711]: time="2026-02-07T17:23: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 17:23:41 music volumio[20421]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 17:23:41 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 17:23:41 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 17:23:41 music volumio[20421]: Error: socket hang up Feb 07 17:23:41 music volumio[20421]: at connResetException (node:internal/errors:720:14) Feb 07 17:23:41 music volumio[20421]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 07 17:23:41 music volumio[20421]: at Socket.emit (node:events:526:35) Feb 07 17:23:41 music volumio[20421]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 07 17:23:41 music volumio[20421]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 07 17:23:41 music volumio[20421]: code: 'ECONNRESET', Feb 07 17:23:41 music volumio[20421]: response: undefined Feb 07 17:23:41 music volumio[20421]: } Feb 07 17:23:41 music volumio[20421]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 17:23:41 music systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 07 17:23:41 music systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 07 17:23:41 music sudo[20763]: pam_unix(sudo:session): session closed for user root Feb 07 17:23:41 music systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 07 17:23:41 music systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 07 17:23:41 music systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 07 17:23:41 music systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 07 17:23:41 music sudo[20765]: pam_unix(sudo:session): session closed for user root Feb 07 17:23:42 music sudo[20782]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-07 17:22' Feb 07 17:23:42 music sudo[20782]: 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"