Jan 08 11:28:00 music go-librespot[24938]: time="2026-01-08T11:28:00-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Jan 08 11:28:00 music go-librespot[24938]: time="2026-01-08T11:28:00-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:00 music go-librespot[24938]: time="2026-01-08T11:28:00-05:00" level=debug msg="completed challenge" Jan 08 11:28:00 music go-librespot[24938]: time="2026-01-08T11:28:00-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:00 music volumio[24644]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 08 11:28:00 music volumio[24644]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 08 11:28:00 music volumio[24644]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 08 11:28:00 music volumio[24644]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 08 11:28:00 music volumio[24644]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 08 11:28:00 music volumio[24644]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 08 11:28:00 music volumio[24644]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 08 11:28:00 music volumio[24644]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 08 11:28:00 music volumio[24644]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 08 11:28:00 music volumio[24644]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 08 11:28:00 music volumio[24644]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 08 11:28:00 music volumio[24644]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 08 11:28:00 music volumio[24644]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 08 11:28:00 music volumio[24644]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 08 11:28:00 music volumio[24644]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 08 11:28:00 music volumio[24644]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 08 11:28:00 music volumio[24644]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 08 11:28:00 music volumio[24644]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 08 11:28:00 music volumio[24644]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 08 11:28:00 music volumio[24644]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 08 11:28:00 music volumio[24644]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 08 11:28:00 music volumio[24644]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 08 11:28:00 music volumio[24644]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 08 11:28:00 music volumio[24644]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 08 11:28:00 music volumio[24644]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 08 11:28:00 music volumio[24644]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 08 11:28:00 music volumio[24644]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 08 11:28:00 music volumio[24644]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 08 11:28:00 music volumio[24644]: info: Adding plugin bluetooth to MyMusic Plugins Jan 08 11:28:00 music volumio[24644]: info: Adding plugin multiroom to MyMusic Plugins Jan 08 11:28:00 music volumio[24644]: info: Adding plugin metavolumio to MyMusic Plugins Jan 08 11:28:00 music volumio[24644]: info: Adding plugin cd_controller to MyMusic Plugins Jan 08 11:28:00 music volumio[24644]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 08 11:28:00 music volumio[24644]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 08 11:28:00 music volumio[24644]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 08 11:28:00 music volumio[24644]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 08 11:28:00 music go-librespot[24938]: time="2026-01-08T11:28:00-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 08 11:28:00 music go-librespot[24938]: time="2026-01-08T11:28:00-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:00 music go-librespot[24938]: time="2026-01-08T11:28:00-05:00" level=debug msg="completed challenge" Jan 08 11:28:00 music go-librespot[24938]: time="2026-01-08T11:28:00-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:01 music go-librespot[24938]: time="2026-01-08T11:28:01-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 08 11:28:01 music volumio[24644]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 08 11:28:01 music volumio[24644]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 08 11:28:01 music volumio[24644]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 11:28:01 music volumio[24644]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 11:28:01 music volumio[24644]: info: Starting MyVolumio Remote Streaming Endpoints Jan 08 11:28:01 music volumio[24644]: info: MyVolumio login type: Token Jan 08 11:28:01 music go-librespot[24938]: time="2026-01-08T11:28:01-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:01 music go-librespot[24938]: time="2026-01-08T11:28:01-05:00" level=debug msg="completed challenge" Jan 08 11:28:01 music volumio[24644]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 08 11:28:01 music volumio[24644]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 08 11:28:01 music go-librespot[24938]: time="2026-01-08T11:28:01-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:02 music go-librespot[24938]: time="2026-01-08T11:28:02-05:00" level=debug msg="connected to ap-gew1.spotify.com:80" Jan 08 11:28:02 music volumio[24644]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 08 11:28:02 music volumio[24644]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 08 11:28:02 music volumio[24644]: info: Streaming services startup Jan 08 11:28:02 music volumio[24644]: info: Starting Streaming Daemon Jan 08 11:28:02 music go-librespot[24938]: time="2026-01-08T11:28:02-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.3.63:44820->104.199.65.9:80: read: connection reset by peer" Jan 08 11:28:02 music go-librespot[24938]: time="2026-01-08T11:28:02-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.3.63:44820->104.199.65.9:80: read: connection reset by peer" Jan 08 11:28:02 music sudo[24948]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 08 11:28:02 music sudo[24948]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:02 music volumio[24644]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 08 11:28:02 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 08 11:28:02 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 08 11:28:02 music systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Jan 08 11:28:02 music volumio[24644]: info: Getting Spotify volume Jan 08 11:28:02 music sudo[24948]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:02 music volumio[24644]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 08 11:28:02 music volumio[24644]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 08 11:28:02 music volumio[24644]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 08 11:28:02 music volumio[24644]: errno: -111, Jan 08 11:28:02 music volumio[24644]: code: 'ECONNREFUSED', Jan 08 11:28:02 music volumio[24644]: syscall: 'connect', Jan 08 11:28:02 music volumio[24644]: address: '127.0.0.1', Jan 08 11:28:02 music volumio[24644]: port: 9879, Jan 08 11:28:02 music volumio[24644]: response: undefined Jan 08 11:28:02 music volumio[24644]: } Jan 08 11:28:02 music volumio[24644]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 08 11:28:03 music sudo[24998]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-08 11:27' Jan 08 11:28:03 music sudo[24998]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:03 music sudo[24998]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:04 music systemd[1]: setdatetime-helper.service: Deactivated successfully. Jan 08 11:28:04 music systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Jan 08 11:28:04 music systemd[1]: setdatetime-helper.service: Consumed 1.009s CPU time. Jan 08 11:28:04 music volumio-remote-updater[696]: [2026-01-08 11:28:04] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 08 11:28:04 music volumio-remote-updater[696]: [2026-01-08 11:28:04] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 08 11:28:04 music systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 08 11:28:04 music systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 08 11:28:04 music systemd[1]: volumio.service: Consumed 26.712s CPU time. Jan 08 11:28:04 music systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 08 11:28:04 music systemd[1]: dynamicswap.service: Deactivated successfully. Jan 08 11:28:04 music systemd[1]: volumio.service: Scheduled restart job, restart counter is at 274. Jan 08 11:28:04 music systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 08 11:28:04 music systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 08 11:28:04 music systemd[1]: volumio.service: Consumed 26.712s CPU time. Jan 08 11:28:04 music systemd[1]: Started volumio.service - Volumio Backend Module. Jan 08 11:28:04 music systemd[1]: dynamicswap.service: Deactivated successfully. Jan 08 11:28:05 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 08 11:28:05 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 08 11:28:05 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 08 11:28:05 music go-librespot[25040]: go-librespot daemon starting... Jan 08 11:28:05 music go-librespot[25041]: time="2026-01-08T11:28:05-05:00" level=info msg="running go-librespot 0.6.2" Jan 08 11:28:05 music go-librespot[25041]: time="2026-01-08T11:28:05-05:00" level=debug msg="app state loaded" Jan 08 11:28:05 music go-librespot[25041]: time="2026-01-08T11:28:05-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 08 11:28:06 music go-librespot[25041]: time="2026-01-08T11:28:06-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]" Jan 08 11:28:06 music go-librespot[25041]: time="2026-01-08T11:28:06-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]" Jan 08 11:28:06 music go-librespot[25041]: time="2026-01-08T11:28:06-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]" Jan 08 11:28:06 music go-librespot[25041]: time="2026-01-08T11:28:06-05:00" level=info msg="zeroconf server listening on port 34327" Jan 08 11:28:06 music go-librespot[25041]: time="2026-01-08T11:28:06-05:00" level=debug msg="obtained new client token: AAAhFDf2xpU3UDD0I+qjSoaoxCkcv0Q3iRlYW39L7rMbpe4TNiW/0ohvtE6wjFbz55iR7Czz1DJoaK955oxiSyMZQx6gdthpWQJfgAapYE4eEMwss0Gk2RhQykcFI2T4NgoUozhtHSC/+mP3tBeBOUY9HEpN+hR0PD6kp2sLkuhTkefESbfuzeU5zCKjO5kRPjQvfBpR1hIQEFyNbr6fvwrsFbjTvfj/0G7s7SRFNaRWmpLzxfXCkiw=" Jan 08 11:28:06 music go-librespot[25041]: time="2026-01-08T11:28:06-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 08 11:28:06 music go-librespot[25041]: time="2026-01-08T11:28:06-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:06 music go-librespot[25041]: time="2026-01-08T11:28:06-05:00" level=debug msg="completed challenge" Jan 08 11:28:06 music go-librespot[25041]: time="2026-01-08T11:28:06-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:06 music volumio[25025]: info: ------------------------------------------- Jan 08 11:28:06 music volumio[25025]: info: ----- Volumio3 ---- Jan 08 11:28:06 music volumio[25025]: info: ------------------------------------------- Jan 08 11:28:06 music volumio[25025]: info: ----- System startup ---- Jan 08 11:28:06 music volumio[25025]: info: ------------------------------------------- Jan 08 11:28:07 music go-librespot[25041]: time="2026-01-08T11:28:07-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 08 11:28:07 music go-librespot[25041]: time="2026-01-08T11:28:07-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:07 music go-librespot[25041]: time="2026-01-08T11:28:07-05:00" level=debug msg="completed challenge" Jan 08 11:28:07 music go-librespot[25041]: time="2026-01-08T11:28:07-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:07 music volumio[25025]: info: MYVOLUMIO Environment detected Jan 08 11:28:07 music volumio[25025]: info: Plugin folders cleanup Jan 08 11:28:07 music volumio[25025]: info: Scanning into folder /volumio/app/plugins/ Jan 08 11:28:07 music volumio[25025]: info: Scanning category audio_interface Jan 08 11:28:07 music volumio[25025]: info: Scanning category miscellanea Jan 08 11:28:07 music volumio[25025]: info: Scanning category music_service Jan 08 11:28:07 music volumio[25025]: info: Scanning category plugins.json Jan 08 11:28:07 music volumio[25025]: info: Scanning category system_controller Jan 08 11:28:07 music volumio[25025]: info: Scanning category user_interface Jan 08 11:28:07 music volumio[25025]: info: Scanning into folder /data/plugins/ Jan 08 11:28:07 music volumio[25025]: info: Scanning category music_service Jan 08 11:28:07 music volumio[25025]: info: Plugin folders cleanup completed Jan 08 11:28:07 music volumio[25025]: info: ------------------------------------------- Jan 08 11:28:07 music volumio[25025]: info: ----- Core plugins startup ---- Jan 08 11:28:07 music volumio[25025]: info: ------------------------------------------- Jan 08 11:28:07 music volumio[25025]: info: Loading plugins from folder /volumio/app/plugins/ Jan 08 11:28:07 music volumio[25025]: info: Adding plugin upnp to MyMusic Plugins Jan 08 11:28:07 music volumio[25025]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 08 11:28:07 music volumio[25025]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 08 11:28:07 music volumio[25025]: info: Loading plugins from folder /data/plugins/ Jan 08 11:28:07 music volumio[25025]: info: Loading plugin "system"... Jan 08 11:28:07 music volumio[25025]: info: Loading plugin "appearance"... Jan 08 11:28:07 music go-librespot[25041]: time="2026-01-08T11:28:07-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Jan 08 11:28:08 music go-librespot[25041]: time="2026-01-08T11:28:08-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:08 music go-librespot[25041]: time="2026-01-08T11:28:08-05:00" level=debug msg="completed challenge" Jan 08 11:28:08 music go-librespot[25041]: time="2026-01-08T11:28:08-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:08 music go-librespot[25041]: time="2026-01-08T11:28:08-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 08 11:28:08 music go-librespot[25041]: time="2026-01-08T11:28:08-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:08 music go-librespot[25041]: time="2026-01-08T11:28:08-05:00" level=debug msg="completed challenge" Jan 08 11:28:08 music go-librespot[25041]: time="2026-01-08T11:28:08-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:08 music volumio[25025]: info: Loading plugin "network"... Jan 08 11:28:08 music volumio[25025]: info: Refreshing Cached IP Addresses Jan 08 11:28:08 music sudo[25063]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 08 11:28:08 music sudo[25063]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:08 music sudo[25063]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:08 music sudo[25065]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 08 11:28:08 music volumio[25025]: info: Loading plugin "services"... Jan 08 11:28:08 music sudo[25065]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:08 music volumio[25025]: info: Loading plugin "alsa_controller"... Jan 08 11:28:08 music sudo[25065]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:09 music sudo[25073]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 08 11:28:09 music sudo[25073]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:09 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 08 11:28:09 music volumio[25025]: info: Loading plugin "wizard"... Jan 08 11:28:09 music volumio[25025]: info: Loading plugin "networkfs"... Jan 08 11:28:09 music volumio[25025]: info: Starting Udev Watcher for removable devices Jan 08 11:28:09 music volumio[25025]: info: Ignoring mount for partition: boot Jan 08 11:28:09 music volumio[25025]: info: Ignoring mount for partition: volumio Jan 08 11:28:09 music volumio[25025]: info: Ignoring mount for partition: volumio_data Jan 08 11:28:09 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 08 11:28:09 music volumio[25025]: info: Loading plugin "volumio_command_line_client"... Jan 08 11:28:09 music volumio[25025]: info: Loading plugin "upnp"... Jan 08 11:28:09 music volumio[25025]: info: [1767889689148] Starting Upmpd Daemon Jan 08 11:28:09 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 08 11:28:09 music volumio[25025]: info: Loading plugin "my_music"... Jan 08 11:28:09 music volumio[25025]: info: Loading plugin "mpd"... Jan 08 11:28:09 music go-librespot[25041]: time="2026-01-08T11:28:09-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 08 11:28:09 music volumio[25025]: info: Loading plugin "upnp_browser"... Jan 08 11:28:09 music sudo[25073]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:09 music volumio-remote-updater[696]: [2026-01-08 11:28:09] [connect] Successful connection Jan 08 11:28:09 music go-librespot[25041]: time="2026-01-08T11:28:09-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:09 music go-librespot[25041]: time="2026-01-08T11:28:09-05:00" level=debug msg="completed challenge" Jan 08 11:28:09 music go-librespot[25041]: time="2026-01-08T11:28:09-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:10 music go-librespot[25041]: time="2026-01-08T11:28:10-05:00" level=debug msg="connected to ap-gew1.spotify.com:80" Jan 08 11:28:10 music go-librespot[25041]: time="2026-01-08T11:28:10-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 08 11:28:10 music go-librespot[25041]: time="2026-01-08T11:28:10-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 08 11:28:10 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 08 11:28:10 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 08 11:28:11 music volumio[25025]: info: Starting UPNP Browser Jan 08 11:28:11 music volumio[25025]: info: Loading plugin "alarm-clock"... Jan 08 11:28:11 music volumio[25025]: info: Loading plugin "airplay_emulation"... Jan 08 11:28:11 music volumio[25025]: info: Starting Shairport Sync Jan 08 11:28:11 music volumio[25025]: info: Loading plugin "last_100"... Jan 08 11:28:11 music volumio[25025]: info: Loading plugin "webradio"... Jan 08 11:28:11 music volumio[25025]: info: Loading plugin "i2s_dacs"... Jan 08 11:28:11 music volumio[25025]: info: I2S DAC not set, start Auto-detection Jan 08 11:28:11 music volumio[25025]: info: Loading plugin "volumiodiscovery"... Jan 08 11:28:11 music volumio[25025]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 08 11:28:11 music node[25025]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 08 11:28:11 music volumio[25025]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 08 11:28:11 music node[25025]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 08 11:28:11 music volumio[25025]: *** WARNING *** For more information see Jan 08 11:28:11 music node[25025]: *** WARNING *** For more information see Jan 08 11:28:11 music volumio[25025]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 08 11:28:11 music node[25025]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 08 11:28:11 music volumio[25025]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 08 11:28:11 music node[25025]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 08 11:28:11 music volumio[25025]: *** WARNING *** For more information see Jan 08 11:28:11 music node[25025]: *** WARNING *** For more information see Jan 08 11:28:11 music volumio[25025]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 08 11:28:11 music volumio[25025]: info: Discovery: Started advertising with name: music Jan 08 11:28:11 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 08 11:28:11 music volumio[25025]: info: Loading plugin "spop"... Jan 08 11:28:12 music volumio[25025]: info: Loading plugin "outputs"... Jan 08 11:28:12 music volumio[25025]: info: Loading plugin "albumart"... Jan 08 11:28:12 music volumio[25025]: info: Plugin example_plugin is not enabled Jan 08 11:28:12 music volumio[25025]: info: Loading plugin "inputs"... Jan 08 11:28:12 music volumio[25025]: info: Loading plugin "updater_comm"... Jan 08 11:28:12 music volumio[25025]: info: Plugin mpdemulation is not enabled Jan 08 11:28:12 music volumio[25025]: info: Loading plugin "rest_api"... Jan 08 11:28:12 music volumio[25025]: info: Loading plugin "websocket"... Jan 08 11:28:12 music volumio[25025]: info: Starting Socket.io Server version 1.7.4 Jan 08 11:28:12 music volumio[25025]: info: Loading i18n strings for locale en Jan 08 11:28:12 music volumio[25025]: Updating browse sources language Jan 08 11:28:12 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 11:28:12 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 11:28:12 music volumio[25025]: info: CoreCommandRouter::initPlayerControls Jan 08 11:28:12 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:12 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:12 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:12 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:12 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:12 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:12 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:12 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:12 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 11:28:12 music volumio[25025]: Express server listening on port 3000 Jan 08 11:28:12 music volumio[25025]: [Metrics] WebUI: 6s 610.43ms Jan 08 11:28:13 music volumio[25025]: info: CoreStateMachine::resetVolumioState Jan 08 11:28:13 music volumio[25025]: info: CoreStateMachine::getcurrentVolume Jan 08 11:28:13 music volumio[25025]: info: CoreCommandRouter::volumioRetrievevolume Jan 08 11:28:13 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 11:28:13 music volumio[25025]: info: Volumio Network Manager: Network status updated: 1 Jan 08 11:28:13 music volumio[25098]: Forking 3 albumart workers Jan 08 11:28:13 music volumio[25025]: info: VolumeController:: Volume=86 Mute =false Jan 08 11:28:13 music volumio[25025]: info: CoreStateMachine::pushState Jan 08 11:28:13 music volumio[25025]: info: CorePlayQueue::getTrack 0 Jan 08 11:28:13 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 08 11:28:13 music volumio[25025]: info: CoreCommandRouter::volumioPushState Jan 08 11:28:13 music volumio[25025]: info: CoreStateMachine::updateTrackBlock Jan 08 11:28:13 music volumio[25025]: info: CorePlayQueue::getTrackBlock Jan 08 11:28:13 music volumio[25025]: info: CoreCommandRouter::volumioRetrievevolume Jan 08 11:28:13 music volumio[25025]: info: CoreCommandRouter::volumioGetState Jan 08 11:28:13 music volumio[25025]: info: CorePlayQueue::getTrack 0 Jan 08 11:28:13 music volumio-remote-updater[696]: [2026-01-08 11:28:13] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1767889689 101 Jan 08 11:28:13 music volumio[25025]: 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 Jan 08 11:28:13 music volumio[25025]: info: Reloading queue from file Jan 08 11:28:13 music volumio[25025]: info: CoreStateMachine::setRepeat null single undefined Jan 08 11:28:13 music volumio[25025]: info: CoreStateMachine::pushState Jan 08 11:28:13 music volumio[25025]: info: CorePlayQueue::getTrack 0 Jan 08 11:28:13 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 08 11:28:13 music volumio[25025]: info: CoreCommandRouter::volumioPushState Jan 08 11:28:13 music volumio[25025]: info: CoreStateMachine::setRandom null Jan 08 11:28:13 music volumio[25025]: info: CoreStateMachine::pushState Jan 08 11:28:13 music volumio[25025]: info: CorePlayQueue::getTrack 0 Jan 08 11:28:13 music volumio[25025]: info: CoreCommandRouter::volumioPushState Jan 08 11:28:13 music volumio[25025]: info: Setting Device type: Raspberry PI Jan 08 11:28:13 music volumio[25025]: info: Listing playlists Jan 08 11:28:13 music volumio[25025]: info: Listing playlists Jan 08 11:28:13 music volumio[25025]: info: VolumeController:: Volume=86 Mute =false Jan 08 11:28:13 music volumio[25025]: info: CoreStateMachine::pushState Jan 08 11:28:13 music volumio[25025]: info: CorePlayQueue::getTrack 0 Jan 08 11:28:13 music volumio[25025]: info: CoreCommandRouter::volumioPushState Jan 08 11:28:13 music volumio[25025]: info: Completed loading Core Plugins Jan 08 11:28:13 music volumio[25025]: info: Preparing to generate the ALSA configuration file Jan 08 11:28:13 music volumio[25025]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Jan 08 11:28:13 music volumio[25025]: info: Discovery: Found device music Jan 08 11:28:13 music volumio[25025]: info: CoreCommandRouter::volumioGetState Jan 08 11:28:13 music volumio[25025]: info: CorePlayQueue::getTrack 0 Jan 08 11:28:13 music volumio[25025]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Jan 08 11:28:13 music volumio[25025]: info: Discovery: Found device music Jan 08 11:28:13 music volumio[25025]: info: CoreCommandRouter::volumioGetState Jan 08 11:28:13 music volumio[25025]: info: CorePlayQueue::getTrack 0 Jan 08 11:28:13 music volumio[25025]: info: Asound.conf file unchanged, so no further update is needed Jan 08 11:28:13 music volumio[25025]: info: Output device has changed, restarting MPD Jan 08 11:28:13 music volumio[25025]: info: Output device has changed, restarting Shairport Sync Jan 08 11:28:13 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:13 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 11:28:13 music sudo[25156]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 08 11:28:13 music sudo[25156]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:13 music sudo[25156]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:13 music sudo[25157]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 08 11:28:13 music sudo[25157]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:13 music volumio[25025]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 08 11:28:13 music volumio[25025]: info: ___________ START PLUGINS ___________ Jan 08 11:28:13 music volumio[25025]: info: ControllerMpd::onStart: Initializing MPD Jan 08 11:28:13 music volumio[25025]: info: Creating MPD Configuration file Jan 08 11:28:13 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 11:28:13 music volumio[25025]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 11:28:13 music volumio[25025]: info: [1767889693805] CoreMusicLibrary::Adding element Media Servers Jan 08 11:28:13 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 11:28:13 music volumio[25025]: info: UPNP Browser: Client initialized successfully Jan 08 11:28:13 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 08 11:28:13 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 08 11:28:13 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:13 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 11:28:13 music sudo[25165]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 08 11:28:13 music sudo[25167]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 08 11:28:13 music sudo[25167]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:13 music sudo[25165]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:13 music sudo[25165]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:13 music volumio[25025]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 08 11:28:13 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:13 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 11:28:13 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 08 11:28:13 music go-librespot[25168]: go-librespot daemon starting... Jan 08 11:28:13 music volumio[25025]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 08 11:28:13 music volumio[25025]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 11:28:13 music volumio[25025]: info: [1767889693959] CoreMusicLibrary::Adding element Last_100 Jan 08 11:28:13 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 11:28:13 music systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 08 11:28:13 music volumio[25025]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 11:28:13 music volumio[25025]: info: [1767889693978] CoreMusicLibrary::Adding element Webradio Jan 08 11:28:13 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 11:28:14 music go-librespot[25179]: time="2026-01-08T11:28:13-05:00" level=info msg="running go-librespot 0.6.2" Jan 08 11:28:14 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 08 11:28:14 music volumio[25025]: info: Initializing BBC Radios Jan 08 11:28:14 music go-librespot[25179]: time="2026-01-08T11:28:14-05:00" level=debug msg="app state loaded" Jan 08 11:28:14 music systemd[1]: mpd.service: Deactivated successfully. Jan 08 11:28:14 music systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 08 11:28:14 music systemd[1]: mpd.service: Consumed 4.231s CPU time. Jan 08 11:28:14 music systemd[1]: mpd.socket: Deactivated successfully. Jan 08 11:28:14 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 08 11:28:14 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 08 11:28:14 music go-librespot[25179]: time="2026-01-08T11:28:14-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 08 11:28:14 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 08 11:28:14 music systemd[1]: Starting mpd.service - Music Player Daemon... Jan 08 11:28:14 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 08 11:28:14 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 11:28:14 music volumio[25025]: info: Creating Spotify config file Jan 08 11:28:14 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:14 music sudo[25201]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 08 11:28:14 music sudo[25201]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 08 11:28:14 music sudo[25201]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:14 music go-librespot[25179]: time="2026-01-08T11:28:14-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]" Jan 08 11:28:14 music go-librespot[25179]: time="2026-01-08T11:28:14-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]" Jan 08 11:28:14 music go-librespot[25179]: time="2026-01-08T11:28:14-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]" Jan 08 11:28:14 music go-librespot[25179]: time="2026-01-08T11:28:14-05:00" level=info msg="zeroconf server listening on port 45851" Jan 08 11:28:14 music go-librespot[25179]: time="2026-01-08T11:28:14-05:00" level=debug msg="obtained new client token: AADpKBVoAOrl1GxBXuZoN8O9VvYh55YhiZ2BbjuzUpwbWG7WrOVIt/qIYg0wD4RufuQO/DQV5k9ciUhjFRBqEDF+DHJqitZOKpT3aR6wsu0X9LBv43bLY9B3/CcA6to0HAojvOCeGBkZ4Po3TM5naIetWNJQ5C3mEzTyT1cyIZS+1np4DhlnuQlbwytDlWiJ+UVT7MzCHXuFEWU+e++ZeuOYyfox3w3agYdhufmlv5bEY2Sc/GKUoAg=" Jan 08 11:28:14 music volumio[25025]: info: Volumio Calling Home Jan 08 11:28:14 music go-librespot[25179]: time="2026-01-08T11:28:14-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 08 11:28:14 music go-librespot[25179]: time="2026-01-08T11:28:14-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:14 music go-librespot[25179]: time="2026-01-08T11:28:14-05:00" level=debug msg="completed challenge" Jan 08 11:28:14 music go-librespot[25179]: time="2026-01-08T11:28:14-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:15 music volumio[25117]: Starting albumart workers Jan 08 11:28:15 music volumio[25115]: Starting albumart workers Jan 08 11:28:15 music volumio[25114]: Starting albumart workers Jan 08 11:28:15 music go-librespot[25179]: time="2026-01-08T11:28:15-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 08 11:28:15 music volumio[25025]: info: MPD Permissions set Jan 08 11:28:15 music volumio[25025]: info: MPD Permissions set Jan 08 11:28:15 music go-librespot[25179]: time="2026-01-08T11:28:15-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:15 music go-librespot[25179]: time="2026-01-08T11:28:15-05:00" level=debug msg="completed challenge" Jan 08 11:28:15 music volumio[25025]: info: Volumio called home Jan 08 11:28:15 music volumio[25025]: info: Spotify config file written Jan 08 11:28:15 music go-librespot[25179]: time="2026-01-08T11:28:15-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:15 music volumio[25025]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 08 11:28:15 music sudo[25211]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 08 11:28:15 music sudo[25211]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:15 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:15 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:15 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:15 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:15 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:15 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:15 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:15 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:15 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 08 11:28:15 music systemd[1]: go-librespot-daemon.service: Killing process 25184 (go-librespot) with signal SIGKILL. Jan 08 11:28:15 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 11:28:15 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 08 11:28:15 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 08 11:28:15 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:15 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:15 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:15 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:15 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:15 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:15 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:15 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:15 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:15 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 08 11:28:15 music sudo[25211]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:15 music go-librespot[25218]: go-librespot daemon starting... Jan 08 11:28:15 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 11:28:15 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:15 music volumio[25025]: info: No need to fix Spotify hosts Jan 08 11:28:15 music go-librespot[25224]: time="2026-01-08T11:28:15-05:00" level=info msg="running go-librespot 0.6.2" Jan 08 11:28:15 music go-librespot[25224]: time="2026-01-08T11:28:15-05:00" level=debug msg="app state loaded" Jan 08 11:28:15 music go-librespot[25224]: time="2026-01-08T11:28:15-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 08 11:28:16 music go-librespot[25224]: time="2026-01-08T11:28:16-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]" Jan 08 11:28:16 music go-librespot[25224]: time="2026-01-08T11:28:16-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]" Jan 08 11:28:16 music go-librespot[25224]: time="2026-01-08T11:28:16-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]" Jan 08 11:28:16 music go-librespot[25224]: time="2026-01-08T11:28:16-05:00" level=info msg="zeroconf server listening on port 36175" Jan 08 11:28:16 music volumio[25025]: info: Starting Shairport Sync Jan 08 11:28:16 music volumio[25025]: info: Starting Shairport Sync Jan 08 11:28:16 music volumio[25025]: info: Starting Shairport Sync Jan 08 11:28:16 music go-librespot[25224]: time="2026-01-08T11:28:16-05:00" level=debug msg="obtained new client token: AAC3XEAJNIDwy1fMgRSUn3bWkM7LdxzEqUojzVtu95+Wg/poLraXh9YxWAdeKyDAU4jANQute1PqDqwug3vW8Y+Dq9Vu2wMQT77WXD3m9cNKuHS9QWqn7j/U/VkUPgRt7TZOmuq6W/6lRtr7fqK97Jly3I2uc2cPU2CnQi+81UShM8ODBMh4JefDMOISCemE6wHwiVJRw49pdE32Zu4PvVrpgrj/IR+TmZlamhW+JnL/J1TtNE1ARz8=" Jan 08 11:28:16 music sudo[25246]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 08 11:28:16 music sudo[25246]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:16 music volumio[25025]: info: An error occurred while refreshing Spotify Token Error: Bad Request Jan 08 11:28:16 music sudo[25248]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 08 11:28:16 music sudo[25248]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:16 music go-librespot[25224]: time="2026-01-08T11:28:16-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 08 11:28:16 music sudo[25250]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 08 11:28:16 music sudo[25250]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:16 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 08 11:28:16 music systemd[1]: shairport-sync.service: Deactivated successfully. Jan 08 11:28:16 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 08 11:28:16 music systemd[1]: shairport-sync.service: Consumed 1.891s CPU time. Jan 08 11:28:16 music go-librespot[25224]: time="2026-01-08T11:28:16-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:16 music go-librespot[25224]: time="2026-01-08T11:28:16-05:00" level=debug msg="completed challenge" Jan 08 11:28:16 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 08 11:28:16 music sudo[25246]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:16 music go-librespot[25224]: time="2026-01-08T11:28:16-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:16 music volumio[25025]: info: CoreCommandRouter::volumioGetState Jan 08 11:28:16 music volumio[25025]: info: CorePlayQueue::getTrack 0 Jan 08 11:28:16 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 08 11:28:16 music systemd[1]: shairport-sync.service: Deactivated successfully. Jan 08 11:28:16 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 08 11:28:16 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 08 11:28:16 music sudo[25248]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:16 music sudo[25250]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:16 music volumio[25025]: info: Shairport-Sync Started Jan 08 11:28:16 music volumio[25025]: Error adding Membership: Error: addMembership EINVAL Jan 08 11:28:16 music volumio[25025]: info: Shairport-Sync Started Jan 08 11:28:16 music volumio[25025]: info: Shairport-Sync Started Jan 08 11:28:17 music go-librespot[25224]: time="2026-01-08T11:28:17-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 08 11:28:17 music go-librespot[25224]: time="2026-01-08T11:28:17-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:17 music go-librespot[25224]: time="2026-01-08T11:28:17-05:00" level=debug msg="completed challenge" Jan 08 11:28:17 music go-librespot[25224]: time="2026-01-08T11:28:17-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:18 music go-librespot[25224]: time="2026-01-08T11:28:18-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Jan 08 11:28:18 music go-librespot[25224]: time="2026-01-08T11:28:18-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:18 music go-librespot[25224]: time="2026-01-08T11:28:18-05:00" level=debug msg="completed challenge" Jan 08 11:28:18 music go-librespot[25224]: time="2026-01-08T11:28:18-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:18 music mpd[25204]: 2026-01-08T11:28:18 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 08 11:28:18 music systemd[1]: Started mpd.service - Music Player Daemon. Jan 08 11:28:18 music sudo[25157]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:18 music sudo[25167]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:18 music volumio[25025]: info: Completed starting Core Plugins Jan 08 11:28:18 music volumio[25025]: info: ------------------------------------------- Jan 08 11:28:18 music volumio[25025]: info: ----- MyVolumio plugins startup ---- Jan 08 11:28:18 music volumio[25025]: info: ------------------------------------------- Jan 08 11:28:18 music volumio[25025]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 08 11:28:18 music volumio[25025]: error: MPD error: The expression evaluated to a falsy value: Jan 08 11:28:18 music volumio[25025]: assert.ok(self.idling) Jan 08 11:28:18 music volumio[25025]: error: The expression evaluated to a falsy value: Jan 08 11:28:18 music volumio[25025]: assert.ok(self.idling) Jan 08 11:28:18 music volumio[25025]: info: MPD running with PID25204 Jan 08 11:28:18 music volumio[25025]: ,establishing connection Jan 08 11:28:18 music volumio[25025]: error: updateQueue error: null Jan 08 11:28:18 music volumio[25025]: error: updateQueue error: null Jan 08 11:28:18 music go-librespot[25224]: time="2026-01-08T11:28:18-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 08 11:28:18 music go-librespot[25224]: time="2026-01-08T11:28:18-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:18 music go-librespot[25224]: time="2026-01-08T11:28:18-05:00" level=debug msg="completed challenge" Jan 08 11:28:18 music go-librespot[25224]: time="2026-01-08T11:28:18-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:19 music sudo[25297]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 08 11:28:19 music sudo[25297]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:19 music sudo[25297]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:19 music sudo[25299]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 08 11:28:19 music sudo[25299]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:19 music sudo[25299]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:19 music sudo[25302]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 08 11:28:19 music sudo[25302]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:19 music sudo[25302]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:19 music volumio[25025]: info: Upmpdcli Daemon Started Jan 08 11:28:19 music volumio[25025]: info: CoreCommandRouter::volumioGetState Jan 08 11:28:19 music volumio[25025]: info: CorePlayQueue::getTrack 0 Jan 08 11:28:19 music volumio[25025]: info: go-librespot daemon successfully initialized Jan 08 11:28:19 music go-librespot[25224]: time="2026-01-08T11:28:19-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 08 11:28:19 music go-librespot[25224]: time="2026-01-08T11:28:19-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:19 music go-librespot[25224]: time="2026-01-08T11:28:19-05:00" level=debug msg="completed challenge" Jan 08 11:28:20 music go-librespot[25224]: time="2026-01-08T11:28:20-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:20 music go-librespot[25224]: time="2026-01-08T11:28:20-05:00" level=debug msg="connected to ap-gew1.spotify.com:80" Jan 08 11:28:20 music go-librespot[25224]: time="2026-01-08T11:28:20-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:20 music go-librespot[25224]: time="2026-01-08T11:28:20-05:00" level=debug msg="completed challenge" Jan 08 11:28:21 music go-librespot[25224]: time="2026-01-08T11:28:21-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:21 music go-librespot[25224]: time="2026-01-08T11:28:21-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 " Jan 08 11:28:21 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 08 11:28:21 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 08 11:28:21 music sudo[25309]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 08 11:28:21 music sudo[25309]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:21 music sudo[25311]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 08 11:28:21 music sudo[25311]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:21 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Jan 08 11:28:21 music systemd[1]: mpd_monitor.service: Deactivated successfully. Jan 08 11:28:21 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Jan 08 11:28:21 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Jan 08 11:28:21 music sudo[25311]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:21 music sudo[25309]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:21 music volumio[25025]: info: Successfully started MPD Monitor Jan 08 11:28:21 music mpd_monitor.sh[25314]: MPD Monitor Service: Starting MPD Monitor Service Jan 08 11:28:21 music volumio[25025]: info: Successfully started MPD Monitor Jan 08 11:28:22 music volumio[25025]: info: Initializing connection to go-librespot Websocket Jan 08 11:28:22 music volumio[25025]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 08 11:28:23 music volumio[25025]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 08 11:28:24 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 08 11:28:24 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 08 11:28:24 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 08 11:28:24 music go-librespot[25320]: go-librespot daemon starting... Jan 08 11:28:24 music go-librespot[25321]: time="2026-01-08T11:28:24-05:00" level=info msg="running go-librespot 0.6.2" Jan 08 11:28:24 music go-librespot[25321]: time="2026-01-08T11:28:24-05:00" level=debug msg="app state loaded" Jan 08 11:28:24 music go-librespot[25321]: time="2026-01-08T11:28:24-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 08 11:28:24 music go-librespot[25321]: time="2026-01-08T11:28:24-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]" Jan 08 11:28:24 music go-librespot[25321]: time="2026-01-08T11:28:24-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]" Jan 08 11:28:24 music go-librespot[25321]: time="2026-01-08T11:28:24-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]" Jan 08 11:28:24 music go-librespot[25321]: time="2026-01-08T11:28:24-05:00" level=info msg="zeroconf server listening on port 45509" Jan 08 11:28:24 music go-librespot[25321]: time="2026-01-08T11:28:24-05:00" level=debug msg="obtained new client token: AACcc4cR6klCF64bocKH+ES3ocQ6ZJgL1meV5UCkFcHcYuhBSAmMJymXh91sDtcgQN7TfrJa4mHHZTA9CJsAachM4RSzR0ijIKzlVhKDFGCvSjDTm7gK30LpU+IrV3FP11BBHQoDpIOnqPr8O74sWHcGpN2FaXMf8Z1SMJJWiW0zAehFwfi7NHyhBFCYgRKKG/Z1Jczyjbri2XE8sh+EJxxzk5q5XrLw6lVtk8ZtQg+8vvjG+i2AnkQ=" Jan 08 11:28:24 music go-librespot[25321]: time="2026-01-08T11:28:24-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 08 11:28:24 music go-librespot[25321]: time="2026-01-08T11:28:24-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:24 music go-librespot[25321]: time="2026-01-08T11:28:24-05:00" level=debug msg="completed challenge" Jan 08 11:28:24 music go-librespot[25321]: time="2026-01-08T11:28:24-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:25 music go-librespot[25321]: time="2026-01-08T11:28:25-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 08 11:28:25 music go-librespot[25321]: time="2026-01-08T11:28:25-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:25 music go-librespot[25321]: time="2026-01-08T11:28:25-05:00" level=debug msg="completed challenge" Jan 08 11:28:25 music go-librespot[25321]: time="2026-01-08T11:28:25-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:25 music volumio[25025]: info: Initializing connection to go-librespot Websocket Jan 08 11:28:25 music go-librespot[25321]: time="2026-01-08T11:28:25-05:00" level=debug msg="new websocket client" Jan 08 11:28:25 music volumio[25025]: info: Connection to go-librespot Websocket established Jan 08 11:28:26 music go-librespot[25321]: time="2026-01-08T11:28:26-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Jan 08 11:28:26 music go-librespot[25321]: time="2026-01-08T11:28:26-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:26 music go-librespot[25321]: time="2026-01-08T11:28:26-05:00" level=debug msg="completed challenge" Jan 08 11:28:26 music go-librespot[25321]: time="2026-01-08T11:28:26-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:26 music go-librespot[25321]: time="2026-01-08T11:28:26-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 08 11:28:26 music go-librespot[25321]: time="2026-01-08T11:28:26-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:26 music go-librespot[25321]: time="2026-01-08T11:28:26-05:00" level=debug msg="completed challenge" Jan 08 11:28:26 music volumio[25025]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 08 11:28:26 music volumio[25025]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 08 11:28:26 music volumio[25025]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 08 11:28:26 music volumio[25025]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 08 11:28:26 music volumio[25025]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 08 11:28:26 music volumio[25025]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 08 11:28:26 music volumio[25025]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 08 11:28:26 music volumio[25025]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 08 11:28:26 music volumio[25025]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 08 11:28:26 music volumio[25025]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 08 11:28:26 music volumio[25025]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 08 11:28:26 music volumio[25025]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 08 11:28:26 music volumio[25025]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 08 11:28:26 music volumio[25025]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 08 11:28:26 music volumio[25025]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 08 11:28:26 music volumio[25025]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 08 11:28:26 music volumio[25025]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 08 11:28:26 music volumio[25025]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 08 11:28:26 music volumio[25025]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 08 11:28:26 music volumio[25025]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 08 11:28:26 music volumio[25025]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 08 11:28:26 music volumio[25025]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 08 11:28:26 music volumio[25025]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 08 11:28:26 music volumio[25025]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 08 11:28:26 music volumio[25025]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 08 11:28:26 music volumio[25025]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 08 11:28:26 music volumio[25025]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 08 11:28:26 music volumio[25025]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 08 11:28:26 music volumio[25025]: info: Adding plugin bluetooth to MyMusic Plugins Jan 08 11:28:26 music volumio[25025]: info: Adding plugin multiroom to MyMusic Plugins Jan 08 11:28:26 music volumio[25025]: info: Adding plugin metavolumio to MyMusic Plugins Jan 08 11:28:26 music volumio[25025]: info: Adding plugin cd_controller to MyMusic Plugins Jan 08 11:28:26 music volumio[25025]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 08 11:28:26 music volumio[25025]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 08 11:28:26 music volumio[25025]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 08 11:28:26 music volumio[25025]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 08 11:28:26 music go-librespot[25321]: time="2026-01-08T11:28:26-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:27 music go-librespot[25321]: time="2026-01-08T11:28:27-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 08 11:28:27 music go-librespot[25321]: time="2026-01-08T11:28:27-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:27 music go-librespot[25321]: time="2026-01-08T11:28:27-05:00" level=debug msg="completed challenge" Jan 08 11:28:27 music volumio[25025]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 08 11:28:27 music volumio[25025]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 08 11:28:27 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 11:28:27 music volumio[25025]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 11:28:27 music volumio[25025]: info: Starting MyVolumio Remote Streaming Endpoints Jan 08 11:28:27 music volumio[25025]: info: MyVolumio login type: Token Jan 08 11:28:27 music volumio[25025]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 08 11:28:27 music volumio[25025]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 08 11:28:28 music go-librespot[25321]: time="2026-01-08T11:28:28-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:28 music go-librespot[25321]: time="2026-01-08T11:28:28-05:00" level=debug msg="connected to ap-gew1.spotify.com:80" Jan 08 11:28:28 music volumio[25025]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 08 11:28:28 music volumio[25025]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 08 11:28:28 music volumio[25025]: info: Streaming services startup Jan 08 11:28:28 music volumio[25025]: info: Starting Streaming Daemon Jan 08 11:28:28 music sudo[25332]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 08 11:28:28 music sudo[25332]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:28 music volumio[25025]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 08 11:28:28 music sudo[25332]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:29 music volumio[25025]: info: Getting Spotify volume Jan 08 11:28:29 music volumio[25025]: error: Cannot start Volumio Streaming Daemon Jan 08 11:28:29 music volumio[25025]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 08 11:28:29 music volumio[25025]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 08 11:28:29 music volumio[25025]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 08 11:28:29 music volumio[25025]: info: CoreCommandRouter::volumioGetState Jan 08 11:28:29 music volumio[25025]: info: CorePlayQueue::getTrack 0 Jan 08 11:28:29 music volumio[25025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Jan 08 11:28:29 music volumio[25025]: SPOTIFY: SPOTIFY VOLUME undefined Jan 08 11:28:29 music volumio[25025]: SPOTIFY: VOLUMIO VOLUME 86 Jan 08 11:28:29 music volumio[25025]: info: Aligning Spotify Volume to Volumio Volume Jan 08 11:28:29 music volumio[25025]: info: CoreCommandRouter::volumioGetState Jan 08 11:28:29 music volumio[25025]: info: CorePlayQueue::getTrack 0 Jan 08 11:28:29 music volumio[25025]: info: Setting Spotify Volume from Volumio: 86 Jan 08 11:28:29 music volumio[25025]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 08 11:28:29 music volumio[25025]: info: CoreCommandRouter::volumioGetState Jan 08 11:28:29 music volumio[25025]: info: CorePlayQueue::getTrack 0 Jan 08 11:28:29 music volumio[25025]: info: Listing playlists Jan 08 11:28:29 music volumio[25025]: info: Listing playlists Jan 08 11:28:30 music volumio[25025]: info: MyVolumio token set successfully Jan 08 11:28:30 music volumio[25025]: info: MYVOLUMIO: Adding device Jan 08 11:28:30 music volumio[25025]: info: MYVOLUMIO: Evaluating Server Jan 08 11:28:30 music volumio[25025]: info: MyVolumio status changed Jan 08 11:28:30 music volumio[25025]: info: Streaming services startup Jan 08 11:28:30 music volumio[25025]: info: Starting Streaming Daemon Jan 08 11:28:30 music volumio[25025]: info: Removing browser output: myVolumio user plan is not superstar Jan 08 11:28:30 music volumio[25025]: info: Removing audio output: Jan 08 11:28:30 music volumio[25025]: info: Stoppping Tunnel 1 Jan 08 11:28:30 music sudo[25374]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 08 11:28:30 music sudo[25374]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:30 music sudo[25376]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 08 11:28:30 music sudo[25376]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:30 music systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 08 11:28:30 music sudo[25374]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:30 music systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 08 11:28:30 music volumio[25025]: error: Cannot start Volumio Streaming Daemon Jan 08 11:28:30 music volumio[25025]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 08 11:28:30 music volumio[25025]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 08 11:28:30 music systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 08 11:28:30 music systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 08 11:28:30 music systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 08 11:28:30 music systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 08 11:28:30 music systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 08 11:28:30 music systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 08 11:28:30 music sudo[25376]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:30 music volumio[25025]: info: Remote SSH Stopped Jan 08 11:28:30 music go-librespot[25321]: time="2026-01-08T11:28:30-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.3.63:40558->104.199.65.9:80: read: connection reset by peer" Jan 08 11:28:30 music go-librespot[25321]: time="2026-01-08T11:28:30-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.3.63:40558->104.199.65.9:80: read: connection reset by peer" Jan 08 11:28:30 music volumio[25025]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 08 11:28:30 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 08 11:28:30 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 08 11:28:30 music volumio[25025]: Error: socket hang up Jan 08 11:28:30 music volumio[25025]: at connResetException (node:internal/errors:720:14) Jan 08 11:28:30 music volumio[25025]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 08 11:28:30 music volumio[25025]: at Socket.emit (node:events:526:35) Jan 08 11:28:30 music volumio[25025]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 08 11:28:30 music volumio[25025]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 08 11:28:30 music volumio[25025]: code: 'ECONNRESET', Jan 08 11:28:30 music volumio[25025]: response: undefined Jan 08 11:28:30 music volumio[25025]: } Jan 08 11:28:30 music volumio[25025]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 08 11:28:31 music sudo[25393]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-08 11:27' Jan 08 11:28:31 music sudo[25393]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:31 music sudo[25393]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:32 music volumio-remote-updater[696]: [2026-01-08 11:28:32] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 08 11:28:32 music volumio-remote-updater[696]: [2026-01-08 11:28:32] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 08 11:28:32 music systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 08 11:28:32 music systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 08 11:28:32 music systemd[1]: volumio.service: Consumed 27.785s CPU time. Jan 08 11:28:32 music systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 08 11:28:32 music systemd[1]: dynamicswap.service: Deactivated successfully. Jan 08 11:28:32 music systemd[1]: volumio.service: Scheduled restart job, restart counter is at 275. Jan 08 11:28:32 music systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 08 11:28:32 music systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 08 11:28:32 music systemd[1]: volumio.service: Consumed 27.785s CPU time. Jan 08 11:28:32 music systemd[1]: Started volumio.service - Volumio Backend Module. Jan 08 11:28:32 music systemd[1]: dynamicswap.service: Deactivated successfully. Jan 08 11:28:33 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 08 11:28:33 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 08 11:28:33 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 08 11:28:33 music go-librespot[25423]: go-librespot daemon starting... Jan 08 11:28:33 music go-librespot[25424]: time="2026-01-08T11:28:33-05:00" level=info msg="running go-librespot 0.6.2" Jan 08 11:28:33 music go-librespot[25424]: time="2026-01-08T11:28:33-05:00" level=debug msg="app state loaded" Jan 08 11:28:33 music go-librespot[25424]: time="2026-01-08T11:28:33-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 08 11:28:34 music go-librespot[25424]: time="2026-01-08T11:28:34-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]" Jan 08 11:28:34 music go-librespot[25424]: time="2026-01-08T11:28:34-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]" Jan 08 11:28:34 music go-librespot[25424]: time="2026-01-08T11:28:34-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]" Jan 08 11:28:34 music go-librespot[25424]: time="2026-01-08T11:28:34-05:00" level=info msg="zeroconf server listening on port 41247" Jan 08 11:28:34 music go-librespot[25424]: time="2026-01-08T11:28:34-05:00" level=debug msg="obtained new client token: AAC0HVxt6XuOxpZ0AQHhnIBLW7RCjWUPdfNcBnCsTqrMxdCAYa4EvCbYEoRotCa8sLM2fkzFYmoE+dSdVplqfVlPpiLsMoEffzhgJCm94XSvn1nIey9VEmnoSWwY1xY4xtnYRuaeAYjgEL1xVdbWAhyVIQR000TpdgyAiG9Pj8pC5DvqIBCAC0FfxemBQ05xwhvE/SQpu4vqHxkR7Lo8WjRyKnmmlgMUXMaGFKzd9wfnFDOF7oVQj9s=" Jan 08 11:28:34 music go-librespot[25424]: time="2026-01-08T11:28:34-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 08 11:28:34 music go-librespot[25424]: time="2026-01-08T11:28:34-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:34 music go-librespot[25424]: time="2026-01-08T11:28:34-05:00" level=debug msg="completed challenge" Jan 08 11:28:34 music go-librespot[25424]: time="2026-01-08T11:28:34-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:34 music volumio[25408]: info: ------------------------------------------- Jan 08 11:28:34 music volumio[25408]: info: ----- Volumio3 ---- Jan 08 11:28:34 music volumio[25408]: info: ------------------------------------------- Jan 08 11:28:34 music volumio[25408]: info: ----- System startup ---- Jan 08 11:28:34 music volumio[25408]: info: ------------------------------------------- Jan 08 11:28:35 music go-librespot[25424]: time="2026-01-08T11:28:35-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 08 11:28:35 music go-librespot[25424]: time="2026-01-08T11:28:35-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:35 music go-librespot[25424]: time="2026-01-08T11:28:35-05:00" level=debug msg="completed challenge" Jan 08 11:28:35 music go-librespot[25424]: time="2026-01-08T11:28:35-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:35 music volumio[25408]: info: MYVOLUMIO Environment detected Jan 08 11:28:35 music volumio[25408]: info: Plugin folders cleanup Jan 08 11:28:35 music volumio[25408]: info: Scanning into folder /volumio/app/plugins/ Jan 08 11:28:35 music volumio[25408]: info: Scanning category audio_interface Jan 08 11:28:35 music volumio[25408]: info: Scanning category miscellanea Jan 08 11:28:35 music volumio[25408]: info: Scanning category music_service Jan 08 11:28:35 music volumio[25408]: info: Scanning category plugins.json Jan 08 11:28:35 music volumio[25408]: info: Scanning category system_controller Jan 08 11:28:35 music volumio[25408]: info: Scanning category user_interface Jan 08 11:28:35 music volumio[25408]: info: Scanning into folder /data/plugins/ Jan 08 11:28:35 music volumio[25408]: info: Scanning category music_service Jan 08 11:28:35 music volumio[25408]: info: Plugin folders cleanup completed Jan 08 11:28:35 music volumio[25408]: info: ------------------------------------------- Jan 08 11:28:35 music volumio[25408]: info: ----- Core plugins startup ---- Jan 08 11:28:35 music volumio[25408]: info: ------------------------------------------- Jan 08 11:28:35 music volumio[25408]: info: Loading plugins from folder /volumio/app/plugins/ Jan 08 11:28:35 music volumio[25408]: info: Adding plugin upnp to MyMusic Plugins Jan 08 11:28:35 music volumio[25408]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 08 11:28:35 music volumio[25408]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 08 11:28:35 music volumio[25408]: info: Loading plugins from folder /data/plugins/ Jan 08 11:28:35 music volumio[25408]: info: Loading plugin "system"... Jan 08 11:28:35 music volumio[25408]: info: Loading plugin "appearance"... Jan 08 11:28:35 music go-librespot[25424]: time="2026-01-08T11:28:35-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Jan 08 11:28:35 music go-librespot[25424]: time="2026-01-08T11:28:35-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:35 music go-librespot[25424]: time="2026-01-08T11:28:35-05:00" level=debug msg="completed challenge" Jan 08 11:28:36 music go-librespot[25424]: time="2026-01-08T11:28:36-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:36 music go-librespot[25424]: time="2026-01-08T11:28:36-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 08 11:28:36 music go-librespot[25424]: time="2026-01-08T11:28:36-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:36 music go-librespot[25424]: time="2026-01-08T11:28:36-05:00" level=debug msg="completed challenge" Jan 08 11:28:36 music go-librespot[25424]: time="2026-01-08T11:28:36-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:36 music volumio[25408]: info: Loading plugin "network"... Jan 08 11:28:36 music volumio[25408]: info: Refreshing Cached IP Addresses Jan 08 11:28:36 music sudo[25446]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 08 11:28:36 music sudo[25446]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:36 music sudo[25446]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:36 music sudo[25448]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 08 11:28:36 music sudo[25448]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:37 music volumio[25408]: info: Loading plugin "services"... Jan 08 11:28:37 music volumio[25408]: info: Loading plugin "alsa_controller"... Jan 08 11:28:37 music sudo[25448]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:37 music sudo[25457]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 08 11:28:37 music sudo[25457]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:37 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 08 11:28:37 music volumio[25408]: info: Loading plugin "wizard"... Jan 08 11:28:37 music volumio[25408]: info: Loading plugin "networkfs"... Jan 08 11:28:37 music volumio[25408]: info: Starting Udev Watcher for removable devices Jan 08 11:28:37 music volumio[25408]: info: Ignoring mount for partition: boot Jan 08 11:28:37 music volumio[25408]: info: Ignoring mount for partition: volumio Jan 08 11:28:37 music volumio[25408]: info: Ignoring mount for partition: volumio_data Jan 08 11:28:37 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 08 11:28:37 music volumio[25408]: info: Loading plugin "volumio_command_line_client"... Jan 08 11:28:37 music volumio[25408]: info: Loading plugin "upnp"... Jan 08 11:28:37 music volumio[25408]: info: [1767889717171] Starting Upmpd Daemon Jan 08 11:28:37 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 08 11:28:37 music volumio[25408]: info: Loading plugin "my_music"... Jan 08 11:28:37 music volumio[25408]: info: Loading plugin "mpd"... Jan 08 11:28:37 music go-librespot[25424]: time="2026-01-08T11:28:37-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 08 11:28:37 music volumio-remote-updater[696]: [2026-01-08 11:28:37] [connect] Successful connection Jan 08 11:28:37 music volumio[25408]: info: Loading plugin "upnp_browser"... Jan 08 11:28:37 music sudo[25457]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:37 music go-librespot[25424]: time="2026-01-08T11:28:37-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:37 music go-librespot[25424]: time="2026-01-08T11:28:37-05:00" level=debug msg="completed challenge" Jan 08 11:28:37 music go-librespot[25424]: time="2026-01-08T11:28:37-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:38 music go-librespot[25424]: time="2026-01-08T11:28:38-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Jan 08 11:28:38 music go-librespot[25424]: time="2026-01-08T11:28:38-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:38 music go-librespot[25424]: time="2026-01-08T11:28:38-05:00" level=debug msg="completed challenge" Jan 08 11:28:38 music go-librespot[25424]: time="2026-01-08T11:28:38-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:38 music go-librespot[25424]: time="2026-01-08T11:28: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 " Jan 08 11:28:38 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 08 11:28:38 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 08 11:28:39 music volumio[25408]: info: Starting UPNP Browser Jan 08 11:28:39 music volumio[25408]: info: Loading plugin "alarm-clock"... Jan 08 11:28:39 music volumio[25408]: info: Loading plugin "airplay_emulation"... Jan 08 11:28:39 music volumio[25408]: info: Starting Shairport Sync Jan 08 11:28:39 music volumio[25408]: info: Loading plugin "last_100"... Jan 08 11:28:39 music volumio[25408]: info: Loading plugin "webradio"... Jan 08 11:28:39 music volumio[25408]: info: Loading plugin "i2s_dacs"... Jan 08 11:28:39 music volumio[25408]: info: I2S DAC not set, start Auto-detection Jan 08 11:28:39 music volumio[25408]: info: Loading plugin "volumiodiscovery"... Jan 08 11:28:39 music volumio[25408]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 08 11:28:39 music volumio[25408]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 08 11:28:39 music volumio[25408]: *** WARNING *** For more information see Jan 08 11:28:39 music volumio[25408]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 08 11:28:39 music volumio[25408]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 08 11:28:39 music volumio[25408]: *** WARNING *** For more information see Jan 08 11:28:39 music node[25408]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 08 11:28:39 music node[25408]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 08 11:28:39 music node[25408]: *** WARNING *** For more information see Jan 08 11:28:39 music node[25408]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 08 11:28:39 music node[25408]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 08 11:28:39 music node[25408]: *** WARNING *** For more information see Jan 08 11:28:39 music volumio[25408]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 08 11:28:39 music volumio[25408]: info: Discovery: Started advertising with name: music Jan 08 11:28:39 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 08 11:28:39 music volumio[25408]: info: Loading plugin "spop"... Jan 08 11:28:40 music volumio[25408]: info: Loading plugin "outputs"... Jan 08 11:28:40 music volumio[25408]: info: Loading plugin "albumart"... Jan 08 11:28:40 music volumio[25408]: info: Plugin example_plugin is not enabled Jan 08 11:28:40 music volumio[25408]: info: Loading plugin "inputs"... Jan 08 11:28:40 music volumio[25408]: info: Loading plugin "updater_comm"... Jan 08 11:28:40 music volumio[25408]: info: Plugin mpdemulation is not enabled Jan 08 11:28:40 music volumio[25408]: info: Loading plugin "rest_api"... Jan 08 11:28:40 music volumio[25408]: info: Loading plugin "websocket"... Jan 08 11:28:40 music volumio[25408]: info: Starting Socket.io Server version 1.7.4 Jan 08 11:28:40 music volumio[25408]: info: Loading i18n strings for locale en Jan 08 11:28:40 music volumio[25408]: Updating browse sources language Jan 08 11:28:40 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 11:28:40 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 11:28:40 music volumio[25408]: info: CoreCommandRouter::initPlayerControls Jan 08 11:28:40 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:40 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:40 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:40 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:40 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:40 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:40 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:40 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:40 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 11:28:40 music volumio[25408]: Express server listening on port 3000 Jan 08 11:28:40 music volumio[25408]: [Metrics] WebUI: 6s 602.89ms Jan 08 11:28:40 music volumio[25408]: info: CoreStateMachine::resetVolumioState Jan 08 11:28:41 music volumio[25408]: info: CoreStateMachine::getcurrentVolume Jan 08 11:28:41 music volumio[25408]: info: CoreCommandRouter::volumioRetrievevolume Jan 08 11:28:41 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 11:28:41 music volumio[25408]: info: Volumio Network Manager: Network status updated: 1 Jan 08 11:28:41 music volumio-remote-updater[696]: [2026-01-08 11:28:41] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1767889717 101 Jan 08 11:28:41 music volumio[25481]: Forking 3 albumart workers Jan 08 11:28:41 music volumio[25408]: 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 Jan 08 11:28:41 music volumio[25408]: info: VolumeController:: Volume=86 Mute =false Jan 08 11:28:41 music volumio[25408]: info: CoreStateMachine::pushState Jan 08 11:28:41 music volumio[25408]: info: CorePlayQueue::getTrack 0 Jan 08 11:28:41 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 08 11:28:41 music volumio[25408]: info: CoreCommandRouter::volumioPushState Jan 08 11:28:41 music volumio[25408]: info: CoreStateMachine::updateTrackBlock Jan 08 11:28:41 music volumio[25408]: info: CorePlayQueue::getTrackBlock Jan 08 11:28:41 music volumio[25408]: info: CoreCommandRouter::volumioRetrievevolume Jan 08 11:28:41 music volumio[25408]: info: Reloading queue from file Jan 08 11:28:41 music volumio[25408]: info: CoreCommandRouter::volumioGetState Jan 08 11:28:41 music volumio[25408]: info: CorePlayQueue::getTrack 0 Jan 08 11:28:41 music volumio[25408]: info: CoreStateMachine::setRepeat null single undefined Jan 08 11:28:41 music volumio[25408]: info: CoreStateMachine::pushState Jan 08 11:28:41 music volumio[25408]: info: CorePlayQueue::getTrack 0 Jan 08 11:28:41 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 08 11:28:41 music volumio[25408]: info: CoreCommandRouter::volumioPushState Jan 08 11:28:41 music volumio[25408]: info: CoreStateMachine::setRandom null Jan 08 11:28:41 music volumio[25408]: info: CoreStateMachine::pushState Jan 08 11:28:41 music volumio[25408]: info: CorePlayQueue::getTrack 0 Jan 08 11:28:41 music volumio[25408]: info: CoreCommandRouter::volumioPushState Jan 08 11:28:41 music volumio[25408]: info: Setting Device type: Raspberry PI Jan 08 11:28:41 music volumio[25408]: info: VolumeController:: Volume=86 Mute =false Jan 08 11:28:41 music volumio[25408]: info: CoreStateMachine::pushState Jan 08 11:28:41 music volumio[25408]: info: CorePlayQueue::getTrack 0 Jan 08 11:28:41 music volumio[25408]: info: CoreCommandRouter::volumioPushState Jan 08 11:28:41 music volumio[25408]: info: Completed loading Core Plugins Jan 08 11:28:41 music volumio[25408]: info: Preparing to generate the ALSA configuration file Jan 08 11:28:41 music volumio[25408]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Jan 08 11:28:41 music volumio[25408]: info: Discovery: Found device music Jan 08 11:28:41 music volumio[25408]: info: CoreCommandRouter::volumioGetState Jan 08 11:28:41 music volumio[25408]: info: CorePlayQueue::getTrack 0 Jan 08 11:28:41 music volumio[25408]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Jan 08 11:28:41 music volumio[25408]: info: Discovery: Found device music Jan 08 11:28:41 music volumio[25408]: info: CoreCommandRouter::volumioGetState Jan 08 11:28:41 music volumio[25408]: info: CorePlayQueue::getTrack 0 Jan 08 11:28:41 music volumio[25408]: info: Asound.conf file unchanged, so no further update is needed Jan 08 11:28:41 music volumio[25408]: info: Output device has changed, restarting MPD Jan 08 11:28:41 music volumio[25408]: info: Output device has changed, restarting Shairport Sync Jan 08 11:28:41 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:41 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 11:28:41 music sudo[25538]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 08 11:28:41 music volumio[25408]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 08 11:28:41 music sudo[25540]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 08 11:28:41 music sudo[25540]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:41 music volumio[25408]: info: ___________ START PLUGINS ___________ Jan 08 11:28:41 music sudo[25538]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:41 music sudo[25538]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:41 music volumio[25408]: info: ControllerMpd::onStart: Initializing MPD Jan 08 11:28:41 music volumio[25408]: info: Creating MPD Configuration file Jan 08 11:28:41 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 11:28:41 music volumio[25408]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 11:28:41 music volumio[25408]: info: [1767889721713] CoreMusicLibrary::Adding element Media Servers Jan 08 11:28:41 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 11:28:41 music systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 08 11:28:41 music volumio[25408]: info: UPNP Browser: Client initialized successfully Jan 08 11:28:41 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:41 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 11:28:41 music sudo[25551]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 08 11:28:41 music sudo[25551]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:41 music systemd[1]: mpd.service: Deactivated successfully. Jan 08 11:28:41 music systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 08 11:28:41 music systemd[1]: mpd.service: Consumed 4.105s CPU time. Jan 08 11:28:41 music systemd[1]: mpd.socket: Deactivated successfully. Jan 08 11:28:41 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 08 11:28:41 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 08 11:28:41 music volumio[25408]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 08 11:28:41 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:41 music sudo[25549]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 08 11:28:41 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 11:28:41 music sudo[25549]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:41 music sudo[25549]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:41 music volumio[25408]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 08 11:28:41 music volumio[25408]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 11:28:41 music volumio[25408]: info: [1767889721865] CoreMusicLibrary::Adding element Last_100 Jan 08 11:28:41 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 11:28:41 music volumio[25408]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 11:28:41 music volumio[25408]: info: [1767889721872] CoreMusicLibrary::Adding element Webradio Jan 08 11:28:41 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 11:28:41 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 08 11:28:41 music volumio[25408]: info: Initializing BBC Radios Jan 08 11:28:41 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 08 11:28:41 music systemd[1]: Starting mpd.service - Music Player Daemon... Jan 08 11:28:41 music systemd[1]: mpd.service: Deactivated successfully. Jan 08 11:28:41 music systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 08 11:28:41 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 08 11:28:41 music systemd[1]: mpd.socket: Deactivated successfully. Jan 08 11:28:41 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 08 11:28:41 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 08 11:28:41 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 08 11:28:41 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 08 11:28:42 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 08 11:28:42 music go-librespot[25577]: go-librespot daemon starting... Jan 08 11:28:42 music systemd[1]: Starting mpd.service - Music Player Daemon... Jan 08 11:28:42 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 08 11:28:42 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 11:28:42 music go-librespot[25580]: time="2026-01-08T11:28:42-05:00" level=info msg="running go-librespot 0.6.2" Jan 08 11:28:42 music go-librespot[25580]: time="2026-01-08T11:28:42-05:00" level=debug msg="app state loaded" Jan 08 11:28:42 music volumio[25408]: info: Creating Spotify config file Jan 08 11:28:42 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:42 music go-librespot[25580]: time="2026-01-08T11:28:42-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 08 11:28:42 music sudo[25581]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 08 11:28:42 music sudo[25581]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 08 11:28:42 music sudo[25581]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:42 music go-librespot[25580]: time="2026-01-08T11:28:42-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]" Jan 08 11:28:42 music go-librespot[25580]: time="2026-01-08T11:28:42-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]" Jan 08 11:28:42 music go-librespot[25580]: time="2026-01-08T11:28:42-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]" Jan 08 11:28:42 music go-librespot[25580]: time="2026-01-08T11:28:42-05:00" level=info msg="zeroconf server listening on port 43023" Jan 08 11:28:42 music go-librespot[25580]: time="2026-01-08T11:28:42-05:00" level=debug msg="obtained new client token: AAB7JdbRJdYknhJKcM0Uemxi94p1ZfDykrTWzg28Dj/YWmVO6WTpvAKwr6P8z1AbIJELN9SeLgoVgAGkyyg14pdpAkLXIql2fFQMOUzhH9YcWE85qDRnPN65FON8lXZLczvj0a/QY3E2wkYE4T5Vykj+3zH1BMLX+9rh4MIUVuCJr5+V1LkHLqsVBkWs8Vwol/iWnbAoqhOkCa+ubed3p0JmoiUTy7wm3hwqBBf/j+sTF6l4D8Vrr7I=" Jan 08 11:28:42 music go-librespot[25580]: time="2026-01-08T11:28:42-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 08 11:28:42 music go-librespot[25580]: time="2026-01-08T11:28:42-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:42 music go-librespot[25580]: time="2026-01-08T11:28:42-05:00" level=debug msg="completed challenge" Jan 08 11:28:42 music volumio[25408]: info: Volumio Calling Home Jan 08 11:28:42 music go-librespot[25580]: time="2026-01-08T11:28:42-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:43 music volumio[25498]: Starting albumart workers Jan 08 11:28:43 music volumio[25499]: Starting albumart workers Jan 08 11:28:43 music volumio[25497]: Starting albumart workers Jan 08 11:28:43 music go-librespot[25580]: time="2026-01-08T11:28:43-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 08 11:28:43 music go-librespot[25580]: time="2026-01-08T11:28:43-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:43 music go-librespot[25580]: time="2026-01-08T11:28:43-05:00" level=debug msg="completed challenge" Jan 08 11:28:43 music volumio[25408]: info: MPD Permissions set Jan 08 11:28:43 music volumio[25408]: info: MPD Permissions set Jan 08 11:28:43 music go-librespot[25580]: time="2026-01-08T11:28:43-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:43 music volumio[25408]: info: Volumio called home Jan 08 11:28:43 music volumio[25408]: info: Spotify config file written Jan 08 11:28:43 music volumio[25408]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 08 11:28:43 music sudo[25598]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 08 11:28:43 music sudo[25598]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:43 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:43 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:43 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:43 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:43 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:43 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:43 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:43 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:43 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 11:28:43 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:43 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:43 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:43 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:43 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:43 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:43 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:43 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 08 11:28:43 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:43 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:43 music systemd[1]: go-librespot-daemon.service: Killing process 25593 (go-librespot) with signal SIGKILL. Jan 08 11:28:43 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 08 11:28:43 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 08 11:28:44 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 11:28:44 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:28:44 music volumio[25408]: info: No need to fix Spotify hosts Jan 08 11:28:44 music go-librespot[25606]: go-librespot daemon starting... Jan 08 11:28:44 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 08 11:28:44 music sudo[25598]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:44 music go-librespot[25611]: time="2026-01-08T11:28:44-05:00" level=info msg="running go-librespot 0.6.2" Jan 08 11:28:44 music go-librespot[25611]: time="2026-01-08T11:28:44-05:00" level=debug msg="app state loaded" Jan 08 11:28:44 music go-librespot[25611]: time="2026-01-08T11:28:44-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 08 11:28:44 music go-librespot[25611]: time="2026-01-08T11:28:44-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Jan 08 11:28:44 music go-librespot[25611]: time="2026-01-08T11:28:44-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]" Jan 08 11:28:44 music go-librespot[25611]: time="2026-01-08T11:28:44-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]" Jan 08 11:28:44 music go-librespot[25611]: time="2026-01-08T11:28:44-05:00" level=info msg="zeroconf server listening on port 38569" Jan 08 11:28:44 music go-librespot[25611]: time="2026-01-08T11:28:44-05:00" level=debug msg="obtained new client token: AADIp37OsTSGBIdsW58vzPpaEF4fmJaTN68sfSAZgdZcMKfKpjZNUcJuYw/NEE3+U3/j5/BF4S++XkqsDCgv0XX4FpimbCQf3JlNLw+QUe4vkNQuW3a8UNySmPfquuoVMzcIedmM7YD95+4E+EfalySdjDyvk7Zh5OqJdsP2NF+iAHgKTR4D/OMDGmZ5Ar4eAa27UmmHnnIk54pdMxrM0ma78/4ViwqUu4aYkva9QYAOusdKDunRZ0U=" Jan 08 11:28:44 music volumio[25408]: info: An error occurred while refreshing Spotify Token Error: Bad Request Jan 08 11:28:44 music volumio[25408]: info: Starting Shairport Sync Jan 08 11:28:44 music volumio[25408]: info: Starting Shairport Sync Jan 08 11:28:44 music volumio[25408]: info: Starting Shairport Sync Jan 08 11:28:44 music go-librespot[25611]: time="2026-01-08T11:28:44-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 08 11:28:44 music sudo[25640]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 08 11:28:44 music sudo[25640]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:44 music sudo[25642]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 08 11:28:44 music sudo[25642]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:44 music sudo[25644]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 08 11:28:44 music sudo[25644]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:44 music go-librespot[25611]: time="2026-01-08T11:28:44-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:44 music go-librespot[25611]: time="2026-01-08T11:28:44-05:00" level=debug msg="completed challenge" Jan 08 11:28:44 music volumio[25408]: info: CoreCommandRouter::volumioGetState Jan 08 11:28:44 music volumio[25408]: info: CorePlayQueue::getTrack 0 Jan 08 11:28:44 music go-librespot[25611]: time="2026-01-08T11:28:44-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:44 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 08 11:28:44 music systemd[1]: shairport-sync.service: Deactivated successfully. Jan 08 11:28:44 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 08 11:28:44 music systemd[1]: shairport-sync.service: Consumed 1.909s CPU time. Jan 08 11:28:44 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 08 11:28:45 music sudo[25642]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:45 music volumio[25408]: info: Shairport-Sync Started Jan 08 11:28:45 music sudo[25640]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:45 music volumio[25408]: Error adding Membership: Error: addMembership EINVAL Jan 08 11:28:45 music sudo[25644]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:45 music volumio[25408]: info: Shairport-Sync Started Jan 08 11:28:45 music volumio[25408]: info: Shairport-Sync Started Jan 08 11:28:45 music go-librespot[25611]: time="2026-01-08T11:28:45-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 08 11:28:45 music go-librespot[25611]: time="2026-01-08T11:28:45-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:45 music go-librespot[25611]: time="2026-01-08T11:28:45-05:00" level=debug msg="completed challenge" Jan 08 11:28:45 music go-librespot[25611]: time="2026-01-08T11:28:45-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:46 music go-librespot[25611]: time="2026-01-08T11:28:46-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Jan 08 11:28:46 music go-librespot[25611]: time="2026-01-08T11:28:46-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:46 music go-librespot[25611]: time="2026-01-08T11:28:46-05:00" level=debug msg="completed challenge" Jan 08 11:28:46 music go-librespot[25611]: time="2026-01-08T11:28:46-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:46 music mpd[25592]: 2026-01-08T11:28:46 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 08 11:28:46 music systemd[1]: Started mpd.service - Music Player Daemon. Jan 08 11:28:46 music sudo[25551]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:46 music sudo[25540]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:46 music volumio[25408]: info: Completed starting Core Plugins Jan 08 11:28:46 music volumio[25408]: info: ------------------------------------------- Jan 08 11:28:46 music volumio[25408]: info: ----- MyVolumio plugins startup ---- Jan 08 11:28:46 music volumio[25408]: info: ------------------------------------------- Jan 08 11:28:46 music volumio[25408]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 08 11:28:46 music volumio[25408]: error: MPD error: The expression evaluated to a falsy value: Jan 08 11:28:46 music volumio[25408]: assert.ok(self.idling) Jan 08 11:28:46 music volumio[25408]: error: The expression evaluated to a falsy value: Jan 08 11:28:46 music volumio[25408]: assert.ok(self.idling) Jan 08 11:28:46 music volumio[25408]: info: MPD running with PID25592 Jan 08 11:28:46 music volumio[25408]: ,establishing connection Jan 08 11:28:46 music volumio[25408]: error: updateQueue error: null Jan 08 11:28:46 music volumio[25408]: error: updateQueue error: null Jan 08 11:28:46 music go-librespot[25611]: time="2026-01-08T11:28:46-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 08 11:28:46 music go-librespot[25611]: time="2026-01-08T11:28:46-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:46 music go-librespot[25611]: time="2026-01-08T11:28:46-05:00" level=debug msg="completed challenge" Jan 08 11:28:46 music go-librespot[25611]: time="2026-01-08T11:28:46-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:47 music sudo[25683]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 08 11:28:47 music sudo[25683]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:47 music sudo[25683]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:47 music sudo[25685]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 08 11:28:47 music sudo[25685]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:47 music sudo[25685]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:47 music sudo[25688]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 08 11:28:47 music sudo[25688]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:47 music sudo[25688]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:47 music volumio[25408]: info: Upmpdcli Daemon Started Jan 08 11:28:47 music go-librespot[25611]: time="2026-01-08T11:28:47-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 08 11:28:47 music volumio[25408]: info: go-librespot daemon successfully initialized Jan 08 11:28:48 music go-librespot[25611]: time="2026-01-08T11:28:48-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:48 music go-librespot[25611]: time="2026-01-08T11:28:48-05:00" level=debug msg="completed challenge" Jan 08 11:28:48 music go-librespot[25611]: time="2026-01-08T11:28:48-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:49 music go-librespot[25611]: time="2026-01-08T11:28:49-05:00" level=debug msg="connected to ap-gew1.spotify.com:80" Jan 08 11:28:49 music go-librespot[25611]: time="2026-01-08T11:28:49-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:49 music go-librespot[25611]: time="2026-01-08T11:28:49-05:00" level=debug msg="completed challenge" Jan 08 11:28:49 music go-librespot[25611]: time="2026-01-08T11:28:49-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:49 music go-librespot[25611]: time="2026-01-08T11:28:49-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 " Jan 08 11:28:49 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 08 11:28:49 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 08 11:28:49 music sudo[25694]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 08 11:28:49 music sudo[25694]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:49 music volumio[25408]: info: CoreCommandRouter::volumioGetState Jan 08 11:28:49 music volumio[25408]: info: CorePlayQueue::getTrack 0 Jan 08 11:28:49 music sudo[25697]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 08 11:28:49 music sudo[25697]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:49 music volumio[25408]: info: Listing playlists Jan 08 11:28:49 music volumio[25408]: info: Listing playlists Jan 08 11:28:49 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Jan 08 11:28:49 music systemd[1]: mpd_monitor.service: Deactivated successfully. Jan 08 11:28:49 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Jan 08 11:28:49 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Jan 08 11:28:49 music sudo[25694]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:49 music volumio[25408]: info: Successfully started MPD Monitor Jan 08 11:28:49 music mpd_monitor.sh[25699]: MPD Monitor Service: Starting MPD Monitor Service Jan 08 11:28:49 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Jan 08 11:28:49 music systemd[1]: mpd_monitor.service: Deactivated successfully. Jan 08 11:28:49 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Jan 08 11:28:49 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Jan 08 11:28:49 music sudo[25697]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:49 music volumio[25408]: info: Successfully started MPD Monitor Jan 08 11:28:49 music mpd_monitor.sh[25705]: MPD Monitor Service: Starting MPD Monitor Service Jan 08 11:28:50 music volumio[25408]: info: Initializing connection to go-librespot Websocket Jan 08 11:28:50 music volumio[25408]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 08 11:28:51 music volumio[25408]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 08 11:28:52 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 08 11:28:52 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 08 11:28:52 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 08 11:28:52 music go-librespot[25709]: go-librespot daemon starting... Jan 08 11:28:52 music go-librespot[25710]: time="2026-01-08T11:28:52-05:00" level=info msg="running go-librespot 0.6.2" Jan 08 11:28:52 music go-librespot[25710]: time="2026-01-08T11:28:52-05:00" level=debug msg="app state loaded" Jan 08 11:28:52 music go-librespot[25710]: time="2026-01-08T11:28:52-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 08 11:28:52 music go-librespot[25710]: time="2026-01-08T11:28:52-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Jan 08 11:28:52 music go-librespot[25710]: time="2026-01-08T11:28:52-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]" Jan 08 11:28:52 music go-librespot[25710]: time="2026-01-08T11:28:52-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]" Jan 08 11:28:52 music go-librespot[25710]: time="2026-01-08T11:28:52-05:00" level=info msg="zeroconf server listening on port 36191" Jan 08 11:28:53 music go-librespot[25710]: time="2026-01-08T11:28:53-05:00" level=debug msg="obtained new client token: AACJVbYHTRbNT1P+yXrYYuAUfzp9oa//E5+sbgy6cjrqdd+0gB6wHihnihIaY8+Fvdf49vJ/RUTpqlay/Lz5hFHj8/fHl2Kb2byIALE3vgvo6Vb2+pKWAkkGQABgmOYwEpD+yP9wyE1zO4dZ6hvLCRrouDHPSLDKb6Mv5pQ1qAwvwyHGhtSNrNG/eMzJeA7/7GkdGGq2TRBMmTYH/CisZzRlYEvhANOfM1n1u/o1B4RoO8k0CXrI" Jan 08 11:28:53 music go-librespot[25710]: time="2026-01-08T11:28:53-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 08 11:28:53 music go-librespot[25710]: time="2026-01-08T11:28:53-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:53 music go-librespot[25710]: time="2026-01-08T11:28:53-05:00" level=debug msg="completed challenge" Jan 08 11:28:53 music go-librespot[25710]: time="2026-01-08T11:28:53-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:53 music volumio[25408]: info: Initializing connection to go-librespot Websocket Jan 08 11:28:53 music go-librespot[25710]: time="2026-01-08T11:28:53-05:00" level=debug msg="new websocket client" Jan 08 11:28:53 music volumio[25408]: info: Connection to go-librespot Websocket established Jan 08 11:28:53 music go-librespot[25710]: time="2026-01-08T11:28:53-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 08 11:28:53 music go-librespot[25710]: time="2026-01-08T11:28:53-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:53 music go-librespot[25710]: time="2026-01-08T11:28:53-05:00" level=debug msg="completed challenge" Jan 08 11:28:53 music go-librespot[25710]: time="2026-01-08T11:28:53-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:54 music go-librespot[25710]: time="2026-01-08T11:28:54-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Jan 08 11:28:54 music go-librespot[25710]: time="2026-01-08T11:28:54-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:54 music go-librespot[25710]: time="2026-01-08T11:28:54-05:00" level=debug msg="completed challenge" Jan 08 11:28:54 music go-librespot[25710]: time="2026-01-08T11:28:54-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:54 music volumio[25408]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 08 11:28:54 music volumio[25408]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 08 11:28:54 music volumio[25408]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 08 11:28:54 music volumio[25408]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 08 11:28:54 music volumio[25408]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 08 11:28:54 music volumio[25408]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 08 11:28:54 music volumio[25408]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 08 11:28:54 music volumio[25408]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 08 11:28:54 music volumio[25408]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 08 11:28:54 music volumio[25408]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 08 11:28:54 music volumio[25408]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 08 11:28:54 music volumio[25408]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 08 11:28:54 music volumio[25408]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 08 11:28:54 music volumio[25408]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 08 11:28:54 music volumio[25408]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 08 11:28:54 music volumio[25408]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 08 11:28:54 music volumio[25408]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 08 11:28:54 music volumio[25408]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 08 11:28:54 music volumio[25408]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 08 11:28:54 music volumio[25408]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 08 11:28:54 music volumio[25408]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 08 11:28:54 music volumio[25408]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 08 11:28:54 music volumio[25408]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 08 11:28:54 music volumio[25408]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 08 11:28:54 music volumio[25408]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 08 11:28:54 music volumio[25408]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 08 11:28:54 music volumio[25408]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 08 11:28:54 music volumio[25408]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 08 11:28:54 music volumio[25408]: info: Adding plugin bluetooth to MyMusic Plugins Jan 08 11:28:54 music volumio[25408]: info: Adding plugin multiroom to MyMusic Plugins Jan 08 11:28:54 music volumio[25408]: info: Adding plugin metavolumio to MyMusic Plugins Jan 08 11:28:54 music volumio[25408]: info: Adding plugin cd_controller to MyMusic Plugins Jan 08 11:28:54 music volumio[25408]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 08 11:28:54 music volumio[25408]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 08 11:28:54 music volumio[25408]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 08 11:28:54 music volumio[25408]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 08 11:28:55 music go-librespot[25710]: time="2026-01-08T11:28:55-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 08 11:28:55 music go-librespot[25710]: time="2026-01-08T11:28:55-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:55 music go-librespot[25710]: time="2026-01-08T11:28:55-05:00" level=debug msg="completed challenge" Jan 08 11:28:55 music go-librespot[25710]: time="2026-01-08T11:28:55-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:55 music volumio[25408]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 08 11:28:55 music volumio[25408]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 08 11:28:55 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 11:28:55 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 11:28:55 music volumio[25408]: info: Starting MyVolumio Remote Streaming Endpoints Jan 08 11:28:55 music volumio[25408]: info: MyVolumio login type: Token Jan 08 11:28:55 music volumio[25408]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 08 11:28:55 music volumio[25408]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 08 11:28:56 music go-librespot[25710]: time="2026-01-08T11:28:56-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 08 11:28:56 music go-librespot[25710]: time="2026-01-08T11:28:56-05:00" level=debug msg="completed keyexchange" Jan 08 11:28:56 music go-librespot[25710]: time="2026-01-08T11:28:56-05:00" level=debug msg="completed challenge" Jan 08 11:28:56 music volumio[25408]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 08 11:28:56 music volumio[25408]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 08 11:28:56 music volumio[25408]: info: Streaming services startup Jan 08 11:28:56 music volumio[25408]: info: Starting Streaming Daemon Jan 08 11:28:56 music sudo[25720]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 08 11:28:56 music sudo[25720]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:56 music volumio[25408]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 08 11:28:56 music sudo[25720]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:56 music volumio[25408]: info: Getting Spotify volume Jan 08 11:28:57 music volumio[25408]: error: Cannot start Volumio Streaming Daemon Jan 08 11:28:57 music volumio[25408]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 08 11:28:57 music volumio[25408]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 08 11:28:57 music volumio[25408]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 08 11:28:57 music volumio[25408]: info: CoreCommandRouter::volumioGetState Jan 08 11:28:57 music volumio[25408]: info: CorePlayQueue::getTrack 0 Jan 08 11:28:57 music volumio[25408]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Jan 08 11:28:57 music volumio[25408]: SPOTIFY: SPOTIFY VOLUME undefined Jan 08 11:28:57 music volumio[25408]: SPOTIFY: VOLUMIO VOLUME 86 Jan 08 11:28:57 music volumio[25408]: info: Aligning Spotify Volume to Volumio Volume Jan 08 11:28:57 music volumio[25408]: info: CoreCommandRouter::volumioGetState Jan 08 11:28:57 music volumio[25408]: info: CorePlayQueue::getTrack 0 Jan 08 11:28:57 music volumio[25408]: info: Setting Spotify Volume from Volumio: 86 Jan 08 11:28:57 music volumio[25408]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 08 11:28:57 music go-librespot[25710]: time="2026-01-08T11:28:57-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:28:58 music volumio[25408]: info: MyVolumio token set successfully Jan 08 11:28:58 music volumio[25408]: info: MYVOLUMIO: Adding device Jan 08 11:28:58 music volumio[25408]: info: MYVOLUMIO: Evaluating Server Jan 08 11:28:58 music volumio[25408]: info: MyVolumio status changed Jan 08 11:28:58 music volumio[25408]: info: Streaming services startup Jan 08 11:28:58 music volumio[25408]: info: Starting Streaming Daemon Jan 08 11:28:58 music volumio[25408]: info: Removing browser output: myVolumio user plan is not superstar Jan 08 11:28:58 music volumio[25408]: info: Removing audio output: Jan 08 11:28:58 music volumio[25408]: info: Stoppping Tunnel 1 Jan 08 11:28:58 music sudo[25761]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 08 11:28:58 music sudo[25761]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:58 music sudo[25763]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 08 11:28:58 music sudo[25763]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:28:58 music sudo[25761]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:58 music volumio[25408]: error: Cannot start Volumio Streaming Daemon Jan 08 11:28:58 music volumio[25408]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 08 11:28:58 music volumio[25408]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 08 11:28:58 music systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 08 11:28:58 music systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 08 11:28:58 music systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 08 11:28:58 music systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 08 11:28:58 music systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 08 11:28:58 music systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 08 11:28:58 music systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 08 11:28:58 music systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 08 11:28:58 music sudo[25763]: pam_unix(sudo:session): session closed for user root Jan 08 11:28:58 music volumio[25408]: info: Remote SSH Stopped Jan 08 11:28:58 music volumio[25408]: SPOTIFY: SETTING SPOTIFY VOLUME 86 Jan 08 11:28:58 music volumio[25408]: info: Sending Spotify command with payload to local API: /player/volume Jan 08 11:28:59 music volumio[25408]: info: CoreCommandRouter::volumioGetState Jan 08 11:28:59 music volumio[25408]: info: CorePlayQueue::getTrack 0 Jan 08 11:29:03 music go-librespot[25710]: time="2026-01-08T11:29:03-05:00" level=debug msg="connected to ap-gew1.spotify.com:80" Jan 08 11:29:03 music volumio[25408]: info: Setting Geolocation for MyVolumio to us4 Jan 08 11:29:03 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 11:29:03 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 11:29:03 music volumio[25408]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 11:29:03 music go-librespot[25710]: time="2026-01-08T11:29:03-05:00" level=debug msg="completed keyexchange" Jan 08 11:29:03 music go-librespot[25710]: time="2026-01-08T11:29:03-05:00" level=debug msg="completed challenge" Jan 08 11:29:03 music go-librespot[25710]: time="2026-01-08T11:29:03-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:29:03 music go-librespot[25710]: time="2026-01-08T11:29:03-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 " Jan 08 11:29:03 music volumio[25408]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Jan 08 11:29:03 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 08 11:29:03 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 08 11:29:03 music volumio[25408]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 08 11:29:03 music volumio[25408]: Error: socket hang up Jan 08 11:29:03 music volumio[25408]: at connResetException (node:internal/errors:720:14) Jan 08 11:29:03 music volumio[25408]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 08 11:29:03 music volumio[25408]: at Socket.emit (node:events:526:35) Jan 08 11:29:03 music volumio[25408]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 08 11:29:03 music volumio[25408]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 08 11:29:03 music volumio[25408]: code: 'ECONNRESET', Jan 08 11:29:03 music volumio[25408]: response: undefined Jan 08 11:29:03 music volumio[25408]: } Jan 08 11:29:03 music volumio[25408]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 08 11:29:04 music sudo[25780]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-08 11:28' Jan 08 11:29:04 music sudo[25780]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:29:04 music sudo[25780]: pam_unix(sudo:session): session closed for user root Jan 08 11:29:04 music volumio-remote-updater[696]: [2026-01-08 11:29:04] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 08 11:29:04 music volumio-remote-updater[696]: [2026-01-08 11:29:04] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 08 11:29:04 music systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 08 11:29:04 music systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 08 11:29:04 music systemd[1]: volumio.service: Consumed 27.841s CPU time. Jan 08 11:29:04 music systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 08 11:29:04 music systemd[1]: dynamicswap.service: Deactivated successfully. Jan 08 11:29:05 music systemd[1]: volumio.service: Scheduled restart job, restart counter is at 276. Jan 08 11:29:05 music systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 08 11:29:05 music systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 08 11:29:05 music systemd[1]: volumio.service: Consumed 27.841s CPU time. Jan 08 11:29:05 music systemd[1]: Started volumio.service - Volumio Backend Module. Jan 08 11:29:05 music systemd[1]: dynamicswap.service: Deactivated successfully. Jan 08 11:29:07 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 08 11:29:07 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 08 11:29:07 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 08 11:29:07 music go-librespot[25813]: go-librespot daemon starting... Jan 08 11:29:07 music volumio[25792]: info: ------------------------------------------- Jan 08 11:29:07 music volumio[25792]: info: ----- Volumio3 ---- Jan 08 11:29:07 music volumio[25792]: info: ------------------------------------------- Jan 08 11:29:07 music volumio[25792]: info: ----- System startup ---- Jan 08 11:29:07 music volumio[25792]: info: ------------------------------------------- Jan 08 11:29:07 music go-librespot[25814]: time="2026-01-08T11:29:07-05:00" level=info msg="running go-librespot 0.6.2" Jan 08 11:29:07 music go-librespot[25814]: time="2026-01-08T11:29:07-05:00" level=debug msg="app state loaded" Jan 08 11:29:07 music go-librespot[25814]: time="2026-01-08T11:29:07-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 08 11:29:07 music go-librespot[25814]: time="2026-01-08T11:29:07-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]" Jan 08 11:29:07 music go-librespot[25814]: time="2026-01-08T11:29:07-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]" Jan 08 11:29:07 music go-librespot[25814]: time="2026-01-08T11:29:07-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]" Jan 08 11:29:07 music go-librespot[25814]: time="2026-01-08T11:29:07-05:00" level=info msg="zeroconf server listening on port 37765" Jan 08 11:29:07 music go-librespot[25814]: time="2026-01-08T11:29:07-05:00" level=debug msg="obtained new client token: AAAg0+Ngukie501Ct2Jwgqi8Dk+H1UHQVYpEoe1/SHD/wAtUNTLcLNUTK1RiihzDsk1qiGZVO80XMoPmLC7vT5W2cm2Hr79R22n/9QbdyhahDSQypfB3YNjYTbP/lfDAWMhX2qLEal0vYOV74nCy9tMkgmV9puCldRSm7Q4yb6hZkSlmPjxNnpgWtUgW3heXwAw17f+BA+5GVassXoIryT09GGCmOgs9ojii+BXSMh267kSixIWgAb8=" Jan 08 11:29:07 music go-librespot[25814]: time="2026-01-08T11:29:07-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 08 11:29:07 music go-librespot[25814]: time="2026-01-08T11:29:07-05:00" level=debug msg="completed keyexchange" Jan 08 11:29:07 music go-librespot[25814]: time="2026-01-08T11:29:07-05:00" level=debug msg="completed challenge" Jan 08 11:29:07 music go-librespot[25814]: time="2026-01-08T11:29:07-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:29:07 music volumio[25792]: info: MYVOLUMIO Environment detected Jan 08 11:29:08 music volumio[25792]: info: Plugin folders cleanup Jan 08 11:29:08 music volumio[25792]: info: Scanning into folder /volumio/app/plugins/ Jan 08 11:29:08 music volumio[25792]: info: Scanning category audio_interface Jan 08 11:29:08 music volumio[25792]: info: Scanning category miscellanea Jan 08 11:29:08 music volumio[25792]: info: Scanning category music_service Jan 08 11:29:08 music volumio[25792]: info: Scanning category plugins.json Jan 08 11:29:08 music volumio[25792]: info: Scanning category system_controller Jan 08 11:29:08 music volumio[25792]: info: Scanning category user_interface Jan 08 11:29:08 music volumio[25792]: info: Scanning into folder /data/plugins/ Jan 08 11:29:08 music volumio[25792]: info: Scanning category music_service Jan 08 11:29:08 music volumio[25792]: info: Plugin folders cleanup completed Jan 08 11:29:08 music volumio[25792]: info: ------------------------------------------- Jan 08 11:29:08 music volumio[25792]: info: ----- Core plugins startup ---- Jan 08 11:29:08 music volumio[25792]: info: ------------------------------------------- Jan 08 11:29:08 music volumio[25792]: info: Loading plugins from folder /volumio/app/plugins/ Jan 08 11:29:08 music volumio[25792]: info: Adding plugin upnp to MyMusic Plugins Jan 08 11:29:08 music volumio[25792]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 08 11:29:08 music volumio[25792]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 08 11:29:08 music volumio[25792]: info: Loading plugins from folder /data/plugins/ Jan 08 11:29:08 music volumio[25792]: info: Loading plugin "system"... Jan 08 11:29:08 music volumio[25792]: info: Loading plugin "appearance"... Jan 08 11:29:08 music go-librespot[25814]: time="2026-01-08T11:29:08-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 08 11:29:08 music go-librespot[25814]: time="2026-01-08T11:29:08-05:00" level=debug msg="completed keyexchange" Jan 08 11:29:08 music go-librespot[25814]: time="2026-01-08T11:29:08-05:00" level=debug msg="completed challenge" Jan 08 11:29:08 music go-librespot[25814]: time="2026-01-08T11:29:08-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:29:09 music go-librespot[25814]: time="2026-01-08T11:29:09-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Jan 08 11:29:09 music volumio[25792]: info: Loading plugin "network"... Jan 08 11:29:09 music volumio[25792]: info: Refreshing Cached IP Addresses Jan 08 11:29:09 music sudo[25830]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 08 11:29:09 music sudo[25830]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:29:09 music sudo[25830]: pam_unix(sudo:session): session closed for user root Jan 08 11:29:09 music sudo[25832]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 08 11:29:09 music sudo[25832]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:29:09 music sudo[25832]: pam_unix(sudo:session): session closed for user root Jan 08 11:29:09 music volumio[25792]: info: Loading plugin "services"... Jan 08 11:29:09 music volumio[25792]: info: Loading plugin "alsa_controller"... Jan 08 11:29:09 music sudo[25840]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 08 11:29:09 music sudo[25840]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:29:09 music go-librespot[25814]: time="2026-01-08T11:29:09-05:00" level=debug msg="completed keyexchange" Jan 08 11:29:09 music go-librespot[25814]: time="2026-01-08T11:29:09-05:00" level=debug msg="completed challenge" Jan 08 11:29:09 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 08 11:29:09 music volumio[25792]: info: Loading plugin "wizard"... Jan 08 11:29:09 music volumio[25792]: info: Loading plugin "networkfs"... Jan 08 11:29:09 music volumio[25792]: info: Starting Udev Watcher for removable devices Jan 08 11:29:09 music go-librespot[25814]: time="2026-01-08T11:29:09-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:29:09 music volumio[25792]: info: Ignoring mount for partition: boot Jan 08 11:29:09 music volumio[25792]: info: Ignoring mount for partition: volumio Jan 08 11:29:09 music volumio[25792]: info: Ignoring mount for partition: volumio_data Jan 08 11:29:09 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 08 11:29:09 music volumio[25792]: info: Loading plugin "volumio_command_line_client"... Jan 08 11:29:09 music volumio[25792]: info: Loading plugin "upnp"... Jan 08 11:29:09 music volumio[25792]: info: [1767889749433] Starting Upmpd Daemon Jan 08 11:29:09 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 08 11:29:09 music volumio[25792]: info: Loading plugin "my_music"... Jan 08 11:29:09 music volumio[25792]: info: Loading plugin "mpd"... Jan 08 11:29:09 music volumio[25792]: info: Loading plugin "upnp_browser"... Jan 08 11:29:09 music volumio-remote-updater[696]: [2026-01-08 11:29:09] [connect] Successful connection Jan 08 11:29:09 music sudo[25840]: pam_unix(sudo:session): session closed for user root Jan 08 11:29:09 music go-librespot[25814]: time="2026-01-08T11:29:09-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 08 11:29:10 music go-librespot[25814]: time="2026-01-08T11:29:10-05:00" level=debug msg="completed keyexchange" Jan 08 11:29:10 music go-librespot[25814]: time="2026-01-08T11:29:10-05:00" level=debug msg="completed challenge" Jan 08 11:29:10 music go-librespot[25814]: time="2026-01-08T11:29:10-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:29:10 music go-librespot[25814]: time="2026-01-08T11:29:10-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Jan 08 11:29:10 music go-librespot[25814]: time="2026-01-08T11:29:10-05:00" level=debug msg="completed keyexchange" Jan 08 11:29:10 music go-librespot[25814]: time="2026-01-08T11:29:10-05:00" level=debug msg="completed challenge" Jan 08 11:29:10 music go-librespot[25814]: time="2026-01-08T11:29:10-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:29:11 music volumio[25792]: info: Starting UPNP Browser Jan 08 11:29:11 music volumio[25792]: info: Loading plugin "alarm-clock"... Jan 08 11:29:11 music volumio[25792]: info: Loading plugin "airplay_emulation"... Jan 08 11:29:11 music volumio[25792]: info: Starting Shairport Sync Jan 08 11:29:11 music volumio[25792]: info: Loading plugin "last_100"... Jan 08 11:29:11 music volumio[25792]: info: Loading plugin "webradio"... Jan 08 11:29:11 music go-librespot[25814]: time="2026-01-08T11:29:11-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Jan 08 11:29:11 music volumio[25792]: info: Loading plugin "i2s_dacs"... Jan 08 11:29:11 music volumio[25792]: info: I2S DAC not set, start Auto-detection Jan 08 11:29:11 music volumio[25792]: info: Loading plugin "volumiodiscovery"... Jan 08 11:29:11 music go-librespot[25814]: time="2026-01-08T11:29:11-05:00" level=debug msg="completed keyexchange" Jan 08 11:29:11 music go-librespot[25814]: time="2026-01-08T11:29:11-05:00" level=debug msg="completed challenge" Jan 08 11:29:11 music volumio[25792]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 08 11:29:11 music volumio[25792]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 08 11:29:11 music volumio[25792]: *** WARNING *** For more information see Jan 08 11:29:11 music volumio[25792]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 08 11:29:11 music volumio[25792]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 08 11:29:11 music volumio[25792]: *** WARNING *** For more information see Jan 08 11:29:11 music node[25792]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 08 11:29:11 music node[25792]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 08 11:29:11 music node[25792]: *** WARNING *** For more information see Jan 08 11:29:11 music node[25792]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 08 11:29:11 music node[25792]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 08 11:29:11 music node[25792]: *** WARNING *** For more information see Jan 08 11:29:11 music volumio[25792]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 08 11:29:11 music volumio[25792]: info: Discovery: Started advertising with name: music Jan 08 11:29:11 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 08 11:29:11 music volumio[25792]: info: Loading plugin "spop"... Jan 08 11:29:11 music go-librespot[25814]: time="2026-01-08T11:29:11-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:29:11 music go-librespot[25814]: time="2026-01-08T11:29:11-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 " Jan 08 11:29:11 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 08 11:29:11 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 08 11:29:12 music volumio[25792]: info: Loading plugin "outputs"... Jan 08 11:29:12 music volumio[25792]: info: Loading plugin "albumart"... Jan 08 11:29:12 music volumio[25792]: info: Plugin example_plugin is not enabled Jan 08 11:29:12 music volumio[25792]: info: Loading plugin "inputs"... Jan 08 11:29:12 music volumio[25792]: info: Loading plugin "updater_comm"... Jan 08 11:29:12 music volumio[25792]: info: Plugin mpdemulation is not enabled Jan 08 11:29:12 music volumio[25792]: info: Loading plugin "rest_api"... Jan 08 11:29:13 music volumio[25792]: info: Loading plugin "websocket"... Jan 08 11:29:13 music volumio[25792]: info: Starting Socket.io Server version 1.7.4 Jan 08 11:29:13 music volumio[25792]: info: Loading i18n strings for locale en Jan 08 11:29:13 music volumio[25792]: Updating browse sources language Jan 08 11:29:13 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 11:29:13 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 11:29:13 music volumio[25792]: info: CoreCommandRouter::initPlayerControls Jan 08 11:29:13 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:29:13 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:29:13 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:29:13 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:29:13 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:29:13 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:29:13 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:29:13 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:29:13 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 11:29:13 music volumio[25792]: Express server listening on port 3000 Jan 08 11:29:13 music volumio[25792]: [Metrics] WebUI: 6s 659.07ms Jan 08 11:29:13 music volumio[25792]: info: CoreStateMachine::resetVolumioState Jan 08 11:29:13 music volumio[25792]: info: CoreStateMachine::getcurrentVolume Jan 08 11:29:13 music volumio[25792]: info: CoreCommandRouter::volumioRetrievevolume Jan 08 11:29:13 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 11:29:13 music volumio[25792]: info: Volumio Network Manager: Network status updated: 1 Jan 08 11:29:13 music volumio[25868]: Forking 3 albumart workers Jan 08 11:29:13 music volumio[25792]: info: VolumeController:: Volume=86 Mute =false Jan 08 11:29:13 music volumio[25792]: info: CoreStateMachine::pushState Jan 08 11:29:13 music volumio[25792]: info: CorePlayQueue::getTrack 0 Jan 08 11:29:13 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 08 11:29:13 music volumio[25792]: info: CoreCommandRouter::volumioPushState Jan 08 11:29:13 music volumio[25792]: info: CoreStateMachine::updateTrackBlock Jan 08 11:29:13 music volumio[25792]: info: CorePlayQueue::getTrackBlock Jan 08 11:29:13 music volumio[25792]: info: CoreCommandRouter::volumioRetrievevolume Jan 08 11:29:13 music volumio[25792]: info: CoreCommandRouter::volumioGetState Jan 08 11:29:13 music volumio[25792]: info: CorePlayQueue::getTrack 0 Jan 08 11:29:13 music volumio-remote-updater[696]: [2026-01-08 11:29:13] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1767889749 101 Jan 08 11:29:13 music volumio[25792]: 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 Jan 08 11:29:13 music volumio[25792]: info: Reloading queue from file Jan 08 11:29:13 music volumio[25792]: info: CoreStateMachine::setRepeat null single undefined Jan 08 11:29:13 music volumio[25792]: info: CoreStateMachine::pushState Jan 08 11:29:13 music volumio[25792]: info: CorePlayQueue::getTrack 0 Jan 08 11:29:13 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 08 11:29:13 music volumio[25792]: info: CoreCommandRouter::volumioPushState Jan 08 11:29:13 music volumio[25792]: info: CoreStateMachine::setRandom null Jan 08 11:29:13 music volumio[25792]: info: CoreStateMachine::pushState Jan 08 11:29:13 music volumio[25792]: info: CorePlayQueue::getTrack 0 Jan 08 11:29:13 music volumio[25792]: info: CoreCommandRouter::volumioPushState Jan 08 11:29:13 music volumio[25792]: info: Setting Device type: Raspberry PI Jan 08 11:29:13 music volumio[25792]: info: Listing playlists Jan 08 11:29:13 music volumio[25792]: info: Listing playlists Jan 08 11:29:13 music volumio[25792]: info: VolumeController:: Volume=86 Mute =false Jan 08 11:29:13 music volumio[25792]: info: CoreStateMachine::pushState Jan 08 11:29:13 music volumio[25792]: info: CorePlayQueue::getTrack 0 Jan 08 11:29:13 music volumio[25792]: info: CoreCommandRouter::volumioPushState Jan 08 11:29:13 music volumio[25792]: info: Completed loading Core Plugins Jan 08 11:29:13 music volumio[25792]: info: Preparing to generate the ALSA configuration file Jan 08 11:29:13 music volumio[25792]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Jan 08 11:29:13 music volumio[25792]: info: Discovery: Found device music Jan 08 11:29:13 music volumio[25792]: info: CoreCommandRouter::volumioGetState Jan 08 11:29:13 music volumio[25792]: info: CorePlayQueue::getTrack 0 Jan 08 11:29:13 music volumio[25792]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Jan 08 11:29:13 music volumio[25792]: info: Discovery: Found device music Jan 08 11:29:13 music volumio[25792]: info: CoreCommandRouter::volumioGetState Jan 08 11:29:13 music volumio[25792]: info: CorePlayQueue::getTrack 0 Jan 08 11:29:13 music volumio[25792]: info: Asound.conf file unchanged, so no further update is needed Jan 08 11:29:13 music volumio[25792]: info: Output device has changed, restarting MPD Jan 08 11:29:13 music volumio[25792]: info: Output device has changed, restarting Shairport Sync Jan 08 11:29:13 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:29:13 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 11:29:13 music sudo[25925]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 08 11:29:13 music sudo[25925]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:29:13 music volumio[25792]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 08 11:29:13 music sudo[25927]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 08 11:29:13 music sudo[25927]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:29:13 music volumio[25792]: info: ___________ START PLUGINS ___________ Jan 08 11:29:13 music sudo[25925]: pam_unix(sudo:session): session closed for user root Jan 08 11:29:14 music volumio[25792]: info: ControllerMpd::onStart: Initializing MPD Jan 08 11:29:14 music volumio[25792]: info: Creating MPD Configuration file Jan 08 11:29:14 music sudo[25935]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 08 11:29:14 music systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 08 11:29:14 music sudo[25935]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:29:14 music sudo[25935]: pam_unix(sudo:session): session closed for user root Jan 08 11:29:14 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 11:29:14 music volumio[25792]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 11:29:14 music volumio[25792]: info: [1767889754078] CoreMusicLibrary::Adding element Media Servers Jan 08 11:29:14 music sudo[25937]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 08 11:29:14 music sudo[25937]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:29:14 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 11:29:14 music systemd[1]: mpd.service: Deactivated successfully. Jan 08 11:29:14 music systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 08 11:29:14 music systemd[1]: mpd.service: Consumed 4.160s CPU time. Jan 08 11:29:14 music volumio[25792]: info: UPNP Browser: Client initialized successfully Jan 08 11:29:14 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:29:14 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 11:29:14 music systemd[1]: mpd.socket: Deactivated successfully. Jan 08 11:29:14 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 08 11:29:14 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 08 11:29:14 music volumio[25792]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 08 11:29:14 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:29:14 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 11:29:14 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 08 11:29:14 music systemd[1]: Starting mpd.service - Music Player Daemon... Jan 08 11:29:14 music systemd[1]: mpd.service: Deactivated successfully. Jan 08 11:29:14 music systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 08 11:29:14 music systemd[1]: mpd.socket: Deactivated successfully. Jan 08 11:29:14 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 08 11:29:14 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 08 11:29:14 music volumio[25792]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 08 11:29:14 music volumio[25792]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 11:29:14 music volumio[25792]: info: [1767889754280] CoreMusicLibrary::Adding element Last_100 Jan 08 11:29:14 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 11:29:14 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 08 11:29:14 music volumio[25792]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 11:29:14 music volumio[25792]: info: [1767889754293] CoreMusicLibrary::Adding element Webradio Jan 08 11:29:14 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 11:29:14 music systemd[1]: Starting mpd.service - Music Player Daemon... Jan 08 11:29:14 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 08 11:29:14 music volumio[25792]: info: Initializing BBC Radios Jan 08 11:29:14 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 08 11:29:14 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 11:29:14 music volumio[25792]: info: Creating Spotify config file Jan 08 11:29:14 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:29:14 music sudo[25951]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 08 11:29:14 music sudo[25951]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 08 11:29:14 music sudo[25951]: pam_unix(sudo:session): session closed for user root Jan 08 11:29:14 music volumio[25792]: info: Volumio Calling Home Jan 08 11:29:15 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 08 11:29:15 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 08 11:29:15 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 08 11:29:15 music go-librespot[25970]: go-librespot daemon starting... Jan 08 11:29:15 music go-librespot[25971]: time="2026-01-08T11:29:15-05:00" level=info msg="running go-librespot 0.6.2" Jan 08 11:29:15 music volumio[25886]: Starting albumart workers Jan 08 11:29:15 music volumio[25885]: Starting albumart workers Jan 08 11:29:15 music go-librespot[25971]: time="2026-01-08T11:29:15-05:00" level=info msg="zeroconf server listening on port 34229" Jan 08 11:29:15 music volumio[25884]: Starting albumart workers Jan 08 11:29:15 music volumio[25792]: info: MPD Permissions set Jan 08 11:29:15 music volumio[25792]: info: MPD Permissions set Jan 08 11:29:15 music volumio[25792]: info: Volumio called home Jan 08 11:29:15 music volumio[25792]: info: Spotify config file written Jan 08 11:29:15 music volumio[25792]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 08 11:29:15 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:29:15 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:29:15 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:29:15 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:29:15 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:29:15 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:29:15 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:29:15 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:29:15 music sudo[25981]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 08 11:29:15 music sudo[25981]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:29:15 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 11:29:15 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 08 11:29:15 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 08 11:29:15 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 08 11:29:15 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:29:15 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:29:15 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:29:15 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:29:15 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:29:15 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:29:15 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:29:15 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:29:15 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:29:15 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 08 11:29:15 music go-librespot[25988]: go-librespot daemon starting... Jan 08 11:29:15 music sudo[25981]: pam_unix(sudo:session): session closed for user root Jan 08 11:29:16 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 11:29:16 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 11:29:16 music go-librespot[25994]: time="2026-01-08T11:29:16-05:00" level=info msg="running go-librespot 0.6.2" Jan 08 11:29:16 music go-librespot[25994]: time="2026-01-08T11:29:16-05:00" level=debug msg="app state loaded" Jan 08 11:29:16 music volumio[25792]: info: No need to fix Spotify hosts Jan 08 11:29:16 music go-librespot[25994]: time="2026-01-08T11:29:16-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 08 11:29:16 music go-librespot[25994]: time="2026-01-08T11:29:16-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]" Jan 08 11:29:16 music go-librespot[25994]: time="2026-01-08T11:29:16-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]" Jan 08 11:29:16 music go-librespot[25994]: time="2026-01-08T11:29:16-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]" Jan 08 11:29:16 music go-librespot[25994]: time="2026-01-08T11:29:16-05:00" level=info msg="zeroconf server listening on port 41965" Jan 08 11:29:16 music go-librespot[25994]: time="2026-01-08T11:29:16-05:00" level=debug msg="obtained new client token: AADYa0WFYDRYt38ROluQRkpZg0iZBxUM4ILHi4R8Ws/2wN9SzStilmwRs0DsR0Qsfw7E1XtVVc3BZpFZh9zUnZlFnnzCNJtiqOIG6CxPeGF8XFFbtO0GxadU8lRRmH/rZk8ldYQxz3qYZCMUwbzScWR4T3hPLBoOAeLy4jdICeKeOtW5ghfbMZAYddXSgtc3eUJc+f4IMvti/B3aZ85PdbS3rHLspOgPMmXIVhN6gJLIF/9LwBvUzXI=" Jan 08 11:29:16 music volumio[25792]: info: Starting Shairport Sync Jan 08 11:29:16 music volumio[25792]: info: Starting Shairport Sync Jan 08 11:29:16 music go-librespot[25994]: time="2026-01-08T11:29:16-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 08 11:29:16 music volumio[25792]: info: Starting Shairport Sync Jan 08 11:29:16 music sudo[26010]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 08 11:29:16 music sudo[26010]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:29:16 music sudo[26012]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 08 11:29:16 music sudo[26012]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:29:16 music go-librespot[25994]: time="2026-01-08T11:29:16-05:00" level=debug msg="completed keyexchange" Jan 08 11:29:16 music go-librespot[25994]: time="2026-01-08T11:29:16-05:00" level=debug msg="completed challenge" Jan 08 11:29:16 music volumio[25792]: info: An error occurred while refreshing Spotify Token Error: Bad Request Jan 08 11:29:16 music sudo[26018]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 08 11:29:16 music sudo[26018]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:29:16 music go-librespot[25994]: time="2026-01-08T11:29:16-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:29:16 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 08 11:29:16 music systemd[1]: shairport-sync.service: Deactivated successfully. Jan 08 11:29:16 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 08 11:29:16 music systemd[1]: shairport-sync.service: Consumed 1.898s CPU time. Jan 08 11:29:17 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 08 11:29:17 music volumio[25792]: info: CoreCommandRouter::volumioGetState Jan 08 11:29:17 music volumio[25792]: info: CorePlayQueue::getTrack 0 Jan 08 11:29:17 music sudo[26010]: pam_unix(sudo:session): session closed for user root Jan 08 11:29:17 music sudo[26012]: pam_unix(sudo:session): session closed for user root Jan 08 11:29:17 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 08 11:29:17 music systemd[1]: shairport-sync.service: Deactivated successfully. Jan 08 11:29:17 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 08 11:29:17 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 08 11:29:17 music volumio[25792]: info: Shairport-Sync Started Jan 08 11:29:17 music volumio[25792]: Error adding Membership: Error: addMembership EINVAL Jan 08 11:29:17 music volumio[25792]: info: Shairport-Sync Started Jan 08 11:29:17 music sudo[26018]: pam_unix(sudo:session): session closed for user root Jan 08 11:29:17 music volumio[25792]: info: Shairport-Sync Started Jan 08 11:29:17 music go-librespot[25994]: time="2026-01-08T11:29:17-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 08 11:29:17 music go-librespot[25994]: time="2026-01-08T11:29:17-05:00" level=debug msg="completed keyexchange" Jan 08 11:29:17 music go-librespot[25994]: time="2026-01-08T11:29:17-05:00" level=debug msg="completed challenge" Jan 08 11:29:17 music go-librespot[25994]: time="2026-01-08T11:29:17-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:29:18 music go-librespot[25994]: time="2026-01-08T11:29:18-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Jan 08 11:29:18 music go-librespot[25994]: time="2026-01-08T11:29:18-05:00" level=debug msg="completed keyexchange" Jan 08 11:29:18 music go-librespot[25994]: time="2026-01-08T11:29:18-05:00" level=debug msg="completed challenge" Jan 08 11:29:18 music go-librespot[25994]: time="2026-01-08T11:29:18-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:29:18 music mpd[25966]: 2026-01-08T11:29:18 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 08 11:29:18 music systemd[1]: Started mpd.service - Music Player Daemon. Jan 08 11:29:18 music sudo[25927]: pam_unix(sudo:session): session closed for user root Jan 08 11:29:18 music sudo[25937]: pam_unix(sudo:session): session closed for user root Jan 08 11:29:18 music volumio[25792]: info: Completed starting Core Plugins Jan 08 11:29:18 music volumio[25792]: info: ------------------------------------------- Jan 08 11:29:18 music volumio[25792]: info: ----- MyVolumio plugins startup ---- Jan 08 11:29:18 music volumio[25792]: info: ------------------------------------------- Jan 08 11:29:18 music volumio[25792]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 08 11:29:18 music volumio[25792]: error: MPD error: The expression evaluated to a falsy value: Jan 08 11:29:18 music volumio[25792]: assert.ok(self.idling) Jan 08 11:29:18 music volumio[25792]: error: The expression evaluated to a falsy value: Jan 08 11:29:18 music volumio[25792]: assert.ok(self.idling) Jan 08 11:29:18 music volumio[25792]: info: MPD running with PID25966 Jan 08 11:29:18 music volumio[25792]: ,establishing connection Jan 08 11:29:18 music volumio[25792]: error: updateQueue error: null Jan 08 11:29:18 music volumio[25792]: error: updateQueue error: null Jan 08 11:29:18 music go-librespot[25994]: time="2026-01-08T11:29:18-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 08 11:29:18 music go-librespot[25994]: time="2026-01-08T11:29:18-05:00" level=debug msg="completed keyexchange" Jan 08 11:29:18 music go-librespot[25994]: time="2026-01-08T11:29:18-05:00" level=debug msg="completed challenge" Jan 08 11:29:18 music go-librespot[25994]: time="2026-01-08T11:29:18-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:29:19 music sudo[26067]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 08 11:29:19 music sudo[26067]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:29:19 music sudo[26067]: pam_unix(sudo:session): session closed for user root Jan 08 11:29:19 music sudo[26069]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 08 11:29:19 music sudo[26069]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:29:19 music sudo[26069]: pam_unix(sudo:session): session closed for user root Jan 08 11:29:19 music sudo[26072]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 08 11:29:19 music volumio[25792]: info: CoreCommandRouter::volumioGetState Jan 08 11:29:19 music volumio[25792]: info: CorePlayQueue::getTrack 0 Jan 08 11:29:19 music sudo[26072]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:29:19 music sudo[26072]: pam_unix(sudo:session): session closed for user root Jan 08 11:29:19 music volumio[25792]: info: Upmpdcli Daemon Started Jan 08 11:29:19 music go-librespot[25994]: time="2026-01-08T11:29:19-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 08 11:29:19 music volumio[25792]: info: go-librespot daemon successfully initialized Jan 08 11:29:19 music go-librespot[25994]: time="2026-01-08T11:29:19-05:00" level=debug msg="completed keyexchange" Jan 08 11:29:19 music go-librespot[25994]: time="2026-01-08T11:29:19-05:00" level=debug msg="completed challenge" Jan 08 11:29:20 music go-librespot[25994]: time="2026-01-08T11:29:20-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:29:20 music go-librespot[25994]: time="2026-01-08T11:29:20-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Jan 08 11:29:21 music go-librespot[25994]: time="2026-01-08T11:29:21-05:00" level=debug msg="completed keyexchange" Jan 08 11:29:21 music go-librespot[25994]: time="2026-01-08T11:29:21-05:00" level=debug msg="completed challenge" Jan 08 11:29:21 music go-librespot[25994]: time="2026-01-08T11:29:21-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:29:21 music go-librespot[25994]: time="2026-01-08T11:29:21-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 " Jan 08 11:29:21 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 08 11:29:21 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 08 11:29:21 music sudo[26079]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 08 11:29:21 music sudo[26079]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:29:21 music sudo[26081]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 08 11:29:21 music sudo[26081]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:29:21 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Jan 08 11:29:21 music systemd[1]: mpd_monitor.service: Deactivated successfully. Jan 08 11:29:21 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Jan 08 11:29:21 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Jan 08 11:29:21 music sudo[26081]: pam_unix(sudo:session): session closed for user root Jan 08 11:29:21 music mpd_monitor.sh[26084]: MPD Monitor Service: Starting MPD Monitor Service Jan 08 11:29:21 music sudo[26079]: pam_unix(sudo:session): session closed for user root Jan 08 11:29:21 music volumio[25792]: info: Successfully started MPD Monitor Jan 08 11:29:21 music volumio[25792]: info: Successfully started MPD Monitor Jan 08 11:29:22 music volumio[25792]: info: Initializing connection to go-librespot Websocket Jan 08 11:29:22 music volumio[25792]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 08 11:29:23 music volumio[25792]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 08 11:29:24 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 08 11:29:24 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 08 11:29:24 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 08 11:29:24 music go-librespot[26090]: go-librespot daemon starting... Jan 08 11:29:24 music go-librespot[26091]: time="2026-01-08T11:29:24-05:00" level=info msg="running go-librespot 0.6.2" Jan 08 11:29:24 music go-librespot[26091]: time="2026-01-08T11:29:24-05:00" level=debug msg="app state loaded" Jan 08 11:29:24 music go-librespot[26091]: time="2026-01-08T11:29:24-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 08 11:29:24 music go-librespot[26091]: time="2026-01-08T11:29:24-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]" Jan 08 11:29:24 music go-librespot[26091]: time="2026-01-08T11:29:24-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]" Jan 08 11:29:24 music go-librespot[26091]: time="2026-01-08T11:29:24-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]" Jan 08 11:29:24 music go-librespot[26091]: time="2026-01-08T11:29:24-05:00" level=info msg="zeroconf server listening on port 38707" Jan 08 11:29:24 music go-librespot[26091]: time="2026-01-08T11:29:24-05:00" level=debug msg="obtained new client token: AAALUt6p/ugs6lQnD6xqyWuUA4X15R4COAX3TMwNp/UHMIWVNF/H8o/y8qROywJqbFzzIi3D5kfIdO7wBJEAT5/aLZCi7bg9icss3RxVf8MNOqrPW2gBKXNiMldG3vG7AqJntvr8Ra/GgSOHjE0desMTs3RKKK11dY9tCb8fdGuZGwYKqFWb3QRxeKdXeD/IIlfOjR6W/SNI9dhzALaJAnGZsZbMLQ0Mo75uxSKv6jEoK32m1wnRn14=" Jan 08 11:29:24 music go-librespot[26091]: time="2026-01-08T11:29:24-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 08 11:29:24 music go-librespot[26091]: time="2026-01-08T11:29:24-05:00" level=debug msg="completed keyexchange" Jan 08 11:29:24 music go-librespot[26091]: time="2026-01-08T11:29:24-05:00" level=debug msg="completed challenge" Jan 08 11:29:25 music go-librespot[26091]: time="2026-01-08T11:29:25-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:29:25 music go-librespot[26091]: time="2026-01-08T11:29:25-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 08 11:29:25 music go-librespot[26091]: time="2026-01-08T11:29:25-05:00" level=debug msg="completed keyexchange" Jan 08 11:29:25 music go-librespot[26091]: time="2026-01-08T11:29:25-05:00" level=debug msg="completed challenge" Jan 08 11:29:25 music go-librespot[26091]: time="2026-01-08T11:29:25-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:29:25 music volumio[25792]: info: Initializing connection to go-librespot Websocket Jan 08 11:29:25 music go-librespot[26091]: time="2026-01-08T11:29:25-05:00" level=debug msg="new websocket client" Jan 08 11:29:25 music volumio[25792]: info: Connection to go-librespot Websocket established Jan 08 11:29:26 music go-librespot[26091]: time="2026-01-08T11:29:26-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Jan 08 11:29:26 music go-librespot[26091]: time="2026-01-08T11:29:26-05:00" level=debug msg="completed keyexchange" Jan 08 11:29:26 music go-librespot[26091]: time="2026-01-08T11:29:26-05:00" level=debug msg="completed challenge" Jan 08 11:29:26 music go-librespot[26091]: time="2026-01-08T11:29:26-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:29:26 music volumio[25792]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 08 11:29:26 music volumio[25792]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 08 11:29:26 music volumio[25792]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 08 11:29:26 music volumio[25792]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 08 11:29:26 music volumio[25792]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 08 11:29:26 music volumio[25792]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 08 11:29:26 music volumio[25792]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 08 11:29:26 music volumio[25792]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 08 11:29:26 music volumio[25792]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 08 11:29:26 music volumio[25792]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 08 11:29:26 music volumio[25792]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 08 11:29:26 music volumio[25792]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 08 11:29:26 music volumio[25792]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 08 11:29:26 music volumio[25792]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 08 11:29:26 music volumio[25792]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 08 11:29:26 music volumio[25792]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 08 11:29:26 music volumio[25792]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 08 11:29:26 music volumio[25792]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 08 11:29:26 music volumio[25792]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 08 11:29:26 music volumio[25792]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 08 11:29:26 music volumio[25792]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 08 11:29:26 music volumio[25792]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 08 11:29:26 music volumio[25792]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 08 11:29:26 music volumio[25792]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 08 11:29:26 music volumio[25792]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 08 11:29:26 music volumio[25792]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 08 11:29:26 music volumio[25792]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 08 11:29:26 music volumio[25792]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 08 11:29:26 music volumio[25792]: info: Adding plugin bluetooth to MyMusic Plugins Jan 08 11:29:26 music volumio[25792]: info: Adding plugin multiroom to MyMusic Plugins Jan 08 11:29:26 music volumio[25792]: info: Adding plugin metavolumio to MyMusic Plugins Jan 08 11:29:26 music volumio[25792]: info: Adding plugin cd_controller to MyMusic Plugins Jan 08 11:29:26 music volumio[25792]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 08 11:29:26 music volumio[25792]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 08 11:29:26 music volumio[25792]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 08 11:29:26 music volumio[25792]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 08 11:29:26 music go-librespot[26091]: time="2026-01-08T11:29:26-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 08 11:29:26 music go-librespot[26091]: time="2026-01-08T11:29:26-05:00" level=debug msg="completed keyexchange" Jan 08 11:29:26 music go-librespot[26091]: time="2026-01-08T11:29:26-05:00" level=debug msg="completed challenge" Jan 08 11:29:27 music go-librespot[26091]: time="2026-01-08T11:29:27-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:29:27 music go-librespot[26091]: time="2026-01-08T11:29:27-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Jan 08 11:29:27 music go-librespot[26091]: time="2026-01-08T11:29:27-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 08 11:29:28 music volumio[25792]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 08 11:29:28 music volumio[25792]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 08 11:29:28 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 11:29:28 music volumio[25792]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 11:29:28 music volumio[25792]: info: Starting MyVolumio Remote Streaming Endpoints Jan 08 11:29:28 music volumio[25792]: info: MyVolumio login type: Token Jan 08 11:29:28 music volumio[25792]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 08 11:29:28 music volumio[25792]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 08 11:29:28 music go-librespot[26091]: time="2026-01-08T11:29:28-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Jan 08 11:29:28 music go-librespot[26091]: time="2026-01-08T11:29:28-05:00" level=debug msg="completed keyexchange" Jan 08 11:29:28 music go-librespot[26091]: time="2026-01-08T11:29:28-05:00" level=debug msg="completed challenge" Jan 08 11:29:28 music go-librespot[26091]: time="2026-01-08T11:29:28-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 08 11:29:28 music go-librespot[26091]: time="2026-01-08T11:29:28-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 " Jan 08 11:29:28 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 08 11:29:28 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 08 11:29:28 music volumio[25792]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 08 11:29:28 music volumio[25792]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 08 11:29:28 music volumio[25792]: info: Streaming services startup Jan 08 11:29:28 music volumio[25792]: info: Starting Streaming Daemon Jan 08 11:29:29 music sudo[26101]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 08 11:29:29 music sudo[26101]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 11:29:29 music volumio[25792]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 08 11:29:29 music sudo[26101]: pam_unix(sudo:session): session closed for user root Jan 08 11:29:29 music volumio[25792]: info: Getting Spotify volume Jan 08 11:29:29 music volumio[25792]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 08 11:29:29 music volumio[25792]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 08 11:29:29 music volumio[25792]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 08 11:29:29 music volumio[25792]: errno: -111, Jan 08 11:29:29 music volumio[25792]: code: 'ECONNREFUSED', Jan 08 11:29:29 music volumio[25792]: syscall: 'connect', Jan 08 11:29:29 music volumio[25792]: address: '127.0.0.1', Jan 08 11:29:29 music volumio[25792]: port: 9879, Jan 08 11:29:29 music volumio[25792]: response: undefined Jan 08 11:29:29 music volumio[25792]: } Jan 08 11:29:29 music volumio[25792]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 08 11:29:29 music sudo[26135]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-08 11:28' Jan 08 11:29:29 music sudo[26135]: 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"