Feb 09 18:22:00 music volumio-remote-updater[30265]: [2026-02-09 18:22:00] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 09 18:22:00 music volumio-remote-updater[30265]: [2026-02-09 18:22:00] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 09 18:22:00 music systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 09 18:22:00 music systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 09 18:22:00 music systemd[1]: volumio.service: Consumed 26.861s CPU time. Feb 09 18:22:00 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 09 18:22:00 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 09 18:22:00 music systemd[1]: volumio.service: Scheduled restart job, restart counter is at 53184. Feb 09 18:22:00 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 09 18:22:00 music systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 09 18:22:00 music systemd[1]: volumio.service: Consumed 26.861s CPU time. Feb 09 18:22:00 music systemd[1]: Started volumio.service - Volumio Backend Module. Feb 09 18:22:00 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 09 18:22:01 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 09 18:22:01 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 18:22:01 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 18:22:01 music go-librespot[27147]: go-librespot daemon starting... Feb 09 18:22:01 music go-librespot[27148]: time="2026-02-09T18:22:01-05:00" level=info msg="running go-librespot 0.6.2" Feb 09 18:22:01 music go-librespot[27148]: time="2026-02-09T18:22:01-05:00" level=debug msg="app state loaded" Feb 09 18:22:01 music go-librespot[27148]: time="2026-02-09T18:22:01-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 18:22:01 music go-librespot[27148]: time="2026-02-09T18:22: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-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 18:22:01 music go-librespot[27148]: time="2026-02-09T18:22:01-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 09 18:22:01 music go-librespot[27148]: time="2026-02-09T18:22:01-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 09 18:22:02 music go-librespot[27148]: time="2026-02-09T18:22:02-05:00" level=info msg="zeroconf server listening on port 37577" Feb 09 18:22:02 music go-librespot[27148]: time="2026-02-09T18:22:02-05:00" level=debug msg="obtained new client token: AAC9eM/NxnNyJuGaD9sL4aBjAYSgooBwDrXXpPcWT9l7wV/SijRLHCBn0cJGcWwaHmHaBNqPrGgr6N8KymOa1eilAh0Gypt7s/JACalwh6PRlppqRTFr79b+qeIqcsT4yozaRBy9PR8IXmLDHkYD6mAUFdPrnYdpFnOPbXsUej1uo5QrjL8LdMgqyCnnKoIRVRkSEf5+WWb4zK+IvCazzq21h9024KI9r0RliqDzmIQzaaiFMNnM" Feb 09 18:22:02 music go-librespot[27148]: time="2026-02-09T18:22:02-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 09 18:22:02 music go-librespot[27148]: time="2026-02-09T18:22:02-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:02 music go-librespot[27148]: time="2026-02-09T18:22:02-05:00" level=debug msg="completed challenge" Feb 09 18:22:02 music go-librespot[27148]: time="2026-02-09T18:22:02-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:02 music volumio[27132]: info: ------------------------------------------- Feb 09 18:22:02 music volumio[27132]: info: ----- Volumio3 ---- Feb 09 18:22:02 music volumio[27132]: info: ------------------------------------------- Feb 09 18:22:02 music volumio[27132]: info: ----- System startup ---- Feb 09 18:22:02 music volumio[27132]: info: ------------------------------------------- Feb 09 18:22:02 music go-librespot[27148]: time="2026-02-09T18:22:02-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 09 18:22:03 music go-librespot[27148]: time="2026-02-09T18:22:03-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:03 music go-librespot[27148]: time="2026-02-09T18:22:03-05:00" level=debug msg="completed challenge" Feb 09 18:22:03 music go-librespot[27148]: time="2026-02-09T18:22:03-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:03 music go-librespot[27148]: time="2026-02-09T18:22:03-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 09 18:22:03 music volumio[27132]: info: MYVOLUMIO Environment detected Feb 09 18:22:03 music go-librespot[27148]: time="2026-02-09T18:22:03-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:03 music go-librespot[27148]: time="2026-02-09T18:22:03-05:00" level=debug msg="completed challenge" Feb 09 18:22:03 music volumio[27132]: info: Plugin folders cleanup Feb 09 18:22:03 music volumio[27132]: info: Scanning into folder /volumio/app/plugins/ Feb 09 18:22:03 music volumio[27132]: info: Scanning category audio_interface Feb 09 18:22:03 music volumio[27132]: info: Scanning category miscellanea Feb 09 18:22:03 music volumio[27132]: info: Scanning category music_service Feb 09 18:22:03 music volumio[27132]: info: Scanning category plugins.json Feb 09 18:22:03 music volumio[27132]: info: Scanning category system_controller Feb 09 18:22:03 music volumio[27132]: info: Scanning category user_interface Feb 09 18:22:03 music volumio[27132]: info: Scanning into folder /data/plugins/ Feb 09 18:22:03 music volumio[27132]: info: Scanning category music_service Feb 09 18:22:03 music volumio[27132]: info: Plugin folders cleanup completed Feb 09 18:22:03 music volumio[27132]: info: ------------------------------------------- Feb 09 18:22:03 music volumio[27132]: info: ----- Core plugins startup ---- Feb 09 18:22:03 music volumio[27132]: info: ------------------------------------------- Feb 09 18:22:03 music volumio[27132]: info: Loading plugins from folder /volumio/app/plugins/ Feb 09 18:22:03 music volumio[27132]: info: Adding plugin upnp to MyMusic Plugins Feb 09 18:22:03 music volumio[27132]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 09 18:22:03 music volumio[27132]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 09 18:22:03 music volumio[27132]: info: Loading plugins from folder /data/plugins/ Feb 09 18:22:03 music go-librespot[27148]: time="2026-02-09T18:22:03-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:03 music volumio[27132]: info: Loading plugin "system"... Feb 09 18:22:03 music volumio[27132]: info: Loading plugin "appearance"... Feb 09 18:22:04 music go-librespot[27148]: time="2026-02-09T18:22:04-05:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 18:22:04 music go-librespot[27148]: time="2026-02-09T18:22:04-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:04 music go-librespot[27148]: time="2026-02-09T18:22:04-05:00" level=debug msg="completed challenge" Feb 09 18:22:04 music volumio[27132]: info: Loading plugin "network"... Feb 09 18:22:04 music go-librespot[27148]: time="2026-02-09T18:22:04-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:04 music volumio[27132]: info: Refreshing Cached IP Addresses Feb 09 18:22:04 music sudo[27171]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 18:22:04 music sudo[27171]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:04 music sudo[27171]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:04 music sudo[27173]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 18:22:04 music sudo[27173]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:04 music volumio[27132]: info: Loading plugin "services"... Feb 09 18:22:04 music sudo[27173]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:04 music volumio[27132]: info: Loading plugin "alsa_controller"... Feb 09 18:22:05 music sudo[27181]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 09 18:22:05 music sudo[27181]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:05 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 18:22:05 music volumio[27132]: info: Loading plugin "wizard"... Feb 09 18:22:05 music volumio[27132]: info: Loading plugin "networkfs"... Feb 09 18:22:05 music volumio[27132]: info: Starting Udev Watcher for removable devices Feb 09 18:22:05 music volumio[27132]: info: Ignoring mount for partition: boot Feb 09 18:22:05 music volumio[27132]: info: Ignoring mount for partition: volumio Feb 09 18:22:05 music volumio[27132]: info: Ignoring mount for partition: volumio_data Feb 09 18:22:05 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 18:22:05 music volumio[27132]: info: Loading plugin "volumio_command_line_client"... Feb 09 18:22:05 music volumio[27132]: info: Loading plugin "upnp"... Feb 09 18:22:05 music volumio[27132]: info: [1770679325163] Starting Upmpd Daemon Feb 09 18:22:05 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 18:22:05 music volumio[27132]: info: Loading plugin "my_music"... Feb 09 18:22:05 music volumio[27132]: info: Loading plugin "mpd"... Feb 09 18:22:05 music volumio[27132]: info: Loading plugin "upnp_browser"... Feb 09 18:22:05 music go-librespot[27148]: time="2026-02-09T18:22:05-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 09 18:22:05 music volumio-remote-updater[30265]: [2026-02-09 18:22:05] [connect] Successful connection Feb 09 18:22:05 music sudo[27181]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:05 music go-librespot[27148]: time="2026-02-09T18:22:05-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:05 music go-librespot[27148]: time="2026-02-09T18:22:05-05:00" level=debug msg="completed challenge" Feb 09 18:22:05 music go-librespot[27148]: time="2026-02-09T18:22:05-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:06 music go-librespot[27148]: time="2026-02-09T18:22:06-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 09 18:22:06 music go-librespot[27148]: time="2026-02-09T18:22:06-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:06 music go-librespot[27148]: time="2026-02-09T18:22:06-05:00" level=debug msg="completed challenge" Feb 09 18:22:06 music go-librespot[27148]: time="2026-02-09T18:22:06-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:06 music go-librespot[27148]: time="2026-02-09T18:22: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 09 18:22:06 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 18:22:06 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 18:22:07 music volumio[27132]: info: Starting UPNP Browser Feb 09 18:22:07 music volumio[27132]: info: Loading plugin "alarm-clock"... Feb 09 18:22:07 music volumio[27132]: info: Loading plugin "airplay_emulation"... Feb 09 18:22:07 music volumio[27132]: info: Starting Shairport Sync Feb 09 18:22:07 music volumio[27132]: info: Loading plugin "last_100"... Feb 09 18:22:07 music volumio[27132]: info: Loading plugin "webradio"... Feb 09 18:22:07 music volumio[27132]: info: Loading plugin "i2s_dacs"... Feb 09 18:22:07 music volumio[27132]: info: I2S DAC not set, start Auto-detection Feb 09 18:22:07 music volumio[27132]: info: Loading plugin "volumiodiscovery"... Feb 09 18:22:07 music volumio[27132]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 18:22:07 music volumio[27132]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 18:22:07 music volumio[27132]: *** WARNING *** For more information see Feb 09 18:22:07 music volumio[27132]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 18:22:07 music volumio[27132]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 18:22:07 music volumio[27132]: *** WARNING *** For more information see Feb 09 18:22:07 music node[27132]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 18:22:07 music node[27132]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 18:22:07 music node[27132]: *** WARNING *** For more information see Feb 09 18:22:07 music node[27132]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 18:22:07 music node[27132]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 18:22:07 music node[27132]: *** WARNING *** For more information see Feb 09 18:22:07 music volumio[27132]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 09 18:22:07 music volumio[27132]: info: Discovery: Started advertising with name: music Feb 09 18:22:07 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 18:22:07 music volumio[27132]: info: Loading plugin "spop"... Feb 09 18:22:08 music volumio[27132]: info: Loading plugin "outputs"... Feb 09 18:22:08 music volumio[27132]: info: Loading plugin "albumart"... Feb 09 18:22:08 music volumio[27132]: info: Plugin example_plugin is not enabled Feb 09 18:22:08 music volumio[27132]: info: Loading plugin "inputs"... Feb 09 18:22:08 music volumio[27132]: info: Loading plugin "updater_comm"... Feb 09 18:22:08 music volumio[27132]: info: Plugin mpdemulation is not enabled Feb 09 18:22:08 music volumio[27132]: info: Loading plugin "rest_api"... Feb 09 18:22:08 music volumio[27132]: info: Loading plugin "websocket"... Feb 09 18:22:08 music volumio[27132]: info: Starting Socket.io Server version 1.7.4 Feb 09 18:22:08 music volumio[27132]: info: Loading i18n strings for locale en Feb 09 18:22:08 music volumio[27132]: Updating browse sources language Feb 09 18:22:08 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 18:22:08 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 18:22:08 music volumio[27132]: info: CoreCommandRouter::initPlayerControls Feb 09 18:22:08 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:08 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:08 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:08 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:08 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:08 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:08 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:08 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:08 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 18:22:08 music volumio[27132]: Express server listening on port 3000 Feb 09 18:22:08 music volumio[27132]: [Metrics] WebUI: 6s 575.86ms Feb 09 18:22:08 music volumio[27132]: info: CoreStateMachine::resetVolumioState Feb 09 18:22:08 music volumio[27132]: info: CoreStateMachine::getcurrentVolume Feb 09 18:22:08 music volumio[27132]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 18:22:09 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 18:22:09 music volumio[27132]: info: Volumio Network Manager: Network status updated: 1 Feb 09 18:22:09 music volumio-remote-updater[30265]: [2026-02-09 18:22:09] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770679325 101 Feb 09 18:22:09 music volumio[27206]: Forking 3 albumart workers Feb 09 18:22:09 music volumio[27132]: 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 09 18:22:09 music volumio[27132]: info: VolumeController:: Volume=86 Mute =false Feb 09 18:22:09 music volumio[27132]: info: CoreStateMachine::pushState Feb 09 18:22:09 music volumio[27132]: info: CorePlayQueue::getTrack 0 Feb 09 18:22:09 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 18:22:09 music volumio[27132]: info: CoreCommandRouter::volumioPushState Feb 09 18:22:09 music volumio[27132]: info: CoreStateMachine::updateTrackBlock Feb 09 18:22:09 music volumio[27132]: info: CorePlayQueue::getTrackBlock Feb 09 18:22:09 music volumio[27132]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 18:22:09 music volumio[27132]: info: Reloading queue from file Feb 09 18:22:09 music volumio[27132]: info: CoreStateMachine::setRepeat null single undefined Feb 09 18:22:09 music volumio[27132]: info: CoreStateMachine::pushState Feb 09 18:22:09 music volumio[27132]: info: CorePlayQueue::getTrack 0 Feb 09 18:22:09 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 18:22:09 music volumio[27132]: info: CoreCommandRouter::volumioPushState Feb 09 18:22:09 music volumio[27132]: info: CoreStateMachine::setRandom null Feb 09 18:22:09 music volumio[27132]: info: CoreStateMachine::pushState Feb 09 18:22:09 music volumio[27132]: info: CorePlayQueue::getTrack 0 Feb 09 18:22:09 music volumio[27132]: info: CoreCommandRouter::volumioPushState Feb 09 18:22:09 music volumio[27132]: info: Setting Device type: Raspberry PI Feb 09 18:22:09 music volumio[27132]: info: VolumeController:: Volume=86 Mute =false Feb 09 18:22:09 music volumio[27132]: info: CoreStateMachine::pushState Feb 09 18:22:09 music volumio[27132]: info: CorePlayQueue::getTrack 0 Feb 09 18:22:09 music volumio[27132]: info: CoreCommandRouter::volumioPushState Feb 09 18:22:09 music volumio[27132]: info: Completed loading Core Plugins Feb 09 18:22:09 music volumio[27132]: info: Preparing to generate the ALSA configuration file Feb 09 18:22:09 music volumio[27132]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 09 18:22:09 music volumio[27132]: info: Discovery: Found device music Feb 09 18:22:09 music volumio[27132]: info: CoreCommandRouter::volumioGetState Feb 09 18:22:09 music volumio[27132]: info: CorePlayQueue::getTrack 0 Feb 09 18:22:09 music volumio[27132]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 09 18:22:09 music volumio[27132]: info: Discovery: Found device music Feb 09 18:22:09 music volumio[27132]: info: CoreCommandRouter::volumioGetState Feb 09 18:22:09 music volumio[27132]: info: CorePlayQueue::getTrack 0 Feb 09 18:22:09 music volumio[27132]: info: Asound.conf file unchanged, so no further update is needed Feb 09 18:22:09 music volumio[27132]: info: Output device has changed, restarting MPD Feb 09 18:22:09 music volumio[27132]: info: Output device has changed, restarting Shairport Sync Feb 09 18:22:09 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:09 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 18:22:09 music sudo[27265]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 18:22:09 music sudo[27261]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 18:22:09 music sudo[27265]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:09 music sudo[27261]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:09 music sudo[27261]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:09 music volumio[27132]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 18:22:09 music volumio[27132]: info: ___________ START PLUGINS ___________ Feb 09 18:22:09 music volumio[27132]: info: ControllerMpd::onStart: Initializing MPD Feb 09 18:22:09 music volumio[27132]: info: Creating MPD Configuration file Feb 09 18:22:09 music systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 09 18:22:09 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 18:22:09 music volumio[27132]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 18:22:09 music volumio[27132]: info: [1770679329693] CoreMusicLibrary::Adding element Media Servers Feb 09 18:22:09 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 18:22:09 music sudo[27271]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 18:22:09 music sudo[27273]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 18:22:09 music sudo[27271]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:09 music sudo[27273]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:09 music sudo[27271]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:09 music volumio[27132]: info: UPNP Browser: Client initialized successfully Feb 09 18:22:09 music systemd[1]: mpd.service: Deactivated successfully. Feb 09 18:22:09 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 09 18:22:09 music systemd[1]: mpd.service: Consumed 4.147s CPU time. Feb 09 18:22:09 music systemd[1]: mpd.socket: Deactivated successfully. Feb 09 18:22:09 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 09 18:22:09 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 09 18:22:09 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:09 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 18:22:09 music volumio[27132]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 18:22:09 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:09 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 18:22:09 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 09 18:22:09 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 09 18:22:09 music volumio[27132]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 18:22:09 music volumio[27132]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 18:22:09 music volumio[27132]: info: [1770679329862] CoreMusicLibrary::Adding element Last_100 Feb 09 18:22:09 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 18:22:09 music volumio[27132]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 18:22:09 music volumio[27132]: info: [1770679329867] CoreMusicLibrary::Adding element Webradio Feb 09 18:22:09 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 18:22:09 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 09 18:22:09 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 18:22:09 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 18:22:09 music volumio[27132]: info: Initializing BBC Radios Feb 09 18:22:09 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 18:22:09 music go-librespot[27288]: go-librespot daemon starting... Feb 09 18:22:09 music systemd[1]: mpd.service: Deactivated successfully. Feb 09 18:22:09 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 09 18:22:09 music systemd[1]: mpd.socket: Deactivated successfully. Feb 09 18:22:09 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 09 18:22:09 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 09 18:22:09 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 09 18:22:09 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 09 18:22:09 music go-librespot[27290]: time="2026-02-09T18:22:09-05:00" level=info msg="running go-librespot 0.6.2" Feb 09 18:22:09 music go-librespot[27290]: time="2026-02-09T18:22:09-05:00" level=debug msg="app state loaded" Feb 09 18:22:10 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 18:22:10 music go-librespot[27290]: time="2026-02-09T18:22:10-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 18:22:10 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 18:22:10 music volumio[27132]: info: Creating Spotify config file Feb 09 18:22:10 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:10 music sudo[27302]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 09 18:22:10 music sudo[27302]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 09 18:22:10 music sudo[27302]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:10 music go-librespot[27290]: time="2026-02-09T18: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 09 18:22:10 music go-librespot[27290]: time="2026-02-09T18: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 09 18:22:10 music go-librespot[27290]: time="2026-02-09T18: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 09 18:22:10 music go-librespot[27290]: time="2026-02-09T18:22:10-05:00" level=info msg="zeroconf server listening on port 45011" Feb 09 18:22:10 music go-librespot[27290]: time="2026-02-09T18:22:10-05:00" level=debug msg="obtained new client token: AAAcNoHvfzb8TECe1th+SnetLhsQ+3uwA62VxW0Y21Ezr8doPy/1HmxGEFDDJ1kOc+P/nlhFYTSyLLcGRaUb+Rz4ji/TwPAVhPoIfFPZQc+3SpDXNXSgZgtrsbOmHWA7EmqpWoXH2tO/XrGGL1xd7MpibtO6+hMV5qQlWxpFN9QJ3QrnsVfDPzXiywCMgraZY/W1RQFFdleB3nnZ+IpCdXxVKBlyNhUPo97oqa36bZMKtN9f/+oabgI=" Feb 09 18:22:10 music volumio[27132]: info: Volumio Calling Home Feb 09 18:22:10 music go-librespot[27290]: time="2026-02-09T18:22:10-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 09 18:22:10 music go-librespot[27290]: time="2026-02-09T18:22:10-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 09 18:22:10 music go-librespot[27290]: time="2026-02-09T18:22:10-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:10 music go-librespot[27290]: time="2026-02-09T18:22:10-05:00" level=debug msg="completed challenge" Feb 09 18:22:10 music go-librespot[27290]: time="2026-02-09T18:22:10-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:11 music volumio[27224]: Starting albumart workers Feb 09 18:22:11 music volumio[27132]: info: MPD Permissions set Feb 09 18:22:11 music volumio[27132]: info: MPD Permissions set Feb 09 18:22:11 music volumio[27132]: info: Spotify config file written Feb 09 18:22:11 music sudo[27319]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 09 18:22:11 music sudo[27319]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:11 music volumio[27132]: 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 09 18:22:11 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 09 18:22:11 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 09 18:22:11 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 18:22:11 music volumio[27132]: info: Volumio called home Feb 09 18:22:11 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:11 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:11 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:11 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:11 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:11 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:11 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:11 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:11 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 18:22:11 music go-librespot[27321]: go-librespot daemon starting... Feb 09 18:22:11 music sudo[27319]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:11 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 18:22:11 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:11 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:11 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:11 music go-librespot[27324]: time="2026-02-09T18:22:11-05:00" level=info msg="running go-librespot 0.6.2" Feb 09 18:22:11 music go-librespot[27324]: time="2026-02-09T18:22:11-05:00" level=debug msg="app state loaded" Feb 09 18:22:11 music volumio[27222]: Starting albumart workers Feb 09 18:22:11 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:11 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:11 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:11 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:11 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:11 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:11 music go-librespot[27324]: time="2026-02-09T18:22:11-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 18:22:11 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 18:22:11 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:11 music volumio[27132]: info: No need to fix Spotify hosts Feb 09 18:22:11 music volumio[27223]: Starting albumart workers Feb 09 18:22:11 music go-librespot[27324]: time="2026-02-09T18:22:11-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 09 18:22:11 music go-librespot[27324]: time="2026-02-09T18:22:11-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 09 18:22:11 music go-librespot[27324]: time="2026-02-09T18:22:11-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 09 18:22:11 music go-librespot[27324]: time="2026-02-09T18:22:11-05:00" level=info msg="zeroconf server listening on port 44863" Feb 09 18:22:12 music go-librespot[27324]: time="2026-02-09T18:22:12-05:00" level=debug msg="obtained new client token: AABsUnMECsiOTekMOWEYm84qaT5WZ6W2PMnt/XSg1aYUo834ZK/DEcccqbeYbRZd2390b4KmSe0ZdUhkGg9+QFSMLv/qtUMFMIEPuxOJXvu6IoLirMlx1Vb3lwONyWrKtTwrf2UwFNBvbrcdLJL8m/aPgVrZamg+qE6P76q2iipquCvprJ81kAgru7jkIdCRHflGvh8DMtDH9PbVq8/0xfugUrHOpKEy35lm2KkhkBxl8PGuBfVJ" Feb 09 18:22:12 music go-librespot[27324]: time="2026-02-09T18:22:12-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 09 18:22:12 music volumio[27132]: info: Starting Shairport Sync Feb 09 18:22:12 music volumio[27132]: info: Starting Shairport Sync Feb 09 18:22:12 music go-librespot[27324]: time="2026-02-09T18:22:12-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:12 music go-librespot[27324]: time="2026-02-09T18:22:12-05:00" level=debug msg="completed challenge" Feb 09 18:22:12 music volumio[27132]: info: Starting Shairport Sync Feb 09 18:22:12 music sudo[27344]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 18:22:12 music sudo[27344]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:12 music go-librespot[27324]: time="2026-02-09T18:22:12-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:12 music volumio[27132]: info: CoreCommandRouter::volumioGetState Feb 09 18:22:12 music volumio[27132]: info: CorePlayQueue::getTrack 0 Feb 09 18:22:12 music sudo[27342]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 18:22:12 music sudo[27342]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:12 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 09 18:22:12 music sudo[27347]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 18:22:12 music sudo[27347]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:12 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 09 18:22:12 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 18:22:12 music systemd[1]: shairport-sync.service: Consumed 1.879s CPU time. Feb 09 18:22:12 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 18:22:12 music sudo[27344]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:12 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 09 18:22:12 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 09 18:22:12 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 18:22:12 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 18:22:12 music sudo[27342]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:12 music sudo[27347]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:12 music volumio[27132]: info: Shairport-Sync Started Feb 09 18:22:12 music volumio[27132]: Error adding Membership: Error: addMembership EINVAL Feb 09 18:22:12 music volumio[27132]: info: Shairport-Sync Started Feb 09 18:22:12 music volumio[27132]: info: Shairport-Sync Started Feb 09 18:22:12 music go-librespot[27324]: time="2026-02-09T18:22:12-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 09 18:22:12 music volumio[27132]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 09 18:22:12 music volumio[27132]: info: Listing playlists Feb 09 18:22:12 music volumio[27132]: info: Listing playlists Feb 09 18:22:12 music go-librespot[27324]: time="2026-02-09T18:22:12-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:12 music go-librespot[27324]: time="2026-02-09T18:22:12-05:00" level=debug msg="completed challenge" Feb 09 18:22:13 music go-librespot[27324]: time="2026-02-09T18:22:13-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:13 music volumio[27132]: info: CoreCommandRouter::volumioGetState Feb 09 18:22:13 music volumio[27132]: info: CorePlayQueue::getTrack 0 Feb 09 18:22:13 music go-librespot[27324]: time="2026-02-09T18:22:13-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 09 18:22:13 music go-librespot[27324]: time="2026-02-09T18:22:13-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:13 music go-librespot[27324]: time="2026-02-09T18:22:13-05:00" level=debug msg="completed challenge" Feb 09 18:22:13 music go-librespot[27324]: time="2026-02-09T18:22:13-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:14 music go-librespot[27324]: time="2026-02-09T18:22:14-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 09 18:22:14 music go-librespot[27324]: time="2026-02-09T18:22:14-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:14 music go-librespot[27324]: time="2026-02-09T18:22:14-05:00" level=debug msg="completed challenge" Feb 09 18:22:14 music go-librespot[27324]: time="2026-02-09T18:22:14-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:14 music mpd[27312]: 2026-02-09T18:22:14 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 09 18:22:14 music systemd[1]: Started mpd.service - Music Player Daemon. Feb 09 18:22:14 music sudo[27265]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:14 music sudo[27273]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:14 music volumio[27132]: info: Completed starting Core Plugins Feb 09 18:22:14 music volumio[27132]: info: ------------------------------------------- Feb 09 18:22:14 music volumio[27132]: info: ----- MyVolumio plugins startup ---- Feb 09 18:22:14 music volumio[27132]: info: ------------------------------------------- Feb 09 18:22:14 music volumio[27132]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 09 18:22:14 music volumio[27132]: error: MPD error: The expression evaluated to a falsy value: Feb 09 18:22:14 music volumio[27132]: assert.ok(self.idling) Feb 09 18:22:14 music volumio[27132]: error: The expression evaluated to a falsy value: Feb 09 18:22:14 music volumio[27132]: assert.ok(self.idling) Feb 09 18:22:14 music volumio[27132]: info: MPD running with PID27312 Feb 09 18:22:14 music volumio[27132]: ,establishing connection Feb 09 18:22:14 music volumio[27132]: error: updateQueue error: null Feb 09 18:22:14 music volumio[27132]: error: updateQueue error: null Feb 09 18:22:15 music go-librespot[27324]: time="2026-02-09T18:22:15-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 09 18:22:15 music volumio[27132]: info: go-librespot daemon successfully initialized Feb 09 18:22:15 music go-librespot[27324]: time="2026-02-09T18:22:15-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:15 music go-librespot[27324]: time="2026-02-09T18:22:15-05:00" level=debug msg="completed challenge" Feb 09 18:22:15 music sudo[27407]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 18:22:15 music sudo[27405]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 18:22:15 music sudo[27407]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:15 music sudo[27405]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:15 music sudo[27407]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:15 music sudo[27405]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:15 music sudo[27411]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 09 18:22:15 music sudo[27411]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:15 music sudo[27411]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:15 music volumio[27132]: info: Upmpdcli Daemon Started Feb 09 18:22:15 music go-librespot[27324]: time="2026-02-09T18:22:15-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:15 music go-librespot[27324]: time="2026-02-09T18:22:15-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 09 18:22:16 music go-librespot[27324]: time="2026-02-09T18:22:16-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:16 music go-librespot[27324]: time="2026-02-09T18:22:16-05:00" level=debug msg="completed challenge" Feb 09 18:22:16 music go-librespot[27324]: time="2026-02-09T18:22:16-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:16 music go-librespot[27324]: time="2026-02-09T18:22:16-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 09 18:22:16 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 18:22:16 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 18:22:17 music sudo[27414]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 09 18:22:17 music sudo[27414]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:17 music sudo[27416]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 09 18:22:17 music sudo[27416]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:17 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 09 18:22:17 music systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 09 18:22:17 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 09 18:22:17 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 09 18:22:17 music sudo[27414]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:17 music mpd_monitor.sh[27419]: MPD Monitor Service: Starting MPD Monitor Service Feb 09 18:22:17 music volumio[27132]: info: Successfully started MPD Monitor Feb 09 18:22:17 music sudo[27416]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:17 music volumio[27132]: info: Successfully started MPD Monitor Feb 09 18:22:18 music volumio[27132]: info: Initializing connection to go-librespot Websocket Feb 09 18:22:18 music volumio[27132]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 18:22:19 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 09 18:22:19 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 18:22:19 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 18:22:19 music go-librespot[27423]: go-librespot daemon starting... Feb 09 18:22:19 music go-librespot[27424]: time="2026-02-09T18:22:19-05:00" level=info msg="running go-librespot 0.6.2" Feb 09 18:22:19 music go-librespot[27424]: time="2026-02-09T18:22:19-05:00" level=debug msg="app state loaded" Feb 09 18:22:19 music go-librespot[27424]: time="2026-02-09T18:22:19-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 18:22:19 music volumio[27132]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 09 18:22:19 music go-librespot[27424]: time="2026-02-09T18:22:19-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 18:22:19 music go-librespot[27424]: time="2026-02-09T18:22:19-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 18:22:19 music go-librespot[27424]: time="2026-02-09T18:22:19-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 18:22:19 music go-librespot[27424]: time="2026-02-09T18:22:19-05:00" level=info msg="zeroconf server listening on port 42041" Feb 09 18:22:19 music go-librespot[27424]: time="2026-02-09T18:22:19-05:00" level=debug msg="obtained new client token: AAD60++vxI31Xkop5fb2AZwCmWTAoeDK9mdKxZdkiWElV/JaJf6ItYrvxaJJV21eU+H20yMIdol2rlSI+rHZTFiSWj84IQ39iFZ//voXQ9zOsLtZ4PjTBIggIFA8uEiimBOWrVxzJ6U6SfNAFg0U1i0elcM/tfzEjpigxXPP38POMfTXMib4CJaPZ7cPnkq0algC/qAS3glfoz/UtiKGMbIGETuYuTBuoQLv66K6++nYCZqXGLM9BFo=" Feb 09 18:22:19 music go-librespot[27424]: time="2026-02-09T18:22:19-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 09 18:22:19 music go-librespot[27424]: time="2026-02-09T18:22:19-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:19 music go-librespot[27424]: time="2026-02-09T18:22:19-05:00" level=debug msg="completed challenge" Feb 09 18:22:20 music go-librespot[27424]: time="2026-02-09T18:22:20-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:20 music go-librespot[27424]: time="2026-02-09T18:22:20-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 09 18:22:20 music go-librespot[27424]: time="2026-02-09T18:22:20-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:20 music go-librespot[27424]: time="2026-02-09T18:22:20-05:00" level=debug msg="completed challenge" Feb 09 18:22:20 music go-librespot[27424]: time="2026-02-09T18:22:20-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:21 music volumio[27132]: info: Initializing connection to go-librespot Websocket Feb 09 18:22:21 music go-librespot[27424]: time="2026-02-09T18:22:21-05:00" level=debug msg="new websocket client" Feb 09 18:22:21 music volumio[27132]: info: Connection to go-librespot Websocket established Feb 09 18:22:21 music go-librespot[27424]: time="2026-02-09T18:22:21-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 09 18:22:21 music go-librespot[27424]: time="2026-02-09T18:22:21-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:21 music go-librespot[27424]: time="2026-02-09T18:22:21-05:00" level=debug msg="completed challenge" Feb 09 18:22:21 music go-librespot[27424]: time="2026-02-09T18:22:21-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:21 music volumio[27132]: info: CoreCommandRouter::volumioGetState Feb 09 18:22:21 music volumio[27132]: info: CorePlayQueue::getTrack 0 Feb 09 18:22:22 music go-librespot[27424]: time="2026-02-09T18:22:22-05:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 18:22:22 music go-librespot[27424]: time="2026-02-09T18:22:22-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:22 music go-librespot[27424]: time="2026-02-09T18:22:22-05:00" level=debug msg="completed challenge" Feb 09 18:22:22 music go-librespot[27424]: time="2026-02-09T18:22:22-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:22 music volumio[27132]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 09 18:22:22 music volumio[27132]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 09 18:22:22 music volumio[27132]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 09 18:22:22 music volumio[27132]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 09 18:22:22 music volumio[27132]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 09 18:22:22 music volumio[27132]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 09 18:22:22 music volumio[27132]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 09 18:22:22 music volumio[27132]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 09 18:22:22 music volumio[27132]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 09 18:22:22 music volumio[27132]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 09 18:22:22 music volumio[27132]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 09 18:22:22 music volumio[27132]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 09 18:22:22 music volumio[27132]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 09 18:22:22 music volumio[27132]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 09 18:22:22 music volumio[27132]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 09 18:22:22 music volumio[27132]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 09 18:22:22 music volumio[27132]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 09 18:22:22 music volumio[27132]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 09 18:22:22 music volumio[27132]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 09 18:22:22 music volumio[27132]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 09 18:22:22 music volumio[27132]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 09 18:22:22 music volumio[27132]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 09 18:22:22 music volumio[27132]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 09 18:22:22 music volumio[27132]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 09 18:22:22 music volumio[27132]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 09 18:22:22 music volumio[27132]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 09 18:22:22 music volumio[27132]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 09 18:22:22 music volumio[27132]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 09 18:22:22 music volumio[27132]: info: Adding plugin bluetooth to MyMusic Plugins Feb 09 18:22:22 music volumio[27132]: info: Adding plugin multiroom to MyMusic Plugins Feb 09 18:22:22 music volumio[27132]: info: Adding plugin metavolumio to MyMusic Plugins Feb 09 18:22:22 music volumio[27132]: info: Adding plugin cd_controller to MyMusic Plugins Feb 09 18:22:22 music volumio[27132]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 09 18:22:22 music volumio[27132]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 09 18:22:22 music volumio[27132]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 09 18:22:22 music volumio[27132]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 09 18:22:23 music go-librespot[27424]: time="2026-02-09T18:22:23-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 09 18:22:23 music go-librespot[27424]: time="2026-02-09T18:22:23-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:23 music go-librespot[27424]: time="2026-02-09T18:22:23-05:00" level=debug msg="completed challenge" Feb 09 18:22:23 music go-librespot[27424]: time="2026-02-09T18:22:23-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:23 music volumio[27132]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 09 18:22:23 music volumio[27132]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 09 18:22:23 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 18:22:23 music volumio[27132]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 18:22:23 music volumio[27132]: info: Starting MyVolumio Remote Streaming Endpoints Feb 09 18:22:23 music volumio[27132]: info: MyVolumio login type: Token Feb 09 18:22:23 music volumio[27132]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 09 18:22:23 music volumio[27132]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 09 18:22:24 music go-librespot[27424]: time="2026-02-09T18:22:24-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 09 18:22:24 music go-librespot[27424]: time="2026-02-09T18:22:24-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:24 music go-librespot[27424]: time="2026-02-09T18:22:24-05:00" level=debug msg="completed challenge" Feb 09 18:22:24 music go-librespot[27424]: time="2026-02-09T18:22:24-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:24 music go-librespot[27424]: time="2026-02-09T18:22:24-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:24 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 18:22:24 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 18:22:24 music volumio[27132]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 09 18:22:24 music volumio[27132]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 09 18:22:24 music volumio[27132]: info: Streaming services startup Feb 09 18:22:24 music volumio[27132]: info: Starting Streaming Daemon Feb 09 18:22:24 music sudo[27434]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 09 18:22:24 music sudo[27434]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:24 music volumio[27132]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 09 18:22:24 music sudo[27434]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:25 music volumio[27132]: info: Getting Spotify volume Feb 09 18:22:25 music volumio[27132]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 18:22:25 music volumio[27132]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 18:22:25 music volumio[27132]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 09 18:22:25 music volumio[27132]: errno: -111, Feb 09 18:22:25 music volumio[27132]: code: 'ECONNREFUSED', Feb 09 18:22:25 music volumio[27132]: syscall: 'connect', Feb 09 18:22:25 music volumio[27132]: address: '127.0.0.1', Feb 09 18:22:25 music volumio[27132]: port: 9879, Feb 09 18:22:25 music volumio[27132]: response: undefined Feb 09 18:22:25 music volumio[27132]: } Feb 09 18:22:25 music volumio[27132]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 18:22:25 music sudo[27468]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-09 18:21' Feb 09 18:22:25 music sudo[27468]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:26 music sudo[27468]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:26 music volumio-remote-updater[30265]: [2026-02-09 18:22:26] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 09 18:22:26 music volumio-remote-updater[30265]: [2026-02-09 18:22:26] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 09 18:22:26 music systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 09 18:22:26 music systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 09 18:22:26 music systemd[1]: volumio.service: Consumed 26.613s CPU time. Feb 09 18:22:26 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 09 18:22:26 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 09 18:22:27 music systemd[1]: volumio.service: Scheduled restart job, restart counter is at 53185. Feb 09 18:22:27 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 09 18:22:27 music systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 09 18:22:27 music systemd[1]: volumio.service: Consumed 26.613s CPU time. Feb 09 18:22:27 music systemd[1]: Started volumio.service - Volumio Backend Module. Feb 09 18:22:27 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 09 18:22:27 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 09 18:22:27 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 18:22:27 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 18:22:27 music go-librespot[27498]: go-librespot daemon starting... Feb 09 18:22:27 music go-librespot[27499]: time="2026-02-09T18:22:27-05:00" level=info msg="running go-librespot 0.6.2" Feb 09 18:22:27 music go-librespot[27499]: time="2026-02-09T18:22:27-05:00" level=debug msg="app state loaded" Feb 09 18:22:27 music go-librespot[27499]: time="2026-02-09T18:22:27-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 18:22:28 music go-librespot[27499]: time="2026-02-09T18:22:28-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Feb 09 18:22:28 music go-librespot[27499]: time="2026-02-09T18:22:28-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 09 18:22:28 music go-librespot[27499]: time="2026-02-09T18:22:28-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 09 18:22:28 music go-librespot[27499]: time="2026-02-09T18:22:28-05:00" level=info msg="zeroconf server listening on port 44363" Feb 09 18:22:28 music go-librespot[27499]: time="2026-02-09T18:22:28-05:00" level=debug msg="obtained new client token: AABIHscLvh//Dba2ZDcG1jpxLXidpwgBHC/TvRGwZXLjVmJ4d2GkDZE3Wa031GWXMO/mSTqF4L4yQE5QmG7D+qf/5F68kIE2+V/972eM0Y81qbsuLA8EQSWUHYlYSgA3Sn6dKYHyxxCkZEc6UB8dWPyLg2kHb63lzuk1ZqlPeZs/+XiOIV1ZZ7AFEM4+pOByvIwY/73CVUgTE28TSX8diIxrqcexta8xwzwgfjj/G4SuzeJKRPWV" Feb 09 18:22:28 music go-librespot[27499]: time="2026-02-09T18:22:28-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 09 18:22:28 music go-librespot[27499]: time="2026-02-09T18:22:28-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:28 music go-librespot[27499]: time="2026-02-09T18:22:28-05:00" level=debug msg="completed challenge" Feb 09 18:22:28 music go-librespot[27499]: time="2026-02-09T18:22:28-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:28 music go-librespot[27499]: time="2026-02-09T18:22:28-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 09 18:22:29 music go-librespot[27499]: time="2026-02-09T18:22:29-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:29 music go-librespot[27499]: time="2026-02-09T18:22:29-05:00" level=debug msg="completed challenge" Feb 09 18:22:29 music go-librespot[27499]: time="2026-02-09T18:22:29-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:29 music volumio[27483]: info: ------------------------------------------- Feb 09 18:22:29 music volumio[27483]: info: ----- Volumio3 ---- Feb 09 18:22:29 music volumio[27483]: info: ------------------------------------------- Feb 09 18:22:29 music volumio[27483]: info: ----- System startup ---- Feb 09 18:22:29 music volumio[27483]: info: ------------------------------------------- Feb 09 18:22:29 music go-librespot[27499]: time="2026-02-09T18:22:29-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 09 18:22:29 music go-librespot[27499]: time="2026-02-09T18:22:29-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:29 music go-librespot[27499]: time="2026-02-09T18:22:29-05:00" level=debug msg="completed challenge" Feb 09 18:22:29 music go-librespot[27499]: time="2026-02-09T18:22:29-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:29 music volumio[27483]: info: MYVOLUMIO Environment detected Feb 09 18:22:29 music volumio[27483]: info: Plugin folders cleanup Feb 09 18:22:29 music volumio[27483]: info: Scanning into folder /volumio/app/plugins/ Feb 09 18:22:29 music volumio[27483]: info: Scanning category audio_interface Feb 09 18:22:29 music volumio[27483]: info: Scanning category miscellanea Feb 09 18:22:29 music volumio[27483]: info: Scanning category music_service Feb 09 18:22:29 music volumio[27483]: info: Scanning category plugins.json Feb 09 18:22:29 music volumio[27483]: info: Scanning category system_controller Feb 09 18:22:29 music volumio[27483]: info: Scanning category user_interface Feb 09 18:22:29 music volumio[27483]: info: Scanning into folder /data/plugins/ Feb 09 18:22:29 music volumio[27483]: info: Scanning category music_service Feb 09 18:22:29 music volumio[27483]: info: Plugin folders cleanup completed Feb 09 18:22:29 music volumio[27483]: info: ------------------------------------------- Feb 09 18:22:29 music volumio[27483]: info: ----- Core plugins startup ---- Feb 09 18:22:29 music volumio[27483]: info: ------------------------------------------- Feb 09 18:22:29 music volumio[27483]: info: Loading plugins from folder /volumio/app/plugins/ Feb 09 18:22:29 music volumio[27483]: info: Adding plugin upnp to MyMusic Plugins Feb 09 18:22:30 music volumio[27483]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 09 18:22:30 music volumio[27483]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 09 18:22:30 music volumio[27483]: info: Loading plugins from folder /data/plugins/ Feb 09 18:22:30 music volumio[27483]: info: Loading plugin "system"... Feb 09 18:22:30 music volumio[27483]: info: Loading plugin "appearance"... Feb 09 18:22:30 music go-librespot[27499]: time="2026-02-09T18:22:30-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 09 18:22:30 music go-librespot[27499]: time="2026-02-09T18:22:30-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:30 music go-librespot[27499]: time="2026-02-09T18:22:30-05:00" level=debug msg="completed challenge" Feb 09 18:22:30 music go-librespot[27499]: time="2026-02-09T18:22:30-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:31 music volumio[27483]: info: Loading plugin "network"... Feb 09 18:22:31 music volumio[27483]: info: Refreshing Cached IP Addresses Feb 09 18:22:31 music sudo[27521]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 18:22:31 music sudo[27521]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:31 music sudo[27521]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:31 music sudo[27523]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 18:22:31 music sudo[27523]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:31 music sudo[27523]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:31 music volumio[27483]: info: Loading plugin "services"... Feb 09 18:22:31 music go-librespot[27499]: time="2026-02-09T18:22:31-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 09 18:22:31 music volumio[27483]: info: Loading plugin "alsa_controller"... Feb 09 18:22:31 music sudo[27531]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 09 18:22:31 music sudo[27531]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:31 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 18:22:31 music volumio[27483]: info: Loading plugin "wizard"... Feb 09 18:22:31 music volumio[27483]: info: Loading plugin "networkfs"... Feb 09 18:22:31 music volumio[27483]: info: Starting Udev Watcher for removable devices Feb 09 18:22:31 music volumio[27483]: info: Ignoring mount for partition: boot Feb 09 18:22:31 music volumio[27483]: info: Ignoring mount for partition: volumio Feb 09 18:22:31 music volumio[27483]: info: Ignoring mount for partition: volumio_data Feb 09 18:22:31 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 18:22:31 music volumio[27483]: info: Loading plugin "volumio_command_line_client"... Feb 09 18:22:31 music volumio[27483]: info: Loading plugin "upnp"... Feb 09 18:22:31 music volumio[27483]: info: [1770679351362] Starting Upmpd Daemon Feb 09 18:22:31 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 18:22:31 music volumio[27483]: info: Loading plugin "my_music"... Feb 09 18:22:31 music volumio[27483]: info: Loading plugin "mpd"... Feb 09 18:22:31 music go-librespot[27499]: time="2026-02-09T18:22:31-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:31 music go-librespot[27499]: time="2026-02-09T18:22:31-05:00" level=debug msg="completed challenge" Feb 09 18:22:31 music go-librespot[27499]: time="2026-02-09T18:22:31-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:31 music volumio[27483]: info: Loading plugin "upnp_browser"... Feb 09 18:22:31 music sudo[27531]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:31 music volumio-remote-updater[30265]: [2026-02-09 18:22:31] [connect] Successful connection Feb 09 18:22:32 music go-librespot[27499]: time="2026-02-09T18:22:32-05:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 09 18:22:32 music go-librespot[27499]: time="2026-02-09T18:22:32-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:32 music go-librespot[27499]: time="2026-02-09T18:22:32-05:00" level=debug msg="completed challenge" Feb 09 18:22:32 music go-librespot[27499]: time="2026-02-09T18:22:32-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:32 music go-librespot[27499]: time="2026-02-09T18:22:32-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 09 18:22:32 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 18:22:32 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 18:22:33 music volumio[27483]: info: Starting UPNP Browser Feb 09 18:22:33 music volumio[27483]: info: Loading plugin "alarm-clock"... Feb 09 18:22:33 music volumio[27483]: info: Loading plugin "airplay_emulation"... Feb 09 18:22:33 music volumio[27483]: info: Starting Shairport Sync Feb 09 18:22:33 music volumio[27483]: info: Loading plugin "last_100"... Feb 09 18:22:33 music volumio[27483]: info: Loading plugin "webradio"... Feb 09 18:22:33 music volumio[27483]: info: Loading plugin "i2s_dacs"... Feb 09 18:22:33 music volumio[27483]: info: I2S DAC not set, start Auto-detection Feb 09 18:22:33 music volumio[27483]: info: Loading plugin "volumiodiscovery"... Feb 09 18:22:33 music volumio[27483]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 18:22:33 music volumio[27483]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 18:22:33 music volumio[27483]: *** WARNING *** For more information see Feb 09 18:22:33 music volumio[27483]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 18:22:33 music volumio[27483]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 18:22:33 music volumio[27483]: *** WARNING *** For more information see Feb 09 18:22:33 music node[27483]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 18:22:33 music node[27483]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 18:22:33 music node[27483]: *** WARNING *** For more information see Feb 09 18:22:33 music node[27483]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 18:22:33 music node[27483]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 18:22:33 music node[27483]: *** WARNING *** For more information see Feb 09 18:22:33 music volumio[27483]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 09 18:22:33 music volumio[27483]: info: Discovery: Started advertising with name: music Feb 09 18:22:33 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 18:22:33 music volumio[27483]: info: Loading plugin "spop"... Feb 09 18:22:34 music volumio[27483]: info: Loading plugin "outputs"... Feb 09 18:22:34 music volumio[27483]: info: Loading plugin "albumart"... Feb 09 18:22:34 music volumio[27483]: info: Plugin example_plugin is not enabled Feb 09 18:22:34 music volumio[27483]: info: Loading plugin "inputs"... Feb 09 18:22:34 music volumio[27483]: info: Loading plugin "updater_comm"... Feb 09 18:22:34 music volumio[27483]: info: Plugin mpdemulation is not enabled Feb 09 18:22:34 music volumio[27483]: info: Loading plugin "rest_api"... Feb 09 18:22:34 music volumio[27483]: info: Loading plugin "websocket"... Feb 09 18:22:34 music volumio[27483]: info: Starting Socket.io Server version 1.7.4 Feb 09 18:22:34 music volumio[27483]: info: Loading i18n strings for locale en Feb 09 18:22:34 music volumio[27483]: Updating browse sources language Feb 09 18:22:35 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 18:22:35 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 18:22:35 music volumio[27483]: info: CoreCommandRouter::initPlayerControls Feb 09 18:22:35 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:35 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:35 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:35 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:35 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:35 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:35 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:35 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:35 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 18:22:35 music volumio[27483]: Express server listening on port 3000 Feb 09 18:22:35 music volumio[27483]: [Metrics] WebUI: 6s 578.20ms Feb 09 18:22:35 music volumio[27483]: info: CoreStateMachine::resetVolumioState Feb 09 18:22:35 music volumio[27483]: info: CoreStateMachine::getcurrentVolume Feb 09 18:22:35 music volumio[27483]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 18:22:35 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 18:22:35 music volumio[27483]: info: Volumio Network Manager: Network status updated: 1 Feb 09 18:22:35 music volumio-remote-updater[30265]: [2026-02-09 18:22:35] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770679351 101 Feb 09 18:22:35 music volumio[27556]: Forking 3 albumart workers Feb 09 18:22:35 music volumio[27483]: 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 09 18:22:35 music volumio[27483]: info: VolumeController:: Volume=86 Mute =false Feb 09 18:22:35 music volumio[27483]: info: CoreStateMachine::pushState Feb 09 18:22:35 music volumio[27483]: info: CorePlayQueue::getTrack 0 Feb 09 18:22:35 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 18:22:35 music volumio[27483]: info: CoreCommandRouter::volumioPushState Feb 09 18:22:35 music volumio[27483]: info: CoreStateMachine::updateTrackBlock Feb 09 18:22:35 music volumio[27483]: info: CorePlayQueue::getTrackBlock Feb 09 18:22:35 music volumio[27483]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 18:22:35 music volumio[27483]: info: Reloading queue from file Feb 09 18:22:35 music volumio[27483]: info: CoreCommandRouter::volumioGetState Feb 09 18:22:35 music volumio[27483]: info: CorePlayQueue::getTrack 0 Feb 09 18:22:35 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 09 18:22:35 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 18:22:35 music volumio[27483]: info: CoreStateMachine::setRepeat null single undefined Feb 09 18:22:35 music volumio[27483]: info: CoreStateMachine::pushState Feb 09 18:22:35 music volumio[27483]: info: CorePlayQueue::getTrack 0 Feb 09 18:22:35 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 18:22:35 music volumio[27483]: info: CoreCommandRouter::volumioPushState Feb 09 18:22:35 music volumio[27483]: info: CoreStateMachine::setRandom null Feb 09 18:22:35 music volumio[27483]: info: CoreStateMachine::pushState Feb 09 18:22:35 music volumio[27483]: info: CorePlayQueue::getTrack 0 Feb 09 18:22:35 music volumio[27483]: info: CoreCommandRouter::volumioPushState Feb 09 18:22:35 music volumio[27483]: info: Setting Device type: Raspberry PI Feb 09 18:22:35 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 18:22:35 music go-librespot[27608]: go-librespot daemon starting... Feb 09 18:22:35 music volumio[27483]: info: Listing playlists Feb 09 18:22:35 music volumio[27483]: info: Listing playlists Feb 09 18:22:35 music go-librespot[27610]: time="2026-02-09T18:22:35-05:00" level=info msg="running go-librespot 0.6.2" Feb 09 18:22:35 music go-librespot[27610]: time="2026-02-09T18:22:35-05:00" level=debug msg="app state loaded" Feb 09 18:22:35 music volumio[27483]: info: VolumeController:: Volume=86 Mute =false Feb 09 18:22:35 music volumio[27483]: info: CoreStateMachine::pushState Feb 09 18:22:35 music volumio[27483]: info: CorePlayQueue::getTrack 0 Feb 09 18:22:35 music volumio[27483]: info: CoreCommandRouter::volumioPushState Feb 09 18:22:35 music go-librespot[27610]: time="2026-02-09T18:22:35-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 18:22:35 music volumio[27483]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 09 18:22:35 music volumio[27483]: info: Discovery: Found device music Feb 09 18:22:35 music volumio[27483]: info: CoreCommandRouter::volumioGetState Feb 09 18:22:35 music volumio[27483]: info: CorePlayQueue::getTrack 0 Feb 09 18:22:35 music volumio[27483]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 09 18:22:35 music volumio[27483]: info: Discovery: Found device music Feb 09 18:22:35 music volumio[27483]: info: CoreCommandRouter::volumioGetState Feb 09 18:22:35 music volumio[27483]: info: CorePlayQueue::getTrack 0 Feb 09 18:22:35 music volumio[27483]: info: Completed loading Core Plugins Feb 09 18:22:35 music volumio[27483]: info: Preparing to generate the ALSA configuration file Feb 09 18:22:35 music volumio[27483]: info: Asound.conf file unchanged, so no further update is needed Feb 09 18:22:35 music volumio[27483]: info: Output device has changed, restarting MPD Feb 09 18:22:35 music volumio[27483]: info: Output device has changed, restarting Shairport Sync Feb 09 18:22:35 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:35 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 18:22:35 music sudo[27621]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 18:22:35 music sudo[27621]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:35 music volumio[27483]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 18:22:35 music volumio[27483]: info: ___________ START PLUGINS ___________ Feb 09 18:22:35 music sudo[27622]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 18:22:35 music sudo[27621]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:35 music sudo[27622]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:35 music volumio[27483]: info: ControllerMpd::onStart: Initializing MPD Feb 09 18:22:35 music volumio[27483]: info: Creating MPD Configuration file Feb 09 18:22:36 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 18:22:36 music systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 09 18:22:36 music volumio[27483]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 18:22:36 music volumio[27483]: info: [1770679356021] CoreMusicLibrary::Adding element Media Servers Feb 09 18:22:36 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 18:22:36 music sudo[27633]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 18:22:36 music sudo[27633]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:36 music volumio[27483]: info: UPNP Browser: Client initialized successfully Feb 09 18:22:36 music systemd[1]: mpd.service: Deactivated successfully. Feb 09 18:22:36 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 09 18:22:36 music systemd[1]: mpd.service: Consumed 4.136s CPU time. Feb 09 18:22:36 music systemd[1]: mpd.socket: Deactivated successfully. Feb 09 18:22:36 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 09 18:22:36 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 09 18:22:36 music sudo[27631]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 18:22:36 music sudo[27631]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:36 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:36 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 18:22:36 music sudo[27631]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:36 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 09 18:22:36 music go-librespot[27610]: time="2026-02-09T18: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 09 18:22:36 music go-librespot[27610]: time="2026-02-09T18: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 09 18:22:36 music go-librespot[27610]: time="2026-02-09T18: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 09 18:22:36 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 09 18:22:36 music go-librespot[27610]: time="2026-02-09T18:22:36-05:00" level=info msg="zeroconf server listening on port 40167" Feb 09 18:22:36 music volumio[27483]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 18:22:36 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:36 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 18:22:36 music volumio[27483]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 18:22:36 music volumio[27483]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 18:22:36 music volumio[27483]: info: [1770679356284] CoreMusicLibrary::Adding element Last_100 Feb 09 18:22:36 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 18:22:36 music volumio[27483]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 18:22:36 music volumio[27483]: info: [1770679356301] CoreMusicLibrary::Adding element Webradio Feb 09 18:22:36 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 18:22:36 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 18:22:36 music volumio[27483]: info: Initializing BBC Radios Feb 09 18:22:36 music go-librespot[27610]: time="2026-02-09T18:22:36-05:00" level=debug msg="obtained new client token: AADBki4bUHWTKSLMEirnXggmTdt9mSj6CQq4cWiHG+oakTHrRemojgeyXya6NKlp3frvXlVX2vyXA7FgoRFqXodwr06q+M0F9jHpK3b3ZHolwuhaxiDOwrFofUNCNG3oSGd4FIOf10HHrNcZwUoZ+6wWqyutGVUeNfE3tttpK6EEaC2aOIjbI/UbHd0UuNuqCsCdsEPrkf/xe8oWG+StCLfensl/HyBEhWIN4Ha15VAZiRrJiS/5xLs=" Feb 09 18:22:36 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 18:22:36 music go-librespot[27610]: time="2026-02-09T18:22:36-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 09 18:22:36 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 18:22:36 music sudo[27641]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 09 18:22:36 music sudo[27641]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 09 18:22:36 music volumio[27483]: info: Creating Spotify config file Feb 09 18:22:36 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:36 music sudo[27641]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:36 music go-librespot[27610]: time="2026-02-09T18:22:36-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:36 music go-librespot[27610]: time="2026-02-09T18:22:36-05:00" level=debug msg="completed challenge" Feb 09 18:22:36 music go-librespot[27610]: time="2026-02-09T18:22:36-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:37 music volumio[27483]: info: Volumio Calling Home Feb 09 18:22:37 music go-librespot[27610]: time="2026-02-09T18:22:37-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 09 18:22:37 music volumio[27572]: Starting albumart workers Feb 09 18:22:37 music go-librespot[27610]: time="2026-02-09T18:22:37-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 09 18:22:37 music go-librespot[27610]: time="2026-02-09T18:22:37-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:37 music go-librespot[27610]: time="2026-02-09T18:22:37-05:00" level=debug msg="completed challenge" Feb 09 18:22:37 music go-librespot[27610]: time="2026-02-09T18:22:37-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:37 music volumio[27483]: info: MPD Permissions set Feb 09 18:22:37 music volumio[27483]: info: MPD Permissions set Feb 09 18:22:37 music volumio[27573]: Starting albumart workers Feb 09 18:22:37 music volumio[27483]: info: Volumio called home Feb 09 18:22:37 music volumio[27483]: info: Spotify config file written Feb 09 18:22:37 music volumio[27574]: Starting albumart workers Feb 09 18:22:37 music volumio[27483]: 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 09 18:22:37 music sudo[27667]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 09 18:22:37 music sudo[27667]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:37 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:37 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:37 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:37 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:37 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:37 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:37 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:37 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:37 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 09 18:22:37 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 09 18:22:37 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 18:22:37 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 18:22:37 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:37 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:37 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:37 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:37 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:37 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:37 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:37 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:37 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:37 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 18:22:37 music go-librespot[27674]: go-librespot daemon starting... Feb 09 18:22:37 music sudo[27667]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:37 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 18:22:37 music volumio[27483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:37 music volumio[27483]: info: No need to fix Spotify hosts Feb 09 18:22:37 music go-librespot[27680]: time="2026-02-09T18:22:37-05:00" level=info msg="running go-librespot 0.6.2" Feb 09 18:22:37 music go-librespot[27680]: time="2026-02-09T18:22:37-05:00" level=debug msg="app state loaded" Feb 09 18:22:38 music go-librespot[27680]: time="2026-02-09T18:22:38-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 18:22:38 music go-librespot[27680]: time="2026-02-09T18:22:38-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 09 18:22:38 music go-librespot[27680]: time="2026-02-09T18:22:38-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 09 18:22:38 music go-librespot[27680]: time="2026-02-09T18:22:38-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 09 18:22:38 music go-librespot[27680]: time="2026-02-09T18:22:38-05:00" level=info msg="zeroconf server listening on port 45497" Feb 09 18:22:38 music volumio[27483]: info: Starting Shairport Sync Feb 09 18:22:38 music volumio[27483]: info: Starting Shairport Sync Feb 09 18:22:38 music volumio[27483]: info: Starting Shairport Sync Feb 09 18:22:38 music sudo[27698]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 18:22:38 music sudo[27698]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:38 music volumio[27483]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 09 18:22:38 music sudo[27696]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 18:22:38 music sudo[27696]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:38 music sudo[27701]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 18:22:38 music sudo[27701]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:38 music go-librespot[27680]: time="2026-02-09T18:22:38-05:00" level=debug msg="obtained new client token: AAAydHRh5uilBLexTyB83Gthl2ZRq7LNFEO/epq0Pf957bfP0vKcJngZTr4w0jYFFSvZsdaOL5cY8aaCKcdovZGYhikvgCbCVgWucc5Psyl0CWjrE0jIesedXPkW+Rh53IOgwFnTx9ceTad/sVVw706Zt6D2VX8frL5aeNJh1xUqNa6jEBJlytYa/SXyb85TCG15tPZyTfZKS6Amwgpaqo1kEnuR3CDAtYMHtXRz7/y0vdAltQciO3Q=" Feb 09 18:22:38 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 09 18:22:38 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 09 18:22:38 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 18:22:38 music systemd[1]: shairport-sync.service: Consumed 1.806s CPU time. Feb 09 18:22:38 music go-librespot[27680]: time="2026-02-09T18:22:38-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 09 18:22:38 music volumio[27483]: info: CoreCommandRouter::volumioGetState Feb 09 18:22:38 music volumio[27483]: info: CorePlayQueue::getTrack 0 Feb 09 18:22:38 music go-librespot[27680]: time="2026-02-09T18:22:38-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:38 music go-librespot[27680]: time="2026-02-09T18:22:38-05:00" level=debug msg="completed challenge" Feb 09 18:22:38 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 18:22:38 music sudo[27696]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:38 music sudo[27698]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:38 music volumio[27483]: info: Shairport-Sync Started Feb 09 18:22:38 music volumio[27483]: Error adding Membership: Error: addMembership EINVAL Feb 09 18:22:38 music volumio[27483]: info: Shairport-Sync Started Feb 09 18:22:38 music sudo[27701]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:38 music go-librespot[27680]: time="2026-02-09T18:22:38-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:39 music volumio[27483]: info: Shairport-Sync Started Feb 09 18:22:39 music go-librespot[27680]: time="2026-02-09T18:22:39-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 09 18:22:39 music go-librespot[27680]: time="2026-02-09T18:22:39-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:39 music go-librespot[27680]: time="2026-02-09T18:22:39-05:00" level=debug msg="completed challenge" Feb 09 18:22:39 music go-librespot[27680]: time="2026-02-09T18:22:39-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:40 music go-librespot[27680]: time="2026-02-09T18:22:40-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 09 18:22:40 music go-librespot[27680]: time="2026-02-09T18:22:40-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:40 music go-librespot[27680]: time="2026-02-09T18:22:40-05:00" level=debug msg="completed challenge" Feb 09 18:22:40 music go-librespot[27680]: time="2026-02-09T18:22:40-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:40 music mpd[27660]: 2026-02-09T18:22:40 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 09 18:22:40 music systemd[1]: Started mpd.service - Music Player Daemon. Feb 09 18:22:40 music sudo[27622]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:40 music sudo[27633]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:40 music volumio[27483]: info: Completed starting Core Plugins Feb 09 18:22:40 music volumio[27483]: info: ------------------------------------------- Feb 09 18:22:40 music volumio[27483]: info: ----- MyVolumio plugins startup ---- Feb 09 18:22:40 music volumio[27483]: info: ------------------------------------------- Feb 09 18:22:40 music volumio[27483]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 09 18:22:40 music volumio[27483]: error: MPD error: The expression evaluated to a falsy value: Feb 09 18:22:40 music volumio[27483]: assert.ok(self.idling) Feb 09 18:22:40 music volumio[27483]: error: The expression evaluated to a falsy value: Feb 09 18:22:40 music volumio[27483]: assert.ok(self.idling) Feb 09 18:22:40 music volumio[27483]: info: MPD running with PID27660 Feb 09 18:22:40 music volumio[27483]: ,establishing connection Feb 09 18:22:40 music volumio[27483]: error: updateQueue error: null Feb 09 18:22:40 music volumio[27483]: error: updateQueue error: null Feb 09 18:22:41 music go-librespot[27680]: time="2026-02-09T18:22:41-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 09 18:22:41 music sudo[27752]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 18:22:41 music sudo[27752]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:41 music sudo[27754]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 18:22:41 music sudo[27754]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:41 music sudo[27754]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:41 music sudo[27752]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:41 music sudo[27756]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 09 18:22:41 music sudo[27756]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:41 music sudo[27756]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:41 music volumio[27483]: info: Upmpdcli Daemon Started Feb 09 18:22:41 music volumio[27483]: info: go-librespot daemon successfully initialized Feb 09 18:22:41 music volumio[27483]: info: CoreCommandRouter::volumioGetState Feb 09 18:22:41 music volumio[27483]: info: CorePlayQueue::getTrack 0 Feb 09 18:22:41 music go-librespot[27680]: time="2026-02-09T18:22:41-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:41 music go-librespot[27680]: time="2026-02-09T18:22:41-05:00" level=debug msg="completed challenge" Feb 09 18:22:42 music go-librespot[27680]: time="2026-02-09T18:22:42-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:43 music sudo[27761]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 09 18:22:43 music sudo[27761]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:43 music sudo[27763]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 09 18:22:43 music sudo[27763]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:43 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 09 18:22:43 music systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 09 18:22:43 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 09 18:22:43 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 09 18:22:43 music sudo[27763]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:43 music sudo[27761]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:43 music mpd_monitor.sh[27766]: MPD Monitor Service: Starting MPD Monitor Service Feb 09 18:22:43 music volumio[27483]: info: Successfully started MPD Monitor Feb 09 18:22:43 music volumio[27483]: info: Successfully started MPD Monitor Feb 09 18:22:43 music go-librespot[27680]: time="2026-02-09T18:22:43-05:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.241.202:443: connect: connection refused" Feb 09 18:22:43 music go-librespot[27680]: time="2026-02-09T18:22:43-05:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 09 18:22:44 music go-librespot[27680]: time="2026-02-09T18:22:44-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:44 music go-librespot[27680]: time="2026-02-09T18:22:44-05:00" level=debug msg="completed challenge" Feb 09 18:22:44 music go-librespot[27680]: time="2026-02-09T18:22:44-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:44 music volumio[27483]: info: Initializing connection to go-librespot Websocket Feb 09 18:22:44 music go-librespot[27680]: time="2026-02-09T18:22:44-05:00" level=debug msg="new websocket client" Feb 09 18:22:44 music volumio[27483]: info: Connection to go-librespot Websocket established Feb 09 18:22:44 music go-librespot[27680]: time="2026-02-09T18:22:44-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 09 18:22:44 music go-librespot[27680]: time="2026-02-09T18:22:44-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:44 music go-librespot[27680]: time="2026-02-09T18:22:44-05:00" level=debug msg="completed challenge" Feb 09 18:22:44 music go-librespot[27680]: time="2026-02-09T18:22:44-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:44 music go-librespot[27680]: time="2026-02-09T18:22:44-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 09 18:22:44 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 18:22:44 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 18:22:44 music volumio[27483]: info: Connection to go-librespot Websocket closed Feb 09 18:22:45 music volumio[27483]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 09 18:22:47 music volumio[27483]: info: Getting Spotify volume Feb 09 18:22:47 music volumio[27483]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 18:22:47 music volumio[27483]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 18:22:47 music volumio[27483]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 09 18:22:47 music volumio[27483]: errno: -111, Feb 09 18:22:47 music volumio[27483]: code: 'ECONNREFUSED', Feb 09 18:22:47 music volumio[27483]: syscall: 'connect', Feb 09 18:22:47 music volumio[27483]: address: '127.0.0.1', Feb 09 18:22:47 music volumio[27483]: port: 9879, Feb 09 18:22:47 music volumio[27483]: response: undefined Feb 09 18:22:47 music volumio[27483]: } Feb 09 18:22:47 music volumio[27483]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 18:22:48 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 09 18:22:48 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 18:22:48 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 18:22:48 music go-librespot[27782]: go-librespot daemon starting... Feb 09 18:22:48 music go-librespot[27783]: time="2026-02-09T18:22:48-05:00" level=info msg="running go-librespot 0.6.2" Feb 09 18:22:48 music go-librespot[27783]: time="2026-02-09T18:22:48-05:00" level=debug msg="app state loaded" Feb 09 18:22:48 music go-librespot[27783]: time="2026-02-09T18:22:48-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 18:22:48 music sudo[27794]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-09 18:21' Feb 09 18:22:48 music sudo[27794]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:48 music go-librespot[27783]: time="2026-02-09T18:22:48-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 09 18:22:48 music go-librespot[27783]: time="2026-02-09T18:22:48-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 09 18:22:48 music go-librespot[27783]: time="2026-02-09T18:22:48-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 09 18:22:48 music go-librespot[27783]: time="2026-02-09T18:22:48-05:00" level=info msg="zeroconf server listening on port 34387" Feb 09 18:22:48 music sudo[27794]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:48 music go-librespot[27783]: time="2026-02-09T18:22:48-05:00" level=debug msg="obtained new client token: AADhwM4Wcv8IzFOCVsHip5unkhvLNk0u3y7Rq89Y+PhWZR3MKqNZ8PIsffYRbf+yZ4i5xoWk5L145OHStiyvQWfmmS1i/+A/Hbsja1SrYE0+mFg2Z/l3NPLabNCmZ+PGDXCRkQCJiBPoJ+U3rAdKWqYXSbsH840Y33CICwIKMHumHRFbKhPc8Lk/DXRmKGPrHpgsP3LhjxBB1cygoBLsZYM8mz47drFRGKnOiQzaOoTpIluiggOUAvg=" Feb 09 18:22:48 music volumio-remote-updater[30265]: [2026-02-09 18:22:48] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 09 18:22:48 music volumio-remote-updater[30265]: [2026-02-09 18:22:48] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 09 18:22:48 music systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 09 18:22:48 music go-librespot[27783]: time="2026-02-09T18:22:48-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 09 18:22:48 music systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 09 18:22:48 music systemd[1]: volumio.service: Consumed 23.533s CPU time. Feb 09 18:22:48 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 09 18:22:48 music go-librespot[27783]: time="2026-02-09T18:22:48-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:48 music go-librespot[27783]: time="2026-02-09T18:22:48-05:00" level=debug msg="completed challenge" Feb 09 18:22:48 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 09 18:22:48 music go-librespot[27783]: time="2026-02-09T18:22:48-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:49 music systemd[1]: volumio.service: Scheduled restart job, restart counter is at 53186. Feb 09 18:22:49 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 09 18:22:49 music systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 09 18:22:49 music systemd[1]: volumio.service: Consumed 23.533s CPU time. Feb 09 18:22:49 music systemd[1]: Started volumio.service - Volumio Backend Module. Feb 09 18:22:49 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 09 18:22:49 music go-librespot[27783]: time="2026-02-09T18:22:49-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 09 18:22:49 music go-librespot[27783]: time="2026-02-09T18:22:49-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:49 music go-librespot[27783]: time="2026-02-09T18:22:49-05:00" level=debug msg="completed challenge" Feb 09 18:22:49 music go-librespot[27783]: time="2026-02-09T18:22:49-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:50 music go-librespot[27783]: time="2026-02-09T18:22:50-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 09 18:22:50 music go-librespot[27783]: time="2026-02-09T18:22:50-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:50 music go-librespot[27783]: time="2026-02-09T18:22:50-05:00" level=debug msg="completed challenge" Feb 09 18:22:50 music go-librespot[27783]: time="2026-02-09T18:22:50-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:50 music go-librespot[27783]: time="2026-02-09T18:22:50-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 09 18:22:51 music go-librespot[27783]: time="2026-02-09T18:22:51-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 09 18:22:51 music volumio[27811]: info: ------------------------------------------- Feb 09 18:22:51 music volumio[27811]: info: ----- Volumio3 ---- Feb 09 18:22:51 music volumio[27811]: info: ------------------------------------------- Feb 09 18:22:51 music volumio[27811]: info: ----- System startup ---- Feb 09 18:22:51 music volumio[27811]: info: ------------------------------------------- Feb 09 18:22:51 music go-librespot[27783]: time="2026-02-09T18:22:51-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:51 music go-librespot[27783]: time="2026-02-09T18:22:51-05:00" level=debug msg="completed challenge" Feb 09 18:22:51 music go-librespot[27783]: time="2026-02-09T18:22:51-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:51 music volumio[27811]: info: MYVOLUMIO Environment detected Feb 09 18:22:51 music volumio[27811]: info: Plugin folders cleanup Feb 09 18:22:51 music volumio[27811]: info: Scanning into folder /volumio/app/plugins/ Feb 09 18:22:51 music volumio[27811]: info: Scanning category audio_interface Feb 09 18:22:51 music volumio[27811]: info: Scanning category miscellanea Feb 09 18:22:51 music volumio[27811]: info: Scanning category music_service Feb 09 18:22:51 music volumio[27811]: info: Scanning category plugins.json Feb 09 18:22:51 music volumio[27811]: info: Scanning category system_controller Feb 09 18:22:51 music volumio[27811]: info: Scanning category user_interface Feb 09 18:22:51 music volumio[27811]: info: Scanning into folder /data/plugins/ Feb 09 18:22:51 music volumio[27811]: info: Scanning category music_service Feb 09 18:22:51 music volumio[27811]: info: Plugin folders cleanup completed Feb 09 18:22:51 music volumio[27811]: info: ------------------------------------------- Feb 09 18:22:51 music volumio[27811]: info: ----- Core plugins startup ---- Feb 09 18:22:51 music volumio[27811]: info: ------------------------------------------- Feb 09 18:22:51 music volumio[27811]: info: Loading plugins from folder /volumio/app/plugins/ Feb 09 18:22:51 music volumio[27811]: info: Adding plugin upnp to MyMusic Plugins Feb 09 18:22:51 music volumio[27811]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 09 18:22:51 music volumio[27811]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 09 18:22:51 music volumio[27811]: info: Loading plugins from folder /data/plugins/ Feb 09 18:22:51 music volumio[27811]: info: Loading plugin "system"... Feb 09 18:22:52 music volumio[27811]: info: Loading plugin "appearance"... Feb 09 18:22:52 music go-librespot[27783]: time="2026-02-09T18:22:52-05:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 09 18:22:52 music go-librespot[27783]: time="2026-02-09T18:22:52-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:52 music go-librespot[27783]: time="2026-02-09T18:22:52-05:00" level=debug msg="completed challenge" Feb 09 18:22:52 music go-librespot[27783]: time="2026-02-09T18:22:52-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:52 music go-librespot[27783]: time="2026-02-09T18:22:52-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 09 18:22:52 music go-librespot[27783]: time="2026-02-09T18:22:52-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:52 music go-librespot[27783]: time="2026-02-09T18:22:52-05:00" level=debug msg="completed challenge" Feb 09 18:22:53 music go-librespot[27783]: time="2026-02-09T18:22:53-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:53 music go-librespot[27783]: time="2026-02-09T18:22:53-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 09 18:22:53 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 18:22:53 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 18:22:53 music volumio[27811]: info: Loading plugin "network"... Feb 09 18:22:53 music volumio[27811]: info: Refreshing Cached IP Addresses Feb 09 18:22:53 music sudo[27839]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 18:22:53 music sudo[27839]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:53 music sudo[27841]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 18:22:53 music sudo[27841]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:53 music volumio[27811]: info: Loading plugin "services"... Feb 09 18:22:53 music sudo[27839]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:53 music volumio[27811]: info: Loading plugin "alsa_controller"... Feb 09 18:22:53 music sudo[27841]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:53 music sudo[27848]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 09 18:22:53 music sudo[27848]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:53 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 18:22:53 music volumio[27811]: info: Loading plugin "wizard"... Feb 09 18:22:53 music volumio[27811]: info: Loading plugin "networkfs"... Feb 09 18:22:53 music volumio[27811]: info: Starting Udev Watcher for removable devices Feb 09 18:22:53 music volumio[27811]: info: Ignoring mount for partition: boot Feb 09 18:22:53 music volumio[27811]: info: Ignoring mount for partition: volumio Feb 09 18:22:53 music volumio[27811]: info: Ignoring mount for partition: volumio_data Feb 09 18:22:53 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 18:22:53 music volumio[27811]: info: Loading plugin "volumio_command_line_client"... Feb 09 18:22:53 music volumio[27811]: info: Loading plugin "upnp"... Feb 09 18:22:53 music volumio[27811]: info: [1770679373342] Starting Upmpd Daemon Feb 09 18:22:53 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 18:22:53 music volumio[27811]: info: Loading plugin "my_music"... Feb 09 18:22:53 music volumio[27811]: info: Loading plugin "mpd"... Feb 09 18:22:53 music volumio[27811]: info: Loading plugin "upnp_browser"... Feb 09 18:22:53 music volumio-remote-updater[30265]: [2026-02-09 18:22:53] [connect] Successful connection Feb 09 18:22:53 music sudo[27848]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:55 music volumio[27811]: info: Starting UPNP Browser Feb 09 18:22:55 music volumio[27811]: info: Loading plugin "alarm-clock"... Feb 09 18:22:55 music volumio[27811]: info: Loading plugin "airplay_emulation"... Feb 09 18:22:55 music volumio[27811]: info: Starting Shairport Sync Feb 09 18:22:55 music volumio[27811]: info: Loading plugin "last_100"... Feb 09 18:22:55 music volumio[27811]: info: Loading plugin "webradio"... Feb 09 18:22:55 music volumio[27811]: info: Loading plugin "i2s_dacs"... Feb 09 18:22:55 music volumio[27811]: info: I2S DAC not set, start Auto-detection Feb 09 18:22:55 music volumio[27811]: info: Loading plugin "volumiodiscovery"... Feb 09 18:22:55 music volumio[27811]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 18:22:55 music volumio[27811]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 18:22:55 music volumio[27811]: *** WARNING *** For more information see Feb 09 18:22:55 music volumio[27811]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 18:22:55 music volumio[27811]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 18:22:55 music volumio[27811]: *** WARNING *** For more information see Feb 09 18:22:55 music node[27811]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 18:22:55 music node[27811]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 18:22:55 music node[27811]: *** WARNING *** For more information see Feb 09 18:22:55 music node[27811]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 18:22:55 music node[27811]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 18:22:55 music node[27811]: *** WARNING *** For more information see Feb 09 18:22:55 music volumio[27811]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 09 18:22:55 music volumio[27811]: info: Discovery: Started advertising with name: music Feb 09 18:22:55 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 18:22:55 music volumio[27811]: info: Loading plugin "spop"... Feb 09 18:22:56 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 09 18:22:56 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 18:22:56 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 18:22:56 music go-librespot[27874]: go-librespot daemon starting... Feb 09 18:22:56 music go-librespot[27875]: time="2026-02-09T18:22:56-05:00" level=info msg="running go-librespot 0.6.2" Feb 09 18:22:56 music go-librespot[27875]: time="2026-02-09T18:22:56-05:00" level=debug msg="app state loaded" Feb 09 18:22:56 music go-librespot[27875]: time="2026-02-09T18:22:56-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 18:22:56 music go-librespot[27875]: time="2026-02-09T18:22:56-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 09 18:22:56 music go-librespot[27875]: time="2026-02-09T18:22:56-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 09 18:22:56 music go-librespot[27875]: time="2026-02-09T18:22:56-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 09 18:22:56 music go-librespot[27875]: time="2026-02-09T18:22:56-05:00" level=info msg="zeroconf server listening on port 39049" Feb 09 18:22:56 music go-librespot[27875]: time="2026-02-09T18:22:56-05:00" level=debug msg="obtained new client token: AADRfW10CdpFhAGMmKh69RsSjahcPUEZpBScRf+e/FxtGTC0ZlpWlUYi6iapi0t4Jz2vyTtQ6b6RFcwBuG6og//Gc3g54K3/scVXB2DcCvrQ/2onCC8h3Mr22Gt0TqhdQSPW7JyQjZOSeac7X7fnoCEeiXHLcEnlR125gKplLDcj0oxAADknFd5zzLBN114WM+9C+4c0o9kNMX2V+Na3VGYXEaOTtdMcCV6y+fO2bQWWsH+nLjddBs0=" Feb 09 18:22:56 music volumio[27811]: info: Loading plugin "outputs"... Feb 09 18:22:56 music volumio[27811]: info: Loading plugin "albumart"... Feb 09 18:22:56 music go-librespot[27875]: time="2026-02-09T18:22:56-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 09 18:22:56 music volumio[27811]: info: Plugin example_plugin is not enabled Feb 09 18:22:56 music volumio[27811]: info: Loading plugin "inputs"... Feb 09 18:22:56 music volumio[27811]: info: Loading plugin "updater_comm"... Feb 09 18:22:56 music go-librespot[27875]: time="2026-02-09T18:22:56-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 09 18:22:56 music go-librespot[27875]: time="2026-02-09T18:22:56-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:56 music go-librespot[27875]: time="2026-02-09T18:22:56-05:00" level=debug msg="completed challenge" Feb 09 18:22:56 music volumio[27811]: info: Plugin mpdemulation is not enabled Feb 09 18:22:56 music volumio[27811]: info: Loading plugin "rest_api"... Feb 09 18:22:56 music volumio[27811]: info: Loading plugin "websocket"... Feb 09 18:22:56 music volumio[27811]: info: Starting Socket.io Server version 1.7.4 Feb 09 18:22:57 music go-librespot[27875]: time="2026-02-09T18:22:57-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:57 music volumio[27811]: info: Loading i18n strings for locale en Feb 09 18:22:57 music volumio[27811]: Updating browse sources language Feb 09 18:22:57 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 18:22:57 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 18:22:57 music volumio[27811]: info: CoreCommandRouter::initPlayerControls Feb 09 18:22:57 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:57 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:57 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:57 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:57 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:57 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:57 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:57 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:57 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 18:22:57 music volumio[27811]: Express server listening on port 3000 Feb 09 18:22:57 music volumio[27811]: [Metrics] WebUI: 6s 626.98ms Feb 09 18:22:57 music volumio[27811]: info: CoreStateMachine::resetVolumioState Feb 09 18:22:57 music volumio[27811]: info: CoreStateMachine::getcurrentVolume Feb 09 18:22:57 music volumio[27811]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 18:22:57 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 18:22:57 music volumio[27811]: info: Volumio Network Manager: Network status updated: 1 Feb 09 18:22:57 music volumio[27884]: Forking 3 albumart workers Feb 09 18:22:57 music volumio[27811]: info: VolumeController:: Volume=86 Mute =false Feb 09 18:22:57 music volumio[27811]: info: CoreStateMachine::pushState Feb 09 18:22:57 music volumio[27811]: info: CorePlayQueue::getTrack 0 Feb 09 18:22:57 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 18:22:57 music volumio[27811]: info: CoreCommandRouter::volumioPushState Feb 09 18:22:57 music volumio[27811]: info: CoreStateMachine::updateTrackBlock Feb 09 18:22:57 music volumio[27811]: info: CorePlayQueue::getTrackBlock Feb 09 18:22:57 music volumio[27811]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 18:22:57 music volumio[27811]: info: CoreCommandRouter::volumioGetState Feb 09 18:22:57 music volumio[27811]: info: CorePlayQueue::getTrack 0 Feb 09 18:22:57 music volumio-remote-updater[30265]: [2026-02-09 18:22:57] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770679373 101 Feb 09 18:22:57 music volumio[27811]: 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 09 18:22:57 music volumio[27811]: info: Reloading queue from file Feb 09 18:22:57 music go-librespot[27875]: time="2026-02-09T18:22:57-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 09 18:22:57 music volumio[27811]: info: CoreStateMachine::setRepeat null single undefined Feb 09 18:22:57 music volumio[27811]: info: CoreStateMachine::pushState Feb 09 18:22:57 music volumio[27811]: info: CorePlayQueue::getTrack 0 Feb 09 18:22:57 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 18:22:57 music volumio[27811]: info: CoreCommandRouter::volumioPushState Feb 09 18:22:57 music volumio[27811]: info: CoreStateMachine::setRandom null Feb 09 18:22:57 music volumio[27811]: info: CoreStateMachine::pushState Feb 09 18:22:57 music volumio[27811]: info: CorePlayQueue::getTrack 0 Feb 09 18:22:57 music volumio[27811]: info: CoreCommandRouter::volumioPushState Feb 09 18:22:57 music volumio[27811]: info: Setting Device type: Raspberry PI Feb 09 18:22:57 music volumio[27811]: info: Listing playlists Feb 09 18:22:57 music volumio[27811]: info: Listing playlists Feb 09 18:22:57 music go-librespot[27875]: time="2026-02-09T18:22:57-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:57 music go-librespot[27875]: time="2026-02-09T18:22:57-05:00" level=debug msg="completed challenge" Feb 09 18:22:57 music volumio[27811]: info: VolumeController:: Volume=86 Mute =false Feb 09 18:22:57 music volumio[27811]: info: CoreStateMachine::pushState Feb 09 18:22:57 music go-librespot[27875]: time="2026-02-09T18:22:57-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:57 music volumio[27811]: info: CorePlayQueue::getTrack 0 Feb 09 18:22:57 music volumio[27811]: info: CoreCommandRouter::volumioPushState Feb 09 18:22:57 music volumio[27811]: info: Completed loading Core Plugins Feb 09 18:22:57 music volumio[27811]: info: Preparing to generate the ALSA configuration file Feb 09 18:22:57 music volumio[27811]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 09 18:22:57 music volumio[27811]: info: Discovery: Found device music Feb 09 18:22:57 music volumio[27811]: info: CoreCommandRouter::volumioGetState Feb 09 18:22:57 music volumio[27811]: info: CorePlayQueue::getTrack 0 Feb 09 18:22:57 music volumio[27811]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 09 18:22:57 music volumio[27811]: info: Discovery: Found device music Feb 09 18:22:57 music volumio[27811]: info: CoreCommandRouter::volumioGetState Feb 09 18:22:57 music volumio[27811]: info: CorePlayQueue::getTrack 0 Feb 09 18:22:57 music volumio[27811]: info: Asound.conf file unchanged, so no further update is needed Feb 09 18:22:57 music volumio[27811]: info: Output device has changed, restarting MPD Feb 09 18:22:57 music volumio[27811]: info: Output device has changed, restarting Shairport Sync Feb 09 18:22:57 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:57 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 18:22:57 music sudo[27938]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 18:22:57 music sudo[27938]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:57 music sudo[27938]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:57 music sudo[27940]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 18:22:57 music sudo[27940]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:57 music volumio[27811]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 18:22:57 music volumio[27811]: info: ___________ START PLUGINS ___________ Feb 09 18:22:57 music volumio[27811]: info: ControllerMpd::onStart: Initializing MPD Feb 09 18:22:57 music volumio[27811]: info: Creating MPD Configuration file Feb 09 18:22:57 music systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 09 18:22:57 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 18:22:57 music volumio[27811]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 18:22:57 music volumio[27811]: info: [1770679377967] CoreMusicLibrary::Adding element Media Servers Feb 09 18:22:57 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 18:22:58 music volumio[27811]: info: UPNP Browser: Client initialized successfully Feb 09 18:22:58 music sudo[27949]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 18:22:58 music sudo[27950]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 18:22:58 music sudo[27950]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:58 music sudo[27949]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:58 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:58 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 18:22:58 music systemd[1]: mpd.service: Deactivated successfully. Feb 09 18:22:58 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 09 18:22:58 music systemd[1]: mpd.service: Consumed 4.156s CPU time. Feb 09 18:22:58 music sudo[27949]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:58 music systemd[1]: mpd.socket: Deactivated successfully. Feb 09 18:22:58 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 09 18:22:58 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 09 18:22:58 music volumio[27811]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 18:22:58 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:58 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 18:22:58 music volumio[27811]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 18:22:58 music volumio[27811]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 18:22:58 music volumio[27811]: info: [1770679378124] CoreMusicLibrary::Adding element Last_100 Feb 09 18:22:58 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 18:22:58 music volumio[27811]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 18:22:58 music volumio[27811]: info: [1770679378140] CoreMusicLibrary::Adding element Webradio Feb 09 18:22:58 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 18:22:58 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 18:22:58 music volumio[27811]: info: Initializing BBC Radios Feb 09 18:22:58 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 09 18:22:58 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 09 18:22:58 music systemd[1]: mpd.service: Deactivated successfully. Feb 09 18:22:58 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 09 18:22:58 music systemd[1]: mpd.socket: Deactivated successfully. Feb 09 18:22:58 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 09 18:22:58 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 09 18:22:58 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 09 18:22:58 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 09 18:22:58 music go-librespot[27875]: time="2026-02-09T18:22:58-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 09 18:22:58 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 18:22:58 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 18:22:58 music go-librespot[27875]: time="2026-02-09T18:22:58-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:58 music go-librespot[27875]: time="2026-02-09T18:22:58-05:00" level=debug msg="completed challenge" Feb 09 18:22:58 music volumio[27811]: info: Creating Spotify config file Feb 09 18:22:58 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:58 music go-librespot[27875]: time="2026-02-09T18:22:58-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:58 music sudo[27973]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 09 18:22:58 music sudo[27973]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 09 18:22:58 music sudo[27973]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:58 music volumio[27811]: info: Volumio Calling Home Feb 09 18:22:59 music go-librespot[27875]: time="2026-02-09T18:22:59-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 09 18:22:59 music volumio[27899]: Starting albumart workers Feb 09 18:22:59 music go-librespot[27875]: time="2026-02-09T18:22:59-05:00" level=debug msg="completed keyexchange" Feb 09 18:22:59 music go-librespot[27875]: time="2026-02-09T18:22:59-05:00" level=debug msg="completed challenge" Feb 09 18:22:59 music volumio[27811]: info: MPD Permissions set Feb 09 18:22:59 music volumio[27811]: info: MPD Permissions set Feb 09 18:22:59 music volumio[27811]: info: Spotify config file written Feb 09 18:22:59 music volumio[27811]: 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 09 18:22:59 music volumio[27811]: info: Volumio called home Feb 09 18:22:59 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:59 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:59 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:59 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:59 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:59 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:59 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:59 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:59 music sudo[27984]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 09 18:22:59 music sudo[27984]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:22:59 music go-librespot[27875]: time="2026-02-09T18:22:59-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:22:59 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 18:22:59 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:59 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:59 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:59 music volumio[27901]: Starting albumart workers Feb 09 18:22:59 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:59 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:59 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 09 18:22:59 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:59 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:59 music systemd[1]: go-librespot-daemon.service: Killing process 27880 (go-librespot) with signal SIGKILL. Feb 09 18:22:59 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 09 18:22:59 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 18:22:59 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:59 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:59 music volumio[27902]: Starting albumart workers Feb 09 18:22:59 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 18:22:59 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:22:59 music volumio[27811]: info: No need to fix Spotify hosts Feb 09 18:22:59 music go-librespot[27991]: go-librespot daemon starting... Feb 09 18:22:59 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 18:22:59 music sudo[27984]: pam_unix(sudo:session): session closed for user root Feb 09 18:22:59 music go-librespot[27997]: time="2026-02-09T18:22:59-05:00" level=info msg="running go-librespot 0.6.2" Feb 09 18:22:59 music go-librespot[27997]: time="2026-02-09T18:22:59-05:00" level=debug msg="app state loaded" Feb 09 18:22:59 music go-librespot[27997]: time="2026-02-09T18:22:59-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 18:23:00 music volumio[27811]: info: Starting Shairport Sync Feb 09 18:23:00 music volumio[27811]: info: Starting Shairport Sync Feb 09 18:23:00 music go-librespot[27997]: time="2026-02-09T18: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 18:23:00 music go-librespot[27997]: time="2026-02-09T18:23:00-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 09 18:23:00 music go-librespot[27997]: time="2026-02-09T18:23:00-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 09 18:23:00 music go-librespot[27997]: time="2026-02-09T18:23:00-05:00" level=info msg="zeroconf server listening on port 44343" Feb 09 18:23:00 music volumio[27811]: info: Starting Shairport Sync Feb 09 18:23:00 music sudo[28008]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 18:23:00 music sudo[28008]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:23:00 music sudo[28013]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 18:23:00 music sudo[28013]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:23:00 music sudo[28010]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 18:23:00 music sudo[28010]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:23:00 music volumio[27811]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 09 18:23:00 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 09 18:23:00 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 09 18:23:00 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 18:23:00 music systemd[1]: shairport-sync.service: Consumed 1.803s CPU time. Feb 09 18:23:00 music go-librespot[27997]: time="2026-02-09T18:23:00-05:00" level=debug msg="obtained new client token: AACb7AYMep83H7xhVCndUljvFzDuGkfed3l7j3LuXW6NKOId3VZsGtVZxEu+wNzSJcx9/9DUCgjTzvqDcJKd819ETy6iKDsnDQYG2jZFhWK/sDs9hq6JCGu10WZqNJkNMbzfgURB1vr0XtR0jd6ZU2d0qgxxLJglHX7cphduVwnE0GBWSAiukPMDAixv/3ticV98I0da9y4f+rRDanEhZFzeN9ZckaadOK9sQ0wb7lRcZ2rf1OjT1D4=" Feb 09 18:23:00 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 18:23:00 music sudo[28008]: pam_unix(sudo:session): session closed for user root Feb 09 18:23:00 music go-librespot[27997]: time="2026-02-09T18:23:00-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 09 18:23:00 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 09 18:23:00 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 09 18:23:00 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 18:23:00 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 18:23:00 music sudo[28013]: pam_unix(sudo:session): session closed for user root Feb 09 18:23:00 music sudo[28010]: pam_unix(sudo:session): session closed for user root Feb 09 18:23:00 music go-librespot[27997]: time="2026-02-09T18:23:00-05:00" level=debug msg="completed keyexchange" Feb 09 18:23:00 music go-librespot[27997]: time="2026-02-09T18:23:00-05:00" level=debug msg="completed challenge" Feb 09 18:23:00 music go-librespot[27997]: time="2026-02-09T18:23:00-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:23:01 music volumio[27811]: info: Shairport-Sync Started Feb 09 18:23:01 music volumio[27811]: Error adding Membership: Error: addMembership EINVAL Feb 09 18:23:01 music volumio[27811]: info: Shairport-Sync Started Feb 09 18:23:01 music volumio[27811]: info: Shairport-Sync Started Feb 09 18:23:01 music volumio[27811]: info: CoreCommandRouter::volumioGetState Feb 09 18:23:01 music volumio[27811]: info: CorePlayQueue::getTrack 0 Feb 09 18:23:01 music go-librespot[27997]: time="2026-02-09T18:23:01-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 09 18:23:01 music go-librespot[27997]: time="2026-02-09T18:23:01-05:00" level=debug msg="completed keyexchange" Feb 09 18:23:01 music go-librespot[27997]: time="2026-02-09T18:23:01-05:00" level=debug msg="completed challenge" Feb 09 18:23:01 music go-librespot[27997]: time="2026-02-09T18:23:01-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:23:01 music volumio[27811]: info: CoreCommandRouter::volumioGetState Feb 09 18:23:01 music volumio[27811]: info: CorePlayQueue::getTrack 0 Feb 09 18:23:02 music go-librespot[27997]: time="2026-02-09T18:23:02-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 09 18:23:02 music go-librespot[27997]: time="2026-02-09T18:23:02-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 09 18:23:02 music go-librespot[27997]: time="2026-02-09T18:23:02-05:00" level=debug msg="completed keyexchange" Feb 09 18:23:02 music go-librespot[27997]: time="2026-02-09T18:23:02-05:00" level=debug msg="completed challenge" Feb 09 18:23:02 music go-librespot[27997]: time="2026-02-09T18:23:02-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:23:02 music mpd[27979]: 2026-02-09T18:23:02 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 09 18:23:02 music systemd[1]: Started mpd.service - Music Player Daemon. Feb 09 18:23:02 music sudo[27950]: pam_unix(sudo:session): session closed for user root Feb 09 18:23:02 music sudo[27940]: pam_unix(sudo:session): session closed for user root Feb 09 18:23:02 music volumio[27811]: info: Completed starting Core Plugins Feb 09 18:23:02 music volumio[27811]: info: ------------------------------------------- Feb 09 18:23:02 music volumio[27811]: info: ----- MyVolumio plugins startup ---- Feb 09 18:23:02 music volumio[27811]: info: ------------------------------------------- Feb 09 18:23:02 music volumio[27811]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 09 18:23:02 music volumio[27811]: error: MPD error: The expression evaluated to a falsy value: Feb 09 18:23:02 music volumio[27811]: assert.ok(self.idling) Feb 09 18:23:02 music volumio[27811]: error: The expression evaluated to a falsy value: Feb 09 18:23:02 music volumio[27811]: assert.ok(self.idling) Feb 09 18:23:02 music volumio[27811]: info: MPD running with PID27979 Feb 09 18:23:02 music volumio[27811]: ,establishing connection Feb 09 18:23:02 music volumio[27811]: error: updateQueue error: null Feb 09 18:23:02 music volumio[27811]: error: updateQueue error: null Feb 09 18:23:02 music go-librespot[27997]: time="2026-02-09T18:23:02-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 09 18:23:02 music go-librespot[27997]: time="2026-02-09T18:23:02-05:00" level=debug msg="completed keyexchange" Feb 09 18:23:02 music go-librespot[27997]: time="2026-02-09T18:23:02-05:00" level=debug msg="completed challenge" Feb 09 18:23:03 music go-librespot[27997]: time="2026-02-09T18:23:03-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:23:03 music volumio[27811]: info: go-librespot daemon successfully initialized Feb 09 18:23:03 music sudo[28079]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 18:23:03 music sudo[28079]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:23:03 music sudo[28081]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 18:23:03 music sudo[28079]: pam_unix(sudo:session): session closed for user root Feb 09 18:23:03 music sudo[28081]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:23:03 music sudo[28081]: pam_unix(sudo:session): session closed for user root Feb 09 18:23:03 music sudo[28084]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 09 18:23:03 music sudo[28084]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:23:03 music sudo[28084]: pam_unix(sudo:session): session closed for user root Feb 09 18:23:03 music volumio[27811]: info: Upmpdcli Daemon Started Feb 09 18:23:03 music go-librespot[27997]: time="2026-02-09T18:23:03-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 09 18:23:03 music go-librespot[27997]: time="2026-02-09T18:23:03-05:00" level=debug msg="completed keyexchange" Feb 09 18:23:03 music go-librespot[27997]: time="2026-02-09T18:23:03-05:00" level=debug msg="completed challenge" Feb 09 18:23:03 music go-librespot[27997]: time="2026-02-09T18:23:03-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:23:04 music go-librespot[27997]: time="2026-02-09T18:23:04-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 09 18:23:04 music go-librespot[27997]: time="2026-02-09T18:23:04-05:00" level=debug msg="completed keyexchange" Feb 09 18:23:04 music go-librespot[27997]: time="2026-02-09T18:23:04-05:00" level=debug msg="completed challenge" Feb 09 18:23:04 music go-librespot[27997]: time="2026-02-09T18:23:04-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:23:04 music go-librespot[27997]: time="2026-02-09T18:23:04-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 09 18:23:04 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 18:23:04 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 18:23:05 music sudo[28091]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 09 18:23:05 music sudo[28091]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:23:05 music sudo[28094]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 09 18:23:05 music sudo[28094]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:23:05 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 09 18:23:05 music systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 09 18:23:05 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 09 18:23:05 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 09 18:23:05 music sudo[28091]: pam_unix(sudo:session): session closed for user root Feb 09 18:23:05 music volumio[27811]: info: Successfully started MPD Monitor Feb 09 18:23:05 music mpd_monitor.sh[28096]: MPD Monitor Service: Starting MPD Monitor Service Feb 09 18:23:05 music sudo[28094]: pam_unix(sudo:session): session closed for user root Feb 09 18:23:05 music volumio[27811]: info: Successfully started MPD Monitor Feb 09 18:23:06 music volumio[27811]: info: Initializing connection to go-librespot Websocket Feb 09 18:23:06 music volumio[27811]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 18:23:07 music volumio[27811]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 09 18:23:07 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 09 18:23:07 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 18:23:07 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 18:23:07 music go-librespot[28100]: go-librespot daemon starting... Feb 09 18:23:07 music go-librespot[28101]: time="2026-02-09T18:23:07-05:00" level=info msg="running go-librespot 0.6.2" Feb 09 18:23:07 music go-librespot[28101]: time="2026-02-09T18:23:07-05:00" level=debug msg="app state loaded" Feb 09 18:23:07 music go-librespot[28101]: time="2026-02-09T18:23:07-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 18:23:08 music go-librespot[28101]: time="2026-02-09T18:23:08-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 09 18:23:08 music go-librespot[28101]: time="2026-02-09T18:23:08-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 09 18:23:08 music go-librespot[28101]: time="2026-02-09T18:23:08-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 09 18:23:08 music go-librespot[28101]: time="2026-02-09T18:23:08-05:00" level=info msg="zeroconf server listening on port 45849" Feb 09 18:23:08 music go-librespot[28101]: time="2026-02-09T18:23:08-05:00" level=debug msg="obtained new client token: AACSIbx8KKoD9B+vZ1LqhwdwsB8LprbVdHPYeEVjvG24Mhfqu9lQgtIZiCUBoDejRGTxwGG1Qdwdbdx2KmVMKOKAEtEblvNbtmthEtgj6uiib8ecUxpkXN7f+8arUtEZ+ZrwtjjZdRiZWoflXwpIqa9st0dSUKVSQ2597YGIC5DiLHdbw7bMp7zCPHkcR+DrjTIsJyNtC02bm8D/sfavi0eAC3alwKHB9vimJhASlr0AuKCOoA6G2T8=" Feb 09 18:23:08 music go-librespot[28101]: time="2026-02-09T18:23:08-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 09 18:23:08 music go-librespot[28101]: time="2026-02-09T18:23:08-05:00" level=debug msg="completed keyexchange" Feb 09 18:23:08 music go-librespot[28101]: time="2026-02-09T18:23:08-05:00" level=debug msg="completed challenge" Feb 09 18:23:08 music go-librespot[28101]: time="2026-02-09T18:23:08-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:23:09 music go-librespot[28101]: time="2026-02-09T18:23:09-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 09 18:23:09 music go-librespot[28101]: time="2026-02-09T18:23:09-05:00" level=debug msg="completed keyexchange" Feb 09 18:23:09 music go-librespot[28101]: time="2026-02-09T18:23:09-05:00" level=debug msg="completed challenge" Feb 09 18:23:09 music go-librespot[28101]: time="2026-02-09T18:23:09-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:23:09 music volumio[27811]: info: Initializing connection to go-librespot Websocket Feb 09 18:23:09 music go-librespot[28101]: time="2026-02-09T18:23:09-05:00" level=debug msg="new websocket client" Feb 09 18:23:09 music volumio[27811]: info: Connection to go-librespot Websocket established Feb 09 18:23:09 music go-librespot[28101]: time="2026-02-09T18:23:09-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 09 18:23:09 music go-librespot[28101]: time="2026-02-09T18:23:09-05:00" level=debug msg="completed keyexchange" Feb 09 18:23:09 music go-librespot[28101]: time="2026-02-09T18:23:09-05:00" level=debug msg="completed challenge" Feb 09 18:23:09 music go-librespot[28101]: time="2026-02-09T18:23:09-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:23:10 music go-librespot[28101]: time="2026-02-09T18:23:10-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 09 18:23:10 music go-librespot[28101]: time="2026-02-09T18:23:10-05:00" level=debug msg="completed keyexchange" Feb 09 18:23:10 music go-librespot[28101]: time="2026-02-09T18:23:10-05:00" level=debug msg="completed challenge" Feb 09 18:23:10 music go-librespot[28101]: time="2026-02-09T18:23:10-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:23:10 music volumio[27811]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 09 18:23:10 music volumio[27811]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 09 18:23:10 music volumio[27811]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 09 18:23:10 music volumio[27811]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 09 18:23:10 music volumio[27811]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 09 18:23:10 music volumio[27811]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 09 18:23:10 music volumio[27811]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 09 18:23:10 music volumio[27811]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 09 18:23:10 music volumio[27811]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 09 18:23:10 music volumio[27811]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 09 18:23:10 music volumio[27811]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 09 18:23:10 music volumio[27811]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 09 18:23:10 music volumio[27811]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 09 18:23:10 music volumio[27811]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 09 18:23:10 music volumio[27811]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 09 18:23:10 music volumio[27811]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 09 18:23:10 music volumio[27811]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 09 18:23:10 music volumio[27811]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 09 18:23:10 music volumio[27811]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 09 18:23:10 music volumio[27811]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 09 18:23:10 music volumio[27811]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 09 18:23:10 music volumio[27811]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 09 18:23:10 music volumio[27811]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 09 18:23:10 music volumio[27811]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 09 18:23:10 music volumio[27811]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 09 18:23:10 music volumio[27811]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 09 18:23:10 music volumio[27811]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 09 18:23:10 music volumio[27811]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 09 18:23:10 music volumio[27811]: info: Adding plugin bluetooth to MyMusic Plugins Feb 09 18:23:10 music volumio[27811]: info: Adding plugin multiroom to MyMusic Plugins Feb 09 18:23:10 music volumio[27811]: info: Adding plugin metavolumio to MyMusic Plugins Feb 09 18:23:10 music volumio[27811]: info: Adding plugin cd_controller to MyMusic Plugins Feb 09 18:23:10 music volumio[27811]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 09 18:23:10 music volumio[27811]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 09 18:23:10 music volumio[27811]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 09 18:23:10 music volumio[27811]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 09 18:23:11 music go-librespot[28101]: time="2026-02-09T18:23:11-05:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.241.202:443: connect: connection refused" Feb 09 18:23:11 music go-librespot[28101]: time="2026-02-09T18:23:11-05:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 09 18:23:11 music go-librespot[28101]: time="2026-02-09T18:23:11-05:00" level=debug msg="completed keyexchange" Feb 09 18:23:11 music go-librespot[28101]: time="2026-02-09T18:23:11-05:00" level=debug msg="completed challenge" Feb 09 18:23:11 music go-librespot[28101]: time="2026-02-09T18:23:11-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:23:11 music volumio[27811]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 09 18:23:11 music volumio[27811]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 09 18:23:11 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 18:23:11 music volumio[27811]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 18:23:12 music volumio[27811]: info: Starting MyVolumio Remote Streaming Endpoints Feb 09 18:23:12 music volumio[27811]: info: MyVolumio login type: Token Feb 09 18:23:12 music volumio[27811]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 09 18:23:12 music volumio[27811]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 09 18:23:12 music go-librespot[28101]: time="2026-02-09T18:23:12-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 09 18:23:12 music go-librespot[28101]: time="2026-02-09T18:23:12-05:00" level=debug msg="completed keyexchange" Feb 09 18:23:12 music go-librespot[28101]: time="2026-02-09T18:23:12-05:00" level=debug msg="completed challenge" Feb 09 18:23:12 music go-librespot[28101]: time="2026-02-09T18:23:12-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:23:12 music go-librespot[28101]: time="2026-02-09T18:23:12-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 09 18:23:12 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 18:23:12 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 18:23:12 music volumio[27811]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 09 18:23:12 music volumio[27811]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 09 18:23:12 music volumio[27811]: info: Streaming services startup Feb 09 18:23:12 music volumio[27811]: info: Starting Streaming Daemon Feb 09 18:23:12 music sudo[28111]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 09 18:23:13 music sudo[28111]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:23:13 music volumio[27811]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 09 18:23:13 music sudo[28111]: pam_unix(sudo:session): session closed for user root Feb 09 18:23:13 music volumio[27811]: info: Getting Spotify volume Feb 09 18:23:13 music volumio[27811]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 18:23:13 music volumio[27811]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 18:23:13 music volumio[27811]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 09 18:23:13 music volumio[27811]: errno: -111, Feb 09 18:23:13 music volumio[27811]: code: 'ECONNREFUSED', Feb 09 18:23:13 music volumio[27811]: syscall: 'connect', Feb 09 18:23:13 music volumio[27811]: address: '127.0.0.1', Feb 09 18:23:13 music volumio[27811]: port: 9879, Feb 09 18:23:13 music volumio[27811]: response: undefined Feb 09 18:23:13 music volumio[27811]: } Feb 09 18:23:13 music volumio[27811]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 18:23:13 music sudo[28146]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-09 18:22' Feb 09 18:23:13 music sudo[28146]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:23:14 music sudo[28146]: pam_unix(sudo:session): session closed for user root Feb 09 18:23:14 music volumio-remote-updater[30265]: [2026-02-09 18:23:14] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 09 18:23:14 music volumio-remote-updater[30265]: [2026-02-09 18:23:14] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 09 18:23:14 music systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 09 18:23:14 music systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 09 18:23:14 music systemd[1]: volumio.service: Consumed 26.449s CPU time. Feb 09 18:23:14 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 09 18:23:14 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 09 18:23:14 music systemd[1]: volumio.service: Scheduled restart job, restart counter is at 53187. Feb 09 18:23:14 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 09 18:23:14 music systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 09 18:23:14 music systemd[1]: volumio.service: Consumed 26.449s CPU time. Feb 09 18:23:14 music systemd[1]: Started volumio.service - Volumio Backend Module. Feb 09 18:23:14 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 09 18:23:15 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 09 18:23:15 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 18:23:15 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 18:23:15 music go-librespot[28173]: go-librespot daemon starting... Feb 09 18:23:15 music go-librespot[28174]: time="2026-02-09T18:23:15-05:00" level=info msg="running go-librespot 0.6.2" Feb 09 18:23:15 music go-librespot[28174]: time="2026-02-09T18:23:15-05:00" level=debug msg="app state loaded" Feb 09 18:23:15 music go-librespot[28174]: time="2026-02-09T18:23:15-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 18:23:15 music go-librespot[28174]: time="2026-02-09T18:23:15-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 09 18:23:15 music go-librespot[28174]: time="2026-02-09T18:23:15-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 09 18:23:15 music go-librespot[28174]: time="2026-02-09T18:23:15-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 09 18:23:15 music go-librespot[28174]: time="2026-02-09T18:23:15-05:00" level=info msg="zeroconf server listening on port 37645" Feb 09 18:23:16 music go-librespot[28174]: time="2026-02-09T18:23:16-05:00" level=debug msg="obtained new client token: AAAI4hEIEBjCFwfO4mYLJgRF7tHCL0RqNyg+Ki6+G6dekSOHc1k28Lx33gye/v3LW+nCEWarKRaXAH/gDaGPli1TqZcRxcgT6ROvakbPHubSSNpfi70RIol4tj+RYgvHC/2aKxNRWsT/bEUSqlBllP+jAxiS0BMOlJcFQQKbEBMOx92tBx0veNeGEJAfG7FYoYK1qDNnoNzWsGn7erxSvzXWzNrkI09gQQYFVvDzkBN3h3XZKDxL" Feb 09 18:23:16 music go-librespot[28174]: time="2026-02-09T18:23:16-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 09 18:23:16 music go-librespot[28174]: time="2026-02-09T18:23:16-05:00" level=debug msg="completed keyexchange" Feb 09 18:23:16 music go-librespot[28174]: time="2026-02-09T18:23:16-05:00" level=debug msg="completed challenge" Feb 09 18:23:16 music volumio[28158]: info: ------------------------------------------- Feb 09 18:23:16 music volumio[28158]: info: ----- Volumio3 ---- Feb 09 18:23:16 music volumio[28158]: info: ------------------------------------------- Feb 09 18:23:16 music volumio[28158]: info: ----- System startup ---- Feb 09 18:23:16 music volumio[28158]: info: ------------------------------------------- Feb 09 18:23:16 music go-librespot[28174]: time="2026-02-09T18:23:16-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:23:16 music go-librespot[28174]: time="2026-02-09T18:23:16-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 09 18:23:16 music go-librespot[28174]: time="2026-02-09T18:23:16-05:00" level=debug msg="completed keyexchange" Feb 09 18:23:16 music go-librespot[28174]: time="2026-02-09T18:23:16-05:00" level=debug msg="completed challenge" Feb 09 18:23:17 music go-librespot[28174]: time="2026-02-09T18:23:17-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:23:17 music volumio[28158]: info: MYVOLUMIO Environment detected Feb 09 18:23:17 music volumio[28158]: info: Plugin folders cleanup Feb 09 18:23:17 music volumio[28158]: info: Scanning into folder /volumio/app/plugins/ Feb 09 18:23:17 music volumio[28158]: info: Scanning category audio_interface Feb 09 18:23:17 music volumio[28158]: info: Scanning category miscellanea Feb 09 18:23:17 music volumio[28158]: info: Scanning category music_service Feb 09 18:23:17 music volumio[28158]: info: Scanning category plugins.json Feb 09 18:23:17 music volumio[28158]: info: Scanning category system_controller Feb 09 18:23:17 music volumio[28158]: info: Scanning category user_interface Feb 09 18:23:17 music volumio[28158]: info: Scanning into folder /data/plugins/ Feb 09 18:23:17 music volumio[28158]: info: Scanning category music_service Feb 09 18:23:17 music volumio[28158]: info: Plugin folders cleanup completed Feb 09 18:23:17 music volumio[28158]: info: ------------------------------------------- Feb 09 18:23:17 music volumio[28158]: info: ----- Core plugins startup ---- Feb 09 18:23:17 music volumio[28158]: info: ------------------------------------------- Feb 09 18:23:17 music volumio[28158]: info: Loading plugins from folder /volumio/app/plugins/ Feb 09 18:23:17 music volumio[28158]: info: Adding plugin upnp to MyMusic Plugins Feb 09 18:23:17 music volumio[28158]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 09 18:23:17 music volumio[28158]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 09 18:23:17 music volumio[28158]: info: Loading plugins from folder /data/plugins/ Feb 09 18:23:17 music volumio[28158]: info: Loading plugin "system"... Feb 09 18:23:17 music volumio[28158]: info: Loading plugin "appearance"... Feb 09 18:23:17 music go-librespot[28174]: time="2026-02-09T18:23:17-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 09 18:23:17 music go-librespot[28174]: time="2026-02-09T18:23:17-05:00" level=debug msg="completed keyexchange" Feb 09 18:23:17 music go-librespot[28174]: time="2026-02-09T18:23:17-05:00" level=debug msg="completed challenge" Feb 09 18:23:17 music go-librespot[28174]: time="2026-02-09T18:23:17-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:23:18 music volumio[28158]: info: Loading plugin "network"... Feb 09 18:23:18 music volumio[28158]: info: Refreshing Cached IP Addresses Feb 09 18:23:18 music sudo[28197]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 18:23:18 music sudo[28197]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:23:18 music sudo[28199]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 18:23:18 music sudo[28197]: pam_unix(sudo:session): session closed for user root Feb 09 18:23:18 music sudo[28199]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:23:18 music volumio[28158]: info: Loading plugin "services"... Feb 09 18:23:18 music volumio[28158]: info: Loading plugin "alsa_controller"... Feb 09 18:23:18 music sudo[28199]: pam_unix(sudo:session): session closed for user root Feb 09 18:23:18 music sudo[28207]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 09 18:23:18 music sudo[28207]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:23:18 music go-librespot[28174]: time="2026-02-09T18:23:18-05:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 18:23:18 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 18:23:18 music volumio[28158]: info: Loading plugin "wizard"... Feb 09 18:23:18 music volumio[28158]: info: Loading plugin "networkfs"... Feb 09 18:23:18 music volumio[28158]: info: Starting Udev Watcher for removable devices Feb 09 18:23:18 music volumio[28158]: info: Ignoring mount for partition: boot Feb 09 18:23:18 music volumio[28158]: info: Ignoring mount for partition: volumio Feb 09 18:23:18 music volumio[28158]: info: Ignoring mount for partition: volumio_data Feb 09 18:23:18 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 18:23:18 music volumio[28158]: info: Loading plugin "volumio_command_line_client"... Feb 09 18:23:18 music volumio[28158]: info: Loading plugin "upnp"... Feb 09 18:23:18 music volumio[28158]: info: [1770679398542] Starting Upmpd Daemon Feb 09 18:23:18 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 18:23:18 music volumio[28158]: info: Loading plugin "my_music"... Feb 09 18:23:18 music volumio[28158]: info: Loading plugin "mpd"... Feb 09 18:23:18 music go-librespot[28174]: time="2026-02-09T18:23:18-05:00" level=debug msg="completed keyexchange" Feb 09 18:23:18 music go-librespot[28174]: time="2026-02-09T18:23:18-05:00" level=debug msg="completed challenge" Feb 09 18:23:18 music go-librespot[28174]: time="2026-02-09T18:23:18-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:23:18 music volumio[28158]: info: Loading plugin "upnp_browser"... Feb 09 18:23:18 music sudo[28207]: pam_unix(sudo:session): session closed for user root Feb 09 18:23:19 music volumio-remote-updater[30265]: [2026-02-09 18:23:19] [connect] Successful connection Feb 09 18:23:19 music go-librespot[28174]: time="2026-02-09T18:23:19-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 09 18:23:19 music go-librespot[28174]: time="2026-02-09T18:23:19-05:00" level=debug msg="completed keyexchange" Feb 09 18:23:19 music go-librespot[28174]: time="2026-02-09T18:23:19-05:00" level=debug msg="completed challenge" Feb 09 18:23:19 music go-librespot[28174]: time="2026-02-09T18:23:19-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:23:20 music go-librespot[28174]: time="2026-02-09T18:23:20-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 09 18:23:20 music volumio[28158]: info: Starting UPNP Browser Feb 09 18:23:20 music volumio[28158]: info: Loading plugin "alarm-clock"... Feb 09 18:23:20 music volumio[28158]: info: Loading plugin "airplay_emulation"... Feb 09 18:23:20 music volumio[28158]: info: Starting Shairport Sync Feb 09 18:23:20 music volumio[28158]: info: Loading plugin "last_100"... Feb 09 18:23:20 music go-librespot[28174]: time="2026-02-09T18:23:20-05:00" level=debug msg="completed keyexchange" Feb 09 18:23:20 music go-librespot[28174]: time="2026-02-09T18:23:20-05:00" level=debug msg="completed challenge" Feb 09 18:23:20 music volumio[28158]: info: Loading plugin "webradio"... Feb 09 18:23:20 music volumio[28158]: info: Loading plugin "i2s_dacs"... Feb 09 18:23:20 music volumio[28158]: info: I2S DAC not set, start Auto-detection Feb 09 18:23:20 music go-librespot[28174]: time="2026-02-09T18:23:20-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:23:20 music go-librespot[28174]: time="2026-02-09T18:23:20-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 09 18:23:20 music volumio[28158]: info: Loading plugin "volumiodiscovery"... Feb 09 18:23:20 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 18:23:20 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 18:23:20 music volumio[28158]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 18:23:20 music volumio[28158]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 18:23:20 music volumio[28158]: *** WARNING *** For more information see Feb 09 18:23:20 music volumio[28158]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 18:23:20 music volumio[28158]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 18:23:20 music volumio[28158]: *** WARNING *** For more information see Feb 09 18:23:20 music node[28158]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 18:23:20 music node[28158]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 18:23:20 music node[28158]: *** WARNING *** For more information see Feb 09 18:23:20 music node[28158]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 18:23:20 music node[28158]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 18:23:20 music node[28158]: *** WARNING *** For more information see Feb 09 18:23:20 music volumio[28158]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 09 18:23:20 music volumio[28158]: info: Discovery: Started advertising with name: music Feb 09 18:23:20 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 18:23:20 music volumio[28158]: info: Loading plugin "spop"... Feb 09 18:23:21 music volumio[28158]: info: Loading plugin "outputs"... Feb 09 18:23:21 music volumio[28158]: info: Loading plugin "albumart"... Feb 09 18:23:21 music volumio[28158]: info: Plugin example_plugin is not enabled Feb 09 18:23:21 music volumio[28158]: info: Loading plugin "inputs"... Feb 09 18:23:21 music volumio[28158]: info: Loading plugin "updater_comm"... Feb 09 18:23:22 music volumio[28158]: info: Plugin mpdemulation is not enabled Feb 09 18:23:22 music volumio[28158]: info: Loading plugin "rest_api"... Feb 09 18:23:22 music volumio[28158]: info: Loading plugin "websocket"... Feb 09 18:23:22 music volumio[28158]: info: Starting Socket.io Server version 1.7.4 Feb 09 18:23:22 music volumio[28158]: info: Loading i18n strings for locale en Feb 09 18:23:22 music volumio[28158]: Updating browse sources language Feb 09 18:23:22 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 18:23:22 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 18:23:22 music volumio[28158]: info: CoreCommandRouter::initPlayerControls Feb 09 18:23:22 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:23:22 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:23:22 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:23:22 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:23:22 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:23:22 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:23:22 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:23:22 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:23:22 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 18:23:22 music volumio[28158]: Express server listening on port 3000 Feb 09 18:23:22 music volumio[28158]: [Metrics] WebUI: 6s 550.03ms Feb 09 18:23:22 music volumio[28158]: info: CoreStateMachine::resetVolumioState Feb 09 18:23:22 music volumio[28158]: info: CoreStateMachine::getcurrentVolume Feb 09 18:23:22 music volumio[28158]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 18:23:22 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 18:23:22 music volumio[28158]: info: Volumio Network Manager: Network status updated: 1 Feb 09 18:23:22 music volumio-remote-updater[30265]: [2026-02-09 18:23:22] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770679399 101 Feb 09 18:23:22 music volumio[28232]: Forking 3 albumart workers Feb 09 18:23:22 music volumio[28158]: 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 09 18:23:22 music volumio[28158]: info: VolumeController:: Volume=86 Mute =false Feb 09 18:23:22 music volumio[28158]: info: CoreStateMachine::pushState Feb 09 18:23:22 music volumio[28158]: info: CorePlayQueue::getTrack 0 Feb 09 18:23:22 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 18:23:22 music volumio[28158]: info: CoreCommandRouter::volumioPushState Feb 09 18:23:22 music volumio[28158]: info: CoreStateMachine::updateTrackBlock Feb 09 18:23:22 music volumio[28158]: info: CorePlayQueue::getTrackBlock Feb 09 18:23:22 music volumio[28158]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 18:23:22 music volumio[28158]: info: Reloading queue from file Feb 09 18:23:22 music volumio[28158]: info: CoreCommandRouter::volumioGetState Feb 09 18:23:22 music volumio[28158]: info: CorePlayQueue::getTrack 0 Feb 09 18:23:22 music volumio[28158]: info: CoreStateMachine::setRepeat null single undefined Feb 09 18:23:22 music volumio[28158]: info: CoreStateMachine::pushState Feb 09 18:23:22 music volumio[28158]: info: CorePlayQueue::getTrack 0 Feb 09 18:23:22 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 18:23:22 music volumio[28158]: info: CoreCommandRouter::volumioPushState Feb 09 18:23:22 music volumio[28158]: info: CoreStateMachine::setRandom null Feb 09 18:23:22 music volumio[28158]: info: CoreStateMachine::pushState Feb 09 18:23:22 music volumio[28158]: info: CorePlayQueue::getTrack 0 Feb 09 18:23:22 music volumio[28158]: info: CoreCommandRouter::volumioPushState Feb 09 18:23:22 music volumio[28158]: info: Setting Device type: Raspberry PI Feb 09 18:23:22 music volumio[28158]: info: VolumeController:: Volume=86 Mute =false Feb 09 18:23:22 music volumio[28158]: info: CoreStateMachine::pushState Feb 09 18:23:22 music volumio[28158]: info: CorePlayQueue::getTrack 0 Feb 09 18:23:22 music volumio[28158]: info: CoreCommandRouter::volumioPushState Feb 09 18:23:22 music volumio[28158]: info: Listing playlists Feb 09 18:23:22 music volumio[28158]: info: Listing playlists Feb 09 18:23:22 music volumio[28158]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 09 18:23:22 music volumio[28158]: info: Discovery: Found device music Feb 09 18:23:22 music volumio[28158]: info: CoreCommandRouter::volumioGetState Feb 09 18:23:22 music volumio[28158]: info: CorePlayQueue::getTrack 0 Feb 09 18:23:22 music volumio[28158]: info: Completed loading Core Plugins Feb 09 18:23:22 music volumio[28158]: info: Preparing to generate the ALSA configuration file Feb 09 18:23:22 music volumio[28158]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 09 18:23:22 music volumio[28158]: info: Discovery: Found device music Feb 09 18:23:22 music volumio[28158]: info: CoreCommandRouter::volumioGetState Feb 09 18:23:22 music volumio[28158]: info: CorePlayQueue::getTrack 0 Feb 09 18:23:22 music volumio[28158]: info: Asound.conf file unchanged, so no further update is needed Feb 09 18:23:22 music volumio[28158]: info: Output device has changed, restarting MPD Feb 09 18:23:23 music volumio[28158]: info: Output device has changed, restarting Shairport Sync Feb 09 18:23:23 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:23:23 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 18:23:23 music sudo[28287]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 18:23:23 music sudo[28287]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:23:23 music volumio[28158]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 18:23:23 music sudo[28289]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 18:23:23 music sudo[28287]: pam_unix(sudo:session): session closed for user root Feb 09 18:23:23 music volumio[28158]: info: ___________ START PLUGINS ___________ Feb 09 18:23:23 music sudo[28289]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:23:23 music volumio[28158]: info: ControllerMpd::onStart: Initializing MPD Feb 09 18:23:23 music volumio[28158]: info: Creating MPD Configuration file Feb 09 18:23:23 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 18:23:23 music volumio[28158]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 18:23:23 music volumio[28158]: info: [1770679403104] CoreMusicLibrary::Adding element Media Servers Feb 09 18:23:23 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 18:23:23 music systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 09 18:23:23 music sudo[28297]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 18:23:23 music sudo[28297]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:23:23 music volumio[28158]: info: UPNP Browser: Client initialized successfully Feb 09 18:23:23 music sudo[28299]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 18:23:23 music sudo[28299]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:23:23 music sudo[28297]: pam_unix(sudo:session): session closed for user root Feb 09 18:23:23 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:23:23 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 18:23:23 music systemd[1]: mpd.service: Deactivated successfully. Feb 09 18:23:23 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 09 18:23:23 music systemd[1]: mpd.service: Consumed 4.128s CPU time. Feb 09 18:23:23 music systemd[1]: mpd.socket: Deactivated successfully. Feb 09 18:23:23 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 09 18:23:23 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 09 18:23:23 music volumio[28158]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 18:23:23 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:23:23 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 18:23:23 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 09 18:23:23 music volumio[28158]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 18:23:23 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 09 18:23:23 music volumio[28158]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 18:23:23 music volumio[28158]: info: [1770679403342] CoreMusicLibrary::Adding element Last_100 Feb 09 18:23:23 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 18:23:23 music volumio[28158]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 18:23:23 music volumio[28158]: info: [1770679403350] CoreMusicLibrary::Adding element Webradio Feb 09 18:23:23 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 18:23:23 music systemd[1]: mpd.service: Deactivated successfully. Feb 09 18:23:23 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 09 18:23:23 music systemd[1]: mpd.socket: Deactivated successfully. Feb 09 18:23:23 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 18:23:23 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 09 18:23:23 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 09 18:23:23 music volumio[28158]: info: Initializing BBC Radios Feb 09 18:23:23 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 09 18:23:23 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 09 18:23:23 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 18:23:23 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 18:23:23 music volumio[28158]: info: Creating Spotify config file Feb 09 18:23:23 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:23:23 music sudo[28315]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 09 18:23:23 music sudo[28315]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 09 18:23:23 music sudo[28315]: pam_unix(sudo:session): session closed for user root Feb 09 18:23:23 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 09 18:23:23 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 18:23:23 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 18:23:23 music go-librespot[28329]: go-librespot daemon starting... Feb 09 18:23:23 music go-librespot[28330]: time="2026-02-09T18:23:23-05:00" level=info msg="running go-librespot 0.6.2" Feb 09 18:23:24 music go-librespot[28330]: time="2026-02-09T18:23:24-05:00" level=info msg="zeroconf server listening on port 42877" Feb 09 18:23:24 music volumio[28158]: info: Volumio Calling Home Feb 09 18:23:24 music volumio[28250]: Starting albumart workers Feb 09 18:23:24 music volumio[28248]: Starting albumart workers Feb 09 18:23:24 music volumio[28249]: Starting albumart workers Feb 09 18:23:24 music volumio[28158]: info: MPD Permissions set Feb 09 18:23:24 music volumio[28158]: info: MPD Permissions set Feb 09 18:23:25 music volumio[28158]: info: Volumio called home Feb 09 18:23:25 music volumio[28158]: info: Spotify config file written Feb 09 18:23:25 music volumio[28158]: 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 09 18:23:25 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:23:25 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:23:25 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:23:25 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:23:25 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:23:25 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:23:25 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:23:25 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:23:25 music sudo[28347]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 09 18:23:25 music sudo[28347]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:23:25 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 18:23:25 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:23:25 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:23:25 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:23:25 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:23:25 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:23:25 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:23:25 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:23:25 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:23:25 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:23:25 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 18:23:25 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 18:23:25 music volumio[28158]: info: No need to fix Spotify hosts Feb 09 18:23:25 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 09 18:23:25 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 09 18:23:25 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 18:23:25 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 18:23:25 music go-librespot[28359]: go-librespot daemon starting... Feb 09 18:23:25 music sudo[28347]: pam_unix(sudo:session): session closed for user root Feb 09 18:23:25 music go-librespot[28360]: time="2026-02-09T18:23:25-05:00" level=info msg="running go-librespot 0.6.2" Feb 09 18:23:25 music go-librespot[28360]: time="2026-02-09T18:23:25-05:00" level=debug msg="app state loaded" Feb 09 18:23:25 music go-librespot[28360]: time="2026-02-09T18:23:25-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 18:23:25 music go-librespot[28360]: time="2026-02-09T18:23:25-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 09 18:23:25 music go-librespot[28360]: time="2026-02-09T18:23:25-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 09 18:23:25 music go-librespot[28360]: time="2026-02-09T18:23:25-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 09 18:23:25 music go-librespot[28360]: time="2026-02-09T18:23:25-05:00" level=info msg="zeroconf server listening on port 34167" Feb 09 18:23:25 music volumio[28158]: info: Starting Shairport Sync Feb 09 18:23:25 music volumio[28158]: info: Starting Shairport Sync Feb 09 18:23:26 music volumio[28158]: info: Starting Shairport Sync Feb 09 18:23:26 music volumio[28158]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 09 18:23:26 music sudo[28391]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 18:23:26 music sudo[28391]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:23:26 music sudo[28395]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 18:23:26 music sudo[28395]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:23:26 music sudo[28394]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 18:23:26 music sudo[28394]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:23:26 music go-librespot[28360]: time="2026-02-09T18:23:26-05:00" level=debug msg="obtained new client token: AAAoPgwZdY4aX42IG0Hi4diRH5PG+UieoMczifJyBRCSHHB6zgIyKExwOsesoMhua6R40eWmTOhDO2eUj+lpz+AKp227FwmyOJMHR7ROWXapzzD4RoaJzdeMV3QFQbsjod26XsW8QgPQGBvjo8JdX43iB5A582yIMlojfl3CD9KWhUtOSX3KEg0iA8axlPQiMPnTX5mSEQrSkC3cR5Y33d9tWNzfzB7wMZfYzAvOOWz1l+kvoJbR" Feb 09 18:23:26 music volumio[28158]: info: CoreCommandRouter::volumioGetState Feb 09 18:23:26 music volumio[28158]: info: CorePlayQueue::getTrack 0 Feb 09 18:23:26 music go-librespot[28360]: time="2026-02-09T18:23:26-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 09 18:23:26 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 09 18:23:26 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 09 18:23:26 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 18:23:26 music systemd[1]: shairport-sync.service: Consumed 1.811s CPU time. Feb 09 18:23:26 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 18:23:26 music go-librespot[28360]: time="2026-02-09T18:23:26-05:00" level=debug msg="completed keyexchange" Feb 09 18:23:26 music go-librespot[28360]: time="2026-02-09T18:23:26-05:00" level=debug msg="completed challenge" Feb 09 18:23:26 music sudo[28394]: pam_unix(sudo:session): session closed for user root Feb 09 18:23:26 music sudo[28395]: pam_unix(sudo:session): session closed for user root Feb 09 18:23:26 music sudo[28391]: pam_unix(sudo:session): session closed for user root Feb 09 18:23:26 music volumio[28158]: info: Shairport-Sync Started Feb 09 18:23:26 music volumio[28158]: Error adding Membership: Error: addMembership EINVAL Feb 09 18:23:26 music volumio[28158]: info: Shairport-Sync Started Feb 09 18:23:26 music volumio[28158]: info: Shairport-Sync Started Feb 09 18:23:26 music go-librespot[28360]: time="2026-02-09T18:23:26-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:23:26 music go-librespot[28360]: time="2026-02-09T18:23:26-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 09 18:23:26 music go-librespot[28360]: time="2026-02-09T18:23:26-05:00" level=debug msg="completed keyexchange" Feb 09 18:23:26 music go-librespot[28360]: time="2026-02-09T18:23:26-05:00" level=debug msg="completed challenge" Feb 09 18:23:27 music go-librespot[28360]: time="2026-02-09T18:23:27-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:23:27 music go-librespot[28360]: time="2026-02-09T18:23:27-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 09 18:23:27 music mpd[28328]: 2026-02-09T18:23:27 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 09 18:23:27 music systemd[1]: Started mpd.service - Music Player Daemon. Feb 09 18:23:27 music sudo[28299]: pam_unix(sudo:session): session closed for user root Feb 09 18:23:27 music sudo[28289]: pam_unix(sudo:session): session closed for user root Feb 09 18:23:27 music volumio[28158]: info: Completed starting Core Plugins Feb 09 18:23:27 music volumio[28158]: info: ------------------------------------------- Feb 09 18:23:27 music volumio[28158]: info: ----- MyVolumio plugins startup ---- Feb 09 18:23:27 music volumio[28158]: info: ------------------------------------------- Feb 09 18:23:27 music volumio[28158]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 09 18:23:27 music go-librespot[28360]: time="2026-02-09T18:23:27-05:00" level=debug msg="completed keyexchange" Feb 09 18:23:27 music go-librespot[28360]: time="2026-02-09T18:23:27-05:00" level=debug msg="completed challenge" Feb 09 18:23:27 music volumio[28158]: error: MPD error: The expression evaluated to a falsy value: Feb 09 18:23:27 music volumio[28158]: assert.ok(self.idling) Feb 09 18:23:27 music volumio[28158]: error: The expression evaluated to a falsy value: Feb 09 18:23:27 music volumio[28158]: assert.ok(self.idling) Feb 09 18:23:27 music volumio[28158]: info: MPD running with PID28328 Feb 09 18:23:27 music volumio[28158]: ,establishing connection Feb 09 18:23:27 music volumio[28158]: error: updateQueue error: null Feb 09 18:23:27 music volumio[28158]: error: updateQueue error: null Feb 09 18:23:27 music go-librespot[28360]: time="2026-02-09T18:23:27-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:23:28 music go-librespot[28360]: time="2026-02-09T18:23:28-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 09 18:23:28 music go-librespot[28360]: time="2026-02-09T18:23:28-05:00" level=debug msg="completed keyexchange" Feb 09 18:23:28 music go-librespot[28360]: time="2026-02-09T18:23:28-05:00" level=debug msg="completed challenge" Feb 09 18:23:28 music go-librespot[28360]: time="2026-02-09T18:23:28-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:23:28 music sudo[28435]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 18:23:28 music sudo[28435]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:23:28 music sudo[28437]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 18:23:28 music sudo[28437]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:23:28 music sudo[28435]: pam_unix(sudo:session): session closed for user root Feb 09 18:23:28 music sudo[28437]: pam_unix(sudo:session): session closed for user root Feb 09 18:23:28 music sudo[28439]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 09 18:23:28 music sudo[28439]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:23:28 music sudo[28439]: pam_unix(sudo:session): session closed for user root Feb 09 18:23:28 music volumio[28158]: info: Upmpdcli Daemon Started Feb 09 18:23:28 music volumio[28158]: info: go-librespot daemon successfully initialized Feb 09 18:23:29 music go-librespot[28360]: time="2026-02-09T18:23:29-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 09 18:23:29 music go-librespot[28360]: time="2026-02-09T18:23:29-05:00" level=debug msg="completed keyexchange" Feb 09 18:23:29 music go-librespot[28360]: time="2026-02-09T18:23:29-05:00" level=debug msg="completed challenge" Feb 09 18:23:29 music go-librespot[28360]: time="2026-02-09T18:23:29-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:23:30 music go-librespot[28360]: time="2026-02-09T18:23:30-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 09 18:23:30 music go-librespot[28360]: time="2026-02-09T18:23:30-05:00" level=debug msg="completed keyexchange" Feb 09 18:23:30 music go-librespot[28360]: time="2026-02-09T18:23:30-05:00" level=debug msg="completed challenge" Feb 09 18:23:30 music go-librespot[28360]: time="2026-02-09T18:23:30-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:23:30 music go-librespot[28360]: time="2026-02-09T18:23:30-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 09 18:23:30 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 18:23:30 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 18:23:30 music sudo[28444]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 09 18:23:30 music sudo[28444]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:23:30 music sudo[28448]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 09 18:23:30 music sudo[28448]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:23:30 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 09 18:23:30 music systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 09 18:23:30 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 09 18:23:30 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 09 18:23:30 music sudo[28444]: pam_unix(sudo:session): session closed for user root Feb 09 18:23:30 music mpd_monitor.sh[28450]: MPD Monitor Service: Starting MPD Monitor Service Feb 09 18:23:30 music volumio[28158]: info: Successfully started MPD Monitor Feb 09 18:23:30 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 09 18:23:30 music systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 09 18:23:30 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 09 18:23:30 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 09 18:23:30 music sudo[28448]: pam_unix(sudo:session): session closed for user root Feb 09 18:23:30 music mpd_monitor.sh[28453]: MPD Monitor Service: Starting MPD Monitor Service Feb 09 18:23:30 music volumio[28158]: info: Successfully started MPD Monitor Feb 09 18:23:31 music volumio[28158]: info: CoreCommandRouter::volumioGetState Feb 09 18:23:31 music volumio[28158]: info: CorePlayQueue::getTrack 0 Feb 09 18:23:31 music volumio[28158]: info: Initializing connection to go-librespot Websocket Feb 09 18:23:31 music volumio[28158]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 18:23:32 music volumio[28158]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 09 18:23:33 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 09 18:23:33 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 18:23:33 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 18:23:33 music go-librespot[28457]: go-librespot daemon starting... Feb 09 18:23:33 music go-librespot[28458]: time="2026-02-09T18:23:33-05:00" level=info msg="running go-librespot 0.6.2" Feb 09 18:23:33 music go-librespot[28458]: time="2026-02-09T18:23:33-05:00" level=debug msg="app state loaded" Feb 09 18:23:33 music go-librespot[28458]: time="2026-02-09T18:23:33-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 18:23:33 music go-librespot[28458]: time="2026-02-09T18:23:33-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 09 18:23:33 music go-librespot[28458]: time="2026-02-09T18:23:33-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 09 18:23:33 music go-librespot[28458]: time="2026-02-09T18:23:33-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 09 18:23:33 music go-librespot[28458]: time="2026-02-09T18:23:33-05:00" level=info msg="zeroconf server listening on port 35361" Feb 09 18:23:34 music go-librespot[28458]: time="2026-02-09T18:23:34-05:00" level=debug msg="obtained new client token: AAByY2L6rR9mSDArZvOG759yu7EhZq04zxUrQSfvn+AqmJv49aeEcb+FEqIi8qXT/KN70XC7BfQL5D/mCFFk70Vi8NBXwaVANWCk06keLJxWW8+64ky4F9sWGMTHlaZ0JSaPWeVWxzaQEcobKSx+SNhKFAfPLgf3zYt5USRrtvHoaXha2sJoix58vaXx59ePxYxmMnJtzFLYDefdWdTgk0qFTgu69Jwua3N4Ev2dk7VetwiijqGO" Feb 09 18:23:34 music go-librespot[28458]: time="2026-02-09T18:23:34-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 09 18:23:34 music go-librespot[28458]: time="2026-02-09T18:23:34-05:00" level=debug msg="completed keyexchange" Feb 09 18:23:34 music go-librespot[28458]: time="2026-02-09T18:23:34-05:00" level=debug msg="completed challenge" Feb 09 18:23:34 music go-librespot[28458]: time="2026-02-09T18:23:34-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:23:34 music go-librespot[28458]: time="2026-02-09T18:23:34-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 09 18:23:34 music go-librespot[28458]: time="2026-02-09T18:23:34-05:00" level=debug msg="completed keyexchange" Feb 09 18:23:34 music go-librespot[28458]: time="2026-02-09T18:23:34-05:00" level=debug msg="completed challenge" Feb 09 18:23:34 music volumio[28158]: info: Initializing connection to go-librespot Websocket Feb 09 18:23:34 music go-librespot[28458]: time="2026-02-09T18:23:34-05:00" level=debug msg="new websocket client" Feb 09 18:23:35 music volumio[28158]: info: Connection to go-librespot Websocket established Feb 09 18:23:35 music go-librespot[28458]: time="2026-02-09T18:23:35-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:23:35 music go-librespot[28458]: time="2026-02-09T18:23:35-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 09 18:23:35 music go-librespot[28458]: time="2026-02-09T18:23:35-05:00" level=debug msg="completed keyexchange" Feb 09 18:23:35 music go-librespot[28458]: time="2026-02-09T18:23:35-05:00" level=debug msg="completed challenge" Feb 09 18:23:35 music go-librespot[28458]: time="2026-02-09T18:23:35-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:23:35 music volumio[28158]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 09 18:23:35 music volumio[28158]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 09 18:23:35 music volumio[28158]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 09 18:23:35 music volumio[28158]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 09 18:23:35 music volumio[28158]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 09 18:23:35 music volumio[28158]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 09 18:23:35 music volumio[28158]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 09 18:23:35 music volumio[28158]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 09 18:23:35 music volumio[28158]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 09 18:23:35 music volumio[28158]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 09 18:23:35 music volumio[28158]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 09 18:23:35 music volumio[28158]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 09 18:23:35 music volumio[28158]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 09 18:23:35 music volumio[28158]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 09 18:23:35 music volumio[28158]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 09 18:23:35 music volumio[28158]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 09 18:23:35 music volumio[28158]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 09 18:23:35 music volumio[28158]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 09 18:23:35 music volumio[28158]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 09 18:23:35 music volumio[28158]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 09 18:23:35 music volumio[28158]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 09 18:23:35 music volumio[28158]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 09 18:23:35 music volumio[28158]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 09 18:23:35 music volumio[28158]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 09 18:23:35 music volumio[28158]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 09 18:23:35 music volumio[28158]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 09 18:23:35 music volumio[28158]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 09 18:23:35 music volumio[28158]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 09 18:23:35 music volumio[28158]: info: Adding plugin bluetooth to MyMusic Plugins Feb 09 18:23:35 music volumio[28158]: info: Adding plugin multiroom to MyMusic Plugins Feb 09 18:23:35 music volumio[28158]: info: Adding plugin metavolumio to MyMusic Plugins Feb 09 18:23:35 music volumio[28158]: info: Adding plugin cd_controller to MyMusic Plugins Feb 09 18:23:35 music volumio[28158]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 09 18:23:35 music volumio[28158]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 09 18:23:35 music volumio[28158]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 09 18:23:36 music volumio[28158]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 09 18:23:36 music go-librespot[28458]: time="2026-02-09T18:23:36-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 09 18:23:36 music go-librespot[28458]: time="2026-02-09T18:23:36-05:00" level=debug msg="completed keyexchange" Feb 09 18:23:36 music go-librespot[28458]: time="2026-02-09T18:23:36-05:00" level=debug msg="completed challenge" Feb 09 18:23:36 music go-librespot[28458]: time="2026-02-09T18:23:36-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:23:37 music volumio[28158]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 09 18:23:37 music volumio[28158]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 09 18:23:37 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 18:23:37 music volumio[28158]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 18:23:37 music volumio[28158]: info: Starting MyVolumio Remote Streaming Endpoints Feb 09 18:23:37 music volumio[28158]: info: MyVolumio login type: Token Feb 09 18:23:37 music go-librespot[28458]: time="2026-02-09T18:23:37-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 09 18:23:37 music volumio[28158]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 09 18:23:37 music volumio[28158]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 09 18:23:37 music go-librespot[28458]: time="2026-02-09T18:23:37-05:00" level=debug msg="completed keyexchange" Feb 09 18:23:37 music go-librespot[28458]: time="2026-02-09T18:23:37-05:00" level=debug msg="completed challenge" Feb 09 18:23:37 music go-librespot[28458]: time="2026-02-09T18:23:37-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:23:38 music volumio[28158]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 09 18:23:38 music volumio[28158]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 09 18:23:38 music volumio[28158]: info: Streaming services startup Feb 09 18:23:38 music volumio[28158]: info: Starting Streaming Daemon Feb 09 18:23:38 music sudo[28468]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 09 18:23:38 music sudo[28468]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 18:23:38 music volumio[28158]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 09 18:23:38 music sudo[28468]: pam_unix(sudo:session): session closed for user root Feb 09 18:23:38 music volumio[28158]: info: Getting Spotify volume Feb 09 18:23:38 music volumio[28158]: error: Cannot start Volumio Streaming Daemon Feb 09 18:23:38 music volumio[28158]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 09 18:23:38 music volumio[28158]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 09 18:23:38 music go-librespot[28458]: time="2026-02-09T18:23:38-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 09 18:23:38 music volumio[28158]: 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 09 18:23:38 music go-librespot[28458]: time="2026-02-09T18:23:38-05:00" level=debug msg="completed keyexchange" Feb 09 18:23:38 music go-librespot[28458]: time="2026-02-09T18:23:38-05:00" level=debug msg="completed challenge" Feb 09 18:23:38 music volumio[28158]: info: CoreCommandRouter::volumioGetState Feb 09 18:23:38 music volumio[28158]: info: CorePlayQueue::getTrack 0 Feb 09 18:23:38 music volumio[28158]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Feb 09 18:23:38 music volumio[28158]: SPOTIFY: SPOTIFY VOLUME undefined Feb 09 18:23:38 music volumio[28158]: SPOTIFY: VOLUMIO VOLUME 86 Feb 09 18:23:38 music volumio[28158]: info: Aligning Spotify Volume to Volumio Volume Feb 09 18:23:38 music volumio[28158]: info: CoreCommandRouter::volumioGetState Feb 09 18:23:38 music volumio[28158]: info: CorePlayQueue::getTrack 0 Feb 09 18:23:38 music volumio[28158]: info: Setting Spotify Volume from Volumio: 86 Feb 09 18:23:38 music go-librespot[28458]: time="2026-02-09T18:23:38-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 18:23:38 music go-librespot[28458]: time="2026-02-09T18:23:38-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 09 18:23:38 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 18:23:38 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 18:23:38 music volumio[28158]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 18:23:38 music volumio[28158]: Error: socket hang up Feb 09 18:23:38 music volumio[28158]: at connResetException (node:internal/errors:720:14) Feb 09 18:23:38 music volumio[28158]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 09 18:23:38 music volumio[28158]: at Socket.emit (node:events:526:35) Feb 09 18:23:38 music volumio[28158]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 09 18:23:38 music volumio[28158]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 09 18:23:38 music volumio[28158]: code: 'ECONNRESET', Feb 09 18:23:38 music volumio[28158]: response: undefined Feb 09 18:23:38 music volumio[28158]: } Feb 09 18:23:38 music volumio[28158]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 18:23:39 music sudo[28502]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-09 18:22' Feb 09 18:23:39 music sudo[28502]: 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"