Feb 06 13:52:00 music go-librespot[12964]: time="2026-02-06T13:52:00-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 06 13:52:00 music go-librespot[12964]: time="2026-02-06T13:52:00-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:00 music go-librespot[12964]: time="2026-02-06T13:52:00-05:00" level=debug msg="completed challenge" Feb 06 13:52:00 music go-librespot[12964]: time="2026-02-06T13:52:00-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:00 music go-librespot[12964]: time="2026-02-06T13:52:00-05:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 06 13:52:01 music volumio[12675]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 06 13:52:01 music volumio[12675]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 06 13:52:01 music volumio[12675]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 06 13:52:01 music volumio[12675]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 06 13:52:01 music volumio[12675]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 06 13:52:01 music volumio[12675]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 06 13:52:01 music volumio[12675]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 06 13:52:01 music volumio[12675]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 06 13:52:01 music volumio[12675]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 06 13:52:01 music volumio[12675]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 06 13:52:01 music volumio[12675]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 06 13:52:01 music volumio[12675]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 06 13:52:01 music volumio[12675]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 06 13:52:01 music volumio[12675]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 06 13:52:01 music volumio[12675]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 06 13:52:01 music volumio[12675]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 06 13:52:01 music volumio[12675]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 06 13:52:01 music volumio[12675]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 06 13:52:01 music volumio[12675]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 06 13:52:01 music volumio[12675]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 06 13:52:01 music volumio[12675]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 06 13:52:01 music volumio[12675]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 06 13:52:01 music volumio[12675]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 06 13:52:01 music volumio[12675]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 06 13:52:01 music volumio[12675]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 06 13:52:01 music volumio[12675]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 06 13:52:01 music volumio[12675]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 06 13:52:01 music volumio[12675]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 06 13:52:01 music volumio[12675]: info: Adding plugin bluetooth to MyMusic Plugins Feb 06 13:52:01 music volumio[12675]: info: Adding plugin multiroom to MyMusic Plugins Feb 06 13:52:01 music volumio[12675]: info: Adding plugin metavolumio to MyMusic Plugins Feb 06 13:52:01 music volumio[12675]: info: Adding plugin cd_controller to MyMusic Plugins Feb 06 13:52:01 music volumio[12675]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 06 13:52:01 music volumio[12675]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 06 13:52:01 music volumio[12675]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 06 13:52:01 music volumio[12675]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 06 13:52:01 music go-librespot[12964]: time="2026-02-06T13:52:01-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:01 music go-librespot[12964]: time="2026-02-06T13:52:01-05:00" level=debug msg="completed challenge" Feb 06 13:52:01 music go-librespot[12964]: time="2026-02-06T13:52:01-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:02 music go-librespot[12964]: time="2026-02-06T13:52:02-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 06 13:52:02 music volumio[12675]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 06 13:52:02 music volumio[12675]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 06 13:52:02 music volumio[12675]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:52:02 music volumio[12675]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:52:02 music volumio[12675]: info: Starting MyVolumio Remote Streaming Endpoints Feb 06 13:52:02 music volumio[12675]: info: MyVolumio login type: Token Feb 06 13:52:02 music volumio[12675]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 06 13:52:02 music volumio[12675]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 06 13:52:02 music go-librespot[12964]: time="2026-02-06T13:52: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:49590->104.199.65.9:443: read: connection reset by peer" Feb 06 13:52:02 music go-librespot[12964]: time="2026-02-06T13:52:02-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 06 13:52:03 music volumio[12675]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 06 13:52:03 music volumio[12675]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 06 13:52:03 music volumio[12675]: info: Streaming services startup Feb 06 13:52:03 music volumio[12675]: info: Starting Streaming Daemon Feb 06 13:52:03 music go-librespot[12964]: time="2026-02-06T13:52:03-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:03 music go-librespot[12964]: time="2026-02-06T13:52:03-05:00" level=debug msg="completed challenge" Feb 06 13:52:03 music sudo[12974]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 06 13:52:03 music sudo[12974]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:03 music volumio[12675]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 06 13:52:03 music sudo[12974]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:03 music volumio[12675]: info: Getting Spotify volume Feb 06 13:52:03 music go-librespot[12964]: time="2026-02-06T13:52:03-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:03 music go-librespot[12964]: time="2026-02-06T13:52: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 " Feb 06 13:52:03 music volumio[12675]: error: Cannot start Volumio Streaming Daemon Feb 06 13:52:03 music volumio[12675]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 06 13:52:03 music volumio[12675]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 06 13:52:03 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 06 13:52:03 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 06 13:52:03 music volumio[12675]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 06 13:52:03 music volumio[12675]: Error: read ECONNRESET Feb 06 13:52:03 music volumio[12675]: at TCP.onStreamRead (node:internal/stream_base_commons:217:20) { Feb 06 13:52:03 music volumio[12675]: errno: -104, Feb 06 13:52:03 music volumio[12675]: code: 'ECONNRESET', Feb 06 13:52:03 music volumio[12675]: syscall: 'read', Feb 06 13:52:03 music volumio[12675]: response: undefined Feb 06 13:52:03 music volumio[12675]: } Feb 06 13:52:03 music volumio[12675]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 06 13:52:04 music sudo[13009]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-06 13:51' Feb 06 13:52:04 music sudo[13009]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:04 music sudo[13009]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:05 music volumio-remote-updater[31331]: [2026-02-06 13:52:05] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 06 13:52:05 music volumio-remote-updater[31331]: [2026-02-06 13:52:05] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 06 13:52:05 music systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 06 13:52:05 music systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 06 13:52:05 music systemd[1]: volumio.service: Consumed 26.663s CPU time. Feb 06 13:52:05 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 06 13:52:05 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 06 13:52:05 music systemd[1]: volumio.service: Scheduled restart job, restart counter is at 48075. Feb 06 13:52:05 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 06 13:52:05 music systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 06 13:52:05 music systemd[1]: volumio.service: Consumed 26.663s CPU time. Feb 06 13:52:05 music systemd[1]: Started volumio.service - Volumio Backend Module. Feb 06 13:52:05 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 06 13:52:06 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 06 13:52:06 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 06 13:52:06 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 06 13:52:06 music go-librespot[13044]: go-librespot daemon starting... Feb 06 13:52:06 music go-librespot[13045]: time="2026-02-06T13:52:06-05:00" level=info msg="running go-librespot 0.6.2" Feb 06 13:52:06 music go-librespot[13045]: time="2026-02-06T13:52:06-05:00" level=debug msg="app state loaded" Feb 06 13:52:06 music go-librespot[13045]: time="2026-02-06T13:52:06-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 06 13:52:06 music go-librespot[13045]: time="2026-02-06T13:52: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-gew4.spotify.com:80]" Feb 06 13:52:06 music go-librespot[13045]: time="2026-02-06T13:52:06-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 06 13:52:06 music go-librespot[13045]: time="2026-02-06T13:52:06-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 06 13:52:07 music go-librespot[13045]: time="2026-02-06T13:52:07-05:00" level=info msg="zeroconf server listening on port 40117" Feb 06 13:52:07 music go-librespot[13045]: time="2026-02-06T13:52:07-05:00" level=debug msg="obtained new client token: AAAirQ88WdLblbcs6eq5Sy6vcSzhqrAgsypFMG01nhCXoH4DjLPZ1v66j1HMU8W0QUVRrlgp679C5uIpY/yfRvmEclOFyrUgOx+0pzQ9Dl5+0CHmmFsWDQdp6UY8L3TS8zraYJN2HX8zwmIKEdoQjV22qwO/mq6ajDXZpWfOf+kUiapsKUolEm6y6UBpiKn2GVdPXucbvq3D9FS5gHdEOsC9O5v/mNOo0agduOdmuVGtU2fmBSEg" Feb 06 13:52:07 music go-librespot[13045]: time="2026-02-06T13:52:07-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 06 13:52:07 music go-librespot[13045]: time="2026-02-06T13:52:07-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:07 music go-librespot[13045]: time="2026-02-06T13:52:07-05:00" level=debug msg="completed challenge" Feb 06 13:52:07 music go-librespot[13045]: time="2026-02-06T13:52:07-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:07 music volumio[13029]: info: ------------------------------------------- Feb 06 13:52:07 music volumio[13029]: info: ----- Volumio3 ---- Feb 06 13:52:07 music volumio[13029]: info: ------------------------------------------- Feb 06 13:52:07 music volumio[13029]: info: ----- System startup ---- Feb 06 13:52:07 music volumio[13029]: info: ------------------------------------------- Feb 06 13:52:07 music go-librespot[13045]: time="2026-02-06T13:52:07-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 06 13:52:08 music go-librespot[13045]: time="2026-02-06T13:52:08-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:08 music go-librespot[13045]: time="2026-02-06T13:52:08-05:00" level=debug msg="completed challenge" Feb 06 13:52:08 music go-librespot[13045]: time="2026-02-06T13:52:08-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:08 music volumio[13029]: info: MYVOLUMIO Environment detected Feb 06 13:52:08 music volumio[13029]: info: Plugin folders cleanup Feb 06 13:52:08 music volumio[13029]: info: Scanning into folder /volumio/app/plugins/ Feb 06 13:52:08 music volumio[13029]: info: Scanning category audio_interface Feb 06 13:52:08 music volumio[13029]: info: Scanning category miscellanea Feb 06 13:52:08 music volumio[13029]: info: Scanning category music_service Feb 06 13:52:08 music volumio[13029]: info: Scanning category plugins.json Feb 06 13:52:08 music volumio[13029]: info: Scanning category system_controller Feb 06 13:52:08 music volumio[13029]: info: Scanning category user_interface Feb 06 13:52:08 music volumio[13029]: info: Scanning into folder /data/plugins/ Feb 06 13:52:08 music volumio[13029]: info: Scanning category music_service Feb 06 13:52:08 music volumio[13029]: info: Plugin folders cleanup completed Feb 06 13:52:08 music volumio[13029]: info: ------------------------------------------- Feb 06 13:52:08 music volumio[13029]: info: ----- Core plugins startup ---- Feb 06 13:52:08 music volumio[13029]: info: ------------------------------------------- Feb 06 13:52:08 music volumio[13029]: info: Loading plugins from folder /volumio/app/plugins/ Feb 06 13:52:08 music volumio[13029]: info: Adding plugin upnp to MyMusic Plugins Feb 06 13:52:08 music volumio[13029]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 06 13:52:08 music volumio[13029]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 06 13:52:08 music volumio[13029]: info: Loading plugins from folder /data/plugins/ Feb 06 13:52:08 music volumio[13029]: info: Loading plugin "system"... Feb 06 13:52:08 music volumio[13029]: info: Loading plugin "appearance"... Feb 06 13:52:08 music go-librespot[13045]: time="2026-02-06T13:52:08-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 06 13:52:08 music go-librespot[13045]: time="2026-02-06T13:52:08-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:08 music go-librespot[13045]: time="2026-02-06T13:52:08-05:00" level=debug msg="completed challenge" Feb 06 13:52:08 music go-librespot[13045]: time="2026-02-06T13:52:08-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:09 music go-librespot[13045]: time="2026-02-06T13:52:09-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 06 13:52:09 music volumio[13029]: info: Loading plugin "network"... Feb 06 13:52:09 music volumio[13029]: info: Refreshing Cached IP Addresses Feb 06 13:52:09 music sudo[13067]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 06 13:52:09 music sudo[13067]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:09 music sudo[13069]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 06 13:52:09 music sudo[13069]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:09 music sudo[13069]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:09 music volumio[13029]: info: Loading plugin "services"... Feb 06 13:52:09 music sudo[13067]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:09 music volumio[13029]: info: Loading plugin "alsa_controller"... Feb 06 13:52:09 music sudo[13077]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 06 13:52:09 music sudo[13077]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:09 music go-librespot[13045]: time="2026-02-06T13:52:09-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:09 music go-librespot[13045]: time="2026-02-06T13:52:09-05:00" level=debug msg="completed challenge" Feb 06 13:52:09 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 06 13:52:09 music volumio[13029]: info: Loading plugin "wizard"... Feb 06 13:52:09 music go-librespot[13045]: time="2026-02-06T13:52:09-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:09 music volumio[13029]: info: Loading plugin "networkfs"... Feb 06 13:52:09 music volumio[13029]: info: Starting Udev Watcher for removable devices Feb 06 13:52:09 music volumio[13029]: info: Ignoring mount for partition: boot Feb 06 13:52:09 music volumio[13029]: info: Ignoring mount for partition: volumio Feb 06 13:52:09 music volumio[13029]: info: Ignoring mount for partition: volumio_data Feb 06 13:52:09 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 06 13:52:09 music volumio[13029]: info: Loading plugin "volumio_command_line_client"... Feb 06 13:52:09 music volumio[13029]: info: Loading plugin "upnp"... Feb 06 13:52:09 music volumio[13029]: info: [1770403929652] Starting Upmpd Daemon Feb 06 13:52:09 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 06 13:52:09 music volumio[13029]: info: Loading plugin "my_music"... Feb 06 13:52:09 music volumio[13029]: info: Loading plugin "mpd"... Feb 06 13:52:10 music volumio[13029]: info: Loading plugin "upnp_browser"... Feb 06 13:52:10 music volumio-remote-updater[31331]: [2026-02-06 13:52:10] [connect] Successful connection Feb 06 13:52:10 music sudo[13077]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:10 music go-librespot[13045]: time="2026-02-06T13:52:10-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 06 13:52:10 music go-librespot[13045]: time="2026-02-06T13:52:10-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:10 music go-librespot[13045]: time="2026-02-06T13:52:10-05:00" level=debug msg="completed challenge" Feb 06 13:52:10 music go-librespot[13045]: time="2026-02-06T13:52:10-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:11 music go-librespot[13045]: time="2026-02-06T13:52:11-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 06 13:52:11 music volumio[13029]: info: Starting UPNP Browser Feb 06 13:52:11 music volumio[13029]: info: Loading plugin "alarm-clock"... Feb 06 13:52:11 music go-librespot[13045]: time="2026-02-06T13:52:11-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:11 music go-librespot[13045]: time="2026-02-06T13:52:11-05:00" level=debug msg="completed challenge" Feb 06 13:52:11 music volumio[13029]: info: Loading plugin "airplay_emulation"... Feb 06 13:52:11 music volumio[13029]: info: Starting Shairport Sync Feb 06 13:52:11 music volumio[13029]: info: Loading plugin "last_100"... Feb 06 13:52:11 music go-librespot[13045]: time="2026-02-06T13:52:11-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:11 music go-librespot[13045]: time="2026-02-06T13:52: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 " Feb 06 13:52:11 music volumio[13029]: info: Loading plugin "webradio"... Feb 06 13:52:11 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 06 13:52:11 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 06 13:52:11 music volumio[13029]: info: Loading plugin "i2s_dacs"... Feb 06 13:52:11 music volumio[13029]: info: I2S DAC not set, start Auto-detection Feb 06 13:52:11 music volumio[13029]: info: Loading plugin "volumiodiscovery"... Feb 06 13:52:11 music volumio[13029]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 06 13:52:11 music volumio[13029]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 06 13:52:11 music node[13029]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 06 13:52:11 music volumio[13029]: *** WARNING *** For more information see Feb 06 13:52:11 music volumio[13029]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 06 13:52:11 music volumio[13029]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 06 13:52:11 music volumio[13029]: *** WARNING *** For more information see Feb 06 13:52:11 music volumio[13029]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 06 13:52:11 music node[13029]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 06 13:52:11 music node[13029]: *** WARNING *** For more information see Feb 06 13:52:11 music node[13029]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 06 13:52:11 music node[13029]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 06 13:52:11 music node[13029]: *** WARNING *** For more information see Feb 06 13:52:11 music volumio[13029]: info: Discovery: Started advertising with name: music Feb 06 13:52:11 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 06 13:52:11 music volumio[13029]: info: Loading plugin "spop"... Feb 06 13:52:13 music volumio[13029]: info: Loading plugin "outputs"... Feb 06 13:52:13 music volumio[13029]: info: Loading plugin "albumart"... Feb 06 13:52:13 music volumio[13029]: info: Plugin example_plugin is not enabled Feb 06 13:52:13 music volumio[13029]: info: Loading plugin "inputs"... Feb 06 13:52:13 music volumio[13029]: info: Loading plugin "updater_comm"... Feb 06 13:52:13 music volumio[13029]: info: Plugin mpdemulation is not enabled Feb 06 13:52:13 music volumio[13029]: info: Loading plugin "rest_api"... Feb 06 13:52:13 music volumio[13029]: info: Loading plugin "websocket"... Feb 06 13:52:13 music volumio[13029]: info: Starting Socket.io Server version 1.7.4 Feb 06 13:52:13 music volumio[13029]: info: Loading i18n strings for locale en Feb 06 13:52:13 music volumio[13029]: Updating browse sources language Feb 06 13:52:13 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 06 13:52:13 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 06 13:52:13 music volumio[13029]: info: CoreCommandRouter::initPlayerControls Feb 06 13:52:13 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:13 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:13 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:13 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:13 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:13 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:13 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:13 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:13 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 06 13:52:13 music volumio[13029]: Express server listening on port 3000 Feb 06 13:52:13 music volumio[13029]: [Metrics] WebUI: 6s 576.37ms Feb 06 13:52:13 music volumio[13029]: info: CoreStateMachine::resetVolumioState Feb 06 13:52:13 music volumio[13029]: info: CoreStateMachine::getcurrentVolume Feb 06 13:52:13 music volumio[13029]: info: CoreCommandRouter::volumioRetrievevolume Feb 06 13:52:13 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:52:13 music volumio[13029]: info: Volumio Network Manager: Network status updated: 1 Feb 06 13:52:13 music volumio-remote-updater[31331]: [2026-02-06 13:52:13] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770403930 101 Feb 06 13:52:13 music volumio[13029]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 06 13:52:13 music volumio[13102]: Forking 3 albumart workers Feb 06 13:52:13 music volumio[13029]: info: VolumeController:: Volume=86 Mute =false Feb 06 13:52:13 music volumio[13029]: info: CoreStateMachine::pushState Feb 06 13:52:13 music volumio[13029]: info: CorePlayQueue::getTrack 0 Feb 06 13:52:13 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 06 13:52:13 music volumio[13029]: info: CoreCommandRouter::volumioPushState Feb 06 13:52:13 music volumio[13029]: info: CoreStateMachine::updateTrackBlock Feb 06 13:52:13 music volumio[13029]: info: CorePlayQueue::getTrackBlock Feb 06 13:52:13 music volumio[13029]: info: CoreCommandRouter::volumioRetrievevolume Feb 06 13:52:13 music volumio[13029]: info: Reloading queue from file Feb 06 13:52:13 music volumio[13029]: info: CoreStateMachine::setRepeat null single undefined Feb 06 13:52:13 music volumio[13029]: info: CoreStateMachine::pushState Feb 06 13:52:13 music volumio[13029]: info: CorePlayQueue::getTrack 0 Feb 06 13:52:13 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 06 13:52:13 music volumio[13029]: info: CoreCommandRouter::volumioPushState Feb 06 13:52:13 music volumio[13029]: info: CoreStateMachine::setRandom null Feb 06 13:52:13 music volumio[13029]: info: CoreStateMachine::pushState Feb 06 13:52:13 music volumio[13029]: info: CorePlayQueue::getTrack 0 Feb 06 13:52:13 music volumio[13029]: info: CoreCommandRouter::volumioPushState Feb 06 13:52:13 music volumio[13029]: info: Setting Device type: Raspberry PI Feb 06 13:52:13 music volumio[13029]: info: VolumeController:: Volume=86 Mute =false Feb 06 13:52:13 music volumio[13029]: info: CoreStateMachine::pushState Feb 06 13:52:13 music volumio[13029]: info: CorePlayQueue::getTrack 0 Feb 06 13:52:13 music volumio[13029]: info: CoreCommandRouter::volumioPushState Feb 06 13:52:13 music volumio[13029]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 06 13:52:13 music volumio[13029]: info: Discovery: Found device music Feb 06 13:52:13 music volumio[13029]: info: CoreCommandRouter::volumioGetState Feb 06 13:52:13 music volumio[13029]: info: CorePlayQueue::getTrack 0 Feb 06 13:52:13 music volumio[13029]: info: Completed loading Core Plugins Feb 06 13:52:13 music volumio[13029]: info: Preparing to generate the ALSA configuration file Feb 06 13:52:13 music volumio[13029]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 06 13:52:13 music volumio[13029]: info: Discovery: Found device music Feb 06 13:52:13 music volumio[13029]: info: CoreCommandRouter::volumioGetState Feb 06 13:52:13 music volumio[13029]: info: CorePlayQueue::getTrack 0 Feb 06 13:52:13 music volumio[13029]: info: Asound.conf file unchanged, so no further update is needed Feb 06 13:52:13 music volumio[13029]: info: Output device has changed, restarting MPD Feb 06 13:52:13 music volumio[13029]: info: Output device has changed, restarting Shairport Sync Feb 06 13:52:13 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:13 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:52:14 music sudo[13156]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 06 13:52:14 music sudo[13158]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 06 13:52:14 music sudo[13156]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:14 music volumio[13029]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 06 13:52:14 music sudo[13156]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:14 music sudo[13158]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:14 music volumio[13029]: info: ___________ START PLUGINS ___________ Feb 06 13:52:14 music volumio[13029]: info: ControllerMpd::onStart: Initializing MPD Feb 06 13:52:14 music volumio[13029]: info: Creating MPD Configuration file Feb 06 13:52:14 music systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 06 13:52:14 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 06 13:52:14 music volumio[13029]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 06 13:52:14 music volumio[13029]: info: [1770403934111] CoreMusicLibrary::Adding element Media Servers Feb 06 13:52:14 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 06 13:52:14 music volumio[13029]: info: UPNP Browser: Client initialized successfully Feb 06 13:52:14 music sudo[13166]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 06 13:52:14 music sudo[13166]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:14 music systemd[1]: mpd.service: Deactivated successfully. Feb 06 13:52:14 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 06 13:52:14 music systemd[1]: mpd.service: Consumed 4.156s CPU time. Feb 06 13:52:14 music systemd[1]: mpd.socket: Deactivated successfully. Feb 06 13:52:14 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:14 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 06 13:52:14 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 06 13:52:14 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:52:14 music sudo[13168]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 06 13:52:14 music sudo[13168]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:14 music sudo[13166]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:14 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 06 13:52:14 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 06 13:52:14 music volumio[13029]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 06 13:52:14 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:14 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:52:14 music systemd[1]: mpd.service: Deactivated successfully. Feb 06 13:52:14 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 06 13:52:14 music systemd[1]: mpd.socket: Deactivated successfully. Feb 06 13:52:14 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 06 13:52:14 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 06 13:52:14 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 06 13:52:14 music volumio[13029]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 06 13:52:14 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 06 13:52:14 music volumio[13029]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 06 13:52:14 music volumio[13029]: info: [1770403934329] CoreMusicLibrary::Adding element Last_100 Feb 06 13:52:14 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 06 13:52:14 music volumio[13029]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 06 13:52:14 music volumio[13029]: info: [1770403934344] CoreMusicLibrary::Adding element Webradio Feb 06 13:52:14 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 06 13:52:14 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 06 13:52:14 music volumio[13029]: info: Initializing BBC Radios Feb 06 13:52:14 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 06 13:52:14 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:52:14 music volumio[13029]: info: Creating Spotify config file Feb 06 13:52:14 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:14 music sudo[13182]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 06 13:52:14 music sudo[13182]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 06 13:52:14 music sudo[13182]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:14 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 06 13:52:14 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 06 13:52:14 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 06 13:52:14 music go-librespot[13198]: go-librespot daemon starting... Feb 06 13:52:14 music go-librespot[13199]: time="2026-02-06T13:52:14-05:00" level=info msg="running go-librespot 0.6.2" Feb 06 13:52:15 music volumio[13029]: info: Volumio Calling Home Feb 06 13:52:15 music go-librespot[13199]: time="2026-02-06T13:52:15-05:00" level=info msg="zeroconf server listening on port 32867" Feb 06 13:52:15 music volumio[13029]: info: MPD Permissions set Feb 06 13:52:15 music volumio[13029]: info: MPD Permissions set Feb 06 13:52:15 music volumio[13029]: info: Spotify config file written Feb 06 13:52:15 music volumio[13120]: Starting albumart workers Feb 06 13:52:15 music sudo[13212]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 06 13:52:15 music sudo[13212]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:15 music volumio[13029]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 06 13:52:15 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:15 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:15 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:15 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:15 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:15 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:15 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:15 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:15 music volumio[13117]: Starting albumart workers Feb 06 13:52:15 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 06 13:52:15 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:52:15 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:15 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:15 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:15 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:15 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:15 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 06 13:52:15 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 06 13:52:15 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:15 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:15 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:15 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:15 music volumio[13118]: Starting albumart workers Feb 06 13:52:15 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 06 13:52:15 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:52:15 music go-librespot[13219]: go-librespot daemon starting... Feb 06 13:52:15 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:15 music sudo[13212]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:15 music volumio[13029]: info: No need to fix Spotify hosts Feb 06 13:52:16 music go-librespot[13227]: time="2026-02-06T13:52:16-05:00" level=info msg="running go-librespot 0.6.2" Feb 06 13:52:16 music go-librespot[13227]: time="2026-02-06T13:52:16-05:00" level=debug msg="app state loaded" Feb 06 13:52:16 music go-librespot[13227]: time="2026-02-06T13:52:16-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 06 13:52:16 music volumio[13029]: info: Volumio called home Feb 06 13:52:16 music go-librespot[13227]: time="2026-02-06T13:52: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]" Feb 06 13:52:16 music go-librespot[13227]: time="2026-02-06T13:52: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]" Feb 06 13:52:16 music go-librespot[13227]: time="2026-02-06T13:52: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]" Feb 06 13:52:16 music volumio[13029]: info: Starting Shairport Sync Feb 06 13:52:16 music go-librespot[13227]: time="2026-02-06T13:52:16-05:00" level=info msg="zeroconf server listening on port 36373" Feb 06 13:52:16 music volumio[13029]: info: Starting Shairport Sync Feb 06 13:52:16 music volumio[13029]: info: Starting Shairport Sync Feb 06 13:52:16 music sudo[13237]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 06 13:52:16 music sudo[13237]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:16 music volumio[13029]: info: CoreCommandRouter::volumioGetState Feb 06 13:52:16 music volumio[13029]: info: CorePlayQueue::getTrack 0 Feb 06 13:52:16 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 06 13:52:16 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 06 13:52:16 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 06 13:52:16 music systemd[1]: shairport-sync.service: Consumed 1.861s CPU time. Feb 06 13:52:16 music sudo[13240]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 06 13:52:16 music sudo[13240]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:16 music go-librespot[13227]: time="2026-02-06T13:52:16-05:00" level=debug msg="obtained new client token: AACCtDuB8dWhLUN7Eaeg5LgiISG5HvyEIsOZd4Eyhx86YLQdkTVkFlwYJfV+qoKfD/Fbgr3K6Mqpsiooka3oCpohzKaTCyu6YluBXQU7rKlFBxsRfUBvSHL1e3GuCXp+gQwlV5D3giLa02OSq/go6KGC1tHqQPyspxBw4Lw4Hg0lze5LOIUf/zBO+5cHqumicgzLTW3oH7S/INoVQhfkDstvKbJyE8mvLl5fHUyJCSUwo5WGc13yH2g=" Feb 06 13:52:16 music sudo[13242]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 06 13:52:16 music sudo[13242]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:16 music volumio[13029]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 06 13:52:16 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 06 13:52:16 music sudo[13237]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:16 music go-librespot[13227]: time="2026-02-06T13:52:16-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 06 13:52:16 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 06 13:52:16 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 06 13:52:16 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 06 13:52:16 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 06 13:52:16 music go-librespot[13227]: time="2026-02-06T13:52:16-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:16 music go-librespot[13227]: time="2026-02-06T13:52:16-05:00" level=debug msg="completed challenge" Feb 06 13:52:16 music sudo[13240]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:16 music sudo[13242]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:16 music go-librespot[13227]: time="2026-02-06T13:52:16-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:17 music volumio[13029]: info: Shairport-Sync Started Feb 06 13:52:17 music volumio[13029]: Error adding Membership: Error: addMembership EINVAL Feb 06 13:52:17 music volumio[13029]: info: Shairport-Sync Started Feb 06 13:52:17 music volumio[13029]: info: Shairport-Sync Started Feb 06 13:52:17 music volumio[13029]: info: Listing playlists Feb 06 13:52:17 music volumio[13029]: info: Listing playlists Feb 06 13:52:17 music volumio[13029]: info: CoreCommandRouter::volumioGetState Feb 06 13:52:17 music volumio[13029]: info: CorePlayQueue::getTrack 0 Feb 06 13:52:17 music go-librespot[13227]: time="2026-02-06T13:52:17-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 06 13:52:17 music go-librespot[13227]: time="2026-02-06T13:52:17-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:17 music go-librespot[13227]: time="2026-02-06T13:52:17-05:00" level=debug msg="completed challenge" Feb 06 13:52:17 music go-librespot[13227]: time="2026-02-06T13:52:17-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:18 music go-librespot[13227]: time="2026-02-06T13:52:18-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 06 13:52:18 music go-librespot[13227]: time="2026-02-06T13:52:18-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:18 music go-librespot[13227]: time="2026-02-06T13:52:18-05:00" level=debug msg="completed challenge" Feb 06 13:52:18 music go-librespot[13227]: time="2026-02-06T13:52:18-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:18 music mpd[13197]: 2026-02-06T13:52:18 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 06 13:52:18 music systemd[1]: Started mpd.service - Music Player Daemon. Feb 06 13:52:18 music sudo[13158]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:18 music sudo[13168]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:18 music go-librespot[13227]: time="2026-02-06T13:52:18-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 06 13:52:18 music volumio[13029]: info: Completed starting Core Plugins Feb 06 13:52:18 music volumio[13029]: info: ------------------------------------------- Feb 06 13:52:18 music volumio[13029]: info: ----- MyVolumio plugins startup ---- Feb 06 13:52:18 music volumio[13029]: info: ------------------------------------------- Feb 06 13:52:18 music volumio[13029]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 06 13:52:18 music go-librespot[13227]: time="2026-02-06T13:52:18-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:18 music go-librespot[13227]: time="2026-02-06T13:52:18-05:00" level=debug msg="completed challenge" Feb 06 13:52:19 music go-librespot[13227]: time="2026-02-06T13:52:19-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:19 music volumio[13029]: error: MPD error: The expression evaluated to a falsy value: Feb 06 13:52:19 music volumio[13029]: assert.ok(self.idling) Feb 06 13:52:19 music volumio[13029]: error: The expression evaluated to a falsy value: Feb 06 13:52:19 music volumio[13029]: assert.ok(self.idling) Feb 06 13:52:19 music volumio[13029]: error: updateQueue error: null Feb 06 13:52:19 music volumio[13029]: info: MPD running with PID13197 Feb 06 13:52:19 music volumio[13029]: ,establishing connection Feb 06 13:52:19 music volumio[13029]: error: updateQueue error: null Feb 06 13:52:19 music volumio[13029]: info: go-librespot daemon successfully initialized Feb 06 13:52:19 music sudo[13300]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 06 13:52:19 music sudo[13300]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:19 music sudo[13300]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:19 music sudo[13302]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 06 13:52:19 music sudo[13302]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:19 music sudo[13302]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:19 music sudo[13306]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 06 13:52:19 music sudo[13306]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:19 music sudo[13306]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:19 music volumio[13029]: info: Upmpdcli Daemon Started Feb 06 13:52:20 music go-librespot[13227]: time="2026-02-06T13:52:20-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 06 13:52:21 music go-librespot[13227]: time="2026-02-06T13:52:21-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:21 music go-librespot[13227]: time="2026-02-06T13:52:21-05:00" level=debug msg="completed challenge" Feb 06 13:52:21 music go-librespot[13227]: time="2026-02-06T13:52:21-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:21 music go-librespot[13227]: time="2026-02-06T13:52:21-05:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 06 13:52:21 music go-librespot[13227]: time="2026-02-06T13:52:21-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:57026->104.199.65.9:80: read: connection reset by peer" Feb 06 13:52:21 music go-librespot[13227]: time="2026-02-06T13:52:21-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:57026->104.199.65.9:80: read: connection reset by peer" Feb 06 13:52:21 music sudo[13309]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 06 13:52:21 music sudo[13309]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:21 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 06 13:52:21 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 06 13:52:21 music sudo[13311]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 06 13:52:21 music sudo[13311]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:22 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 06 13:52:22 music systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 06 13:52:22 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 06 13:52:22 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 06 13:52:22 music sudo[13309]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:22 music sudo[13311]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:22 music mpd_monitor.sh[13314]: MPD Monitor Service: Starting MPD Monitor Service Feb 06 13:52:22 music volumio[13029]: info: Successfully started MPD Monitor Feb 06 13:52:22 music volumio[13029]: info: Successfully started MPD Monitor Feb 06 13:52:22 music volumio[13029]: info: Initializing connection to go-librespot Websocket Feb 06 13:52:22 music volumio[13029]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 06 13:52:23 music volumio[13029]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 06 13:52:25 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 06 13:52:25 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 06 13:52:25 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 06 13:52:25 music go-librespot[13318]: go-librespot daemon starting... Feb 06 13:52:25 music go-librespot[13319]: time="2026-02-06T13:52:25-05:00" level=info msg="running go-librespot 0.6.2" Feb 06 13:52:25 music go-librespot[13319]: time="2026-02-06T13:52:25-05:00" level=debug msg="app state loaded" Feb 06 13:52:25 music go-librespot[13319]: time="2026-02-06T13:52:25-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 06 13:52:25 music go-librespot[13319]: time="2026-02-06T13:52:25-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Feb 06 13:52:25 music go-librespot[13319]: time="2026-02-06T13:52:25-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 06 13:52:25 music go-librespot[13319]: time="2026-02-06T13:52:25-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 06 13:52:25 music go-librespot[13319]: time="2026-02-06T13:52:25-05:00" level=info msg="zeroconf server listening on port 46783" Feb 06 13:52:25 music volumio[13029]: info: Initializing connection to go-librespot Websocket Feb 06 13:52:25 music go-librespot[13319]: time="2026-02-06T13:52:25-05:00" level=debug msg="new websocket client" Feb 06 13:52:25 music volumio[13029]: info: Connection to go-librespot Websocket established Feb 06 13:52:25 music go-librespot[13319]: time="2026-02-06T13:52:25-05:00" level=debug msg="obtained new client token: AABUW8LWFQyBvhHUBqNdZoqf4oTSKPVVJoM+11tqvhawDpSLKxOU9k/7JJld8C49WOL/sZYGPNMjSAWmGBEXsEe+5f4ZP8ZcpDUmMIgD3nL5fLXzd/tNe7RhgKoa0445t61+AWkIyWkgSCgnhQM0tnJXXeqfzPlNVKsnXWVlS6uoE+bf9uPnIw/ueg7O6MZSu9u2aeSMHtSfLZcT5lR/grrzGsCeKSmWkx7IGXOe0JS+05eY2loBDsw=" Feb 06 13:52:25 music go-librespot[13319]: time="2026-02-06T13:52:25-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.255.62:4070: connect: connection refused" Feb 06 13:52:25 music volumio[13029]: info: CoreCommandRouter::volumioGetState Feb 06 13:52:25 music volumio[13029]: info: CorePlayQueue::getTrack 0 Feb 06 13:52:25 music go-librespot[13319]: time="2026-02-06T13:52:25-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 06 13:52:25 music go-librespot[13319]: time="2026-02-06T13:52:25-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:25 music go-librespot[13319]: time="2026-02-06T13:52:25-05:00" level=debug msg="completed challenge" Feb 06 13:52:25 music go-librespot[13319]: time="2026-02-06T13:52:25-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:26 music go-librespot[13319]: time="2026-02-06T13:52:26-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 06 13:52:26 music go-librespot[13319]: time="2026-02-06T13:52:26-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:26 music go-librespot[13319]: time="2026-02-06T13:52:26-05:00" level=debug msg="completed challenge" Feb 06 13:52:26 music go-librespot[13319]: time="2026-02-06T13:52:26-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:27 music go-librespot[13319]: time="2026-02-06T13:52:27-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 06 13:52:27 music volumio[13029]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 06 13:52:27 music volumio[13029]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 06 13:52:27 music volumio[13029]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 06 13:52:27 music volumio[13029]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 06 13:52:27 music volumio[13029]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 06 13:52:27 music volumio[13029]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 06 13:52:27 music volumio[13029]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 06 13:52:27 music volumio[13029]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 06 13:52:27 music volumio[13029]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 06 13:52:27 music volumio[13029]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 06 13:52:27 music volumio[13029]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 06 13:52:27 music volumio[13029]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 06 13:52:27 music volumio[13029]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 06 13:52:27 music volumio[13029]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 06 13:52:27 music volumio[13029]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 06 13:52:27 music volumio[13029]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 06 13:52:27 music volumio[13029]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 06 13:52:27 music volumio[13029]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 06 13:52:27 music volumio[13029]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 06 13:52:27 music volumio[13029]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 06 13:52:27 music volumio[13029]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 06 13:52:27 music volumio[13029]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 06 13:52:27 music volumio[13029]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 06 13:52:27 music volumio[13029]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 06 13:52:27 music volumio[13029]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 06 13:52:27 music volumio[13029]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 06 13:52:27 music volumio[13029]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 06 13:52:27 music volumio[13029]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 06 13:52:27 music volumio[13029]: info: Adding plugin bluetooth to MyMusic Plugins Feb 06 13:52:27 music volumio[13029]: info: Adding plugin multiroom to MyMusic Plugins Feb 06 13:52:27 music volumio[13029]: info: Adding plugin metavolumio to MyMusic Plugins Feb 06 13:52:27 music volumio[13029]: info: Adding plugin cd_controller to MyMusic Plugins Feb 06 13:52:27 music volumio[13029]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 06 13:52:27 music volumio[13029]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 06 13:52:27 music volumio[13029]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 06 13:52:27 music volumio[13029]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 06 13:52:27 music go-librespot[13319]: time="2026-02-06T13:52:27-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:27 music go-librespot[13319]: time="2026-02-06T13:52:27-05:00" level=debug msg="completed challenge" Feb 06 13:52:27 music go-librespot[13319]: time="2026-02-06T13:52:27-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:28 music go-librespot[13319]: time="2026-02-06T13:52:28-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 06 13:52:28 music volumio[13029]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 06 13:52:28 music volumio[13029]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 06 13:52:28 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:52:28 music volumio[13029]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:52:28 music volumio[13029]: info: Starting MyVolumio Remote Streaming Endpoints Feb 06 13:52:28 music volumio[13029]: info: MyVolumio login type: Token Feb 06 13:52:28 music volumio[13029]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 06 13:52:28 music volumio[13029]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 06 13:52:28 music go-librespot[13319]: time="2026-02-06T13:52:28-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:28 music go-librespot[13319]: time="2026-02-06T13:52:28-05:00" level=debug msg="completed challenge" Feb 06 13:52:28 music go-librespot[13319]: time="2026-02-06T13:52:28-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:29 music volumio[13029]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 06 13:52:29 music volumio[13029]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 06 13:52:29 music volumio[13029]: info: Streaming services startup Feb 06 13:52:29 music volumio[13029]: info: Starting Streaming Daemon Feb 06 13:52:29 music sudo[13329]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 06 13:52:29 music sudo[13329]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:29 music volumio[13029]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 06 13:52:29 music go-librespot[13319]: time="2026-02-06T13:52:29-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 06 13:52:29 music sudo[13329]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:29 music volumio[13029]: info: Getting Spotify volume Feb 06 13:52:29 music volumio[13029]: error: Cannot start Volumio Streaming Daemon Feb 06 13:52:29 music volumio[13029]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 06 13:52:29 music volumio[13029]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 06 13:52:29 music volumio[13029]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 06 13:52:29 music go-librespot[13319]: time="2026-02-06T13:52:29-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:29 music go-librespot[13319]: time="2026-02-06T13:52:29-05:00" level=debug msg="completed challenge" Feb 06 13:52:29 music volumio[13029]: info: CoreCommandRouter::volumioGetState Feb 06 13:52:29 music volumio[13029]: info: CorePlayQueue::getTrack 0 Feb 06 13:52:29 music go-librespot[13319]: time="2026-02-06T13:52:29-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:29 music volumio[13029]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Feb 06 13:52:29 music volumio[13029]: SPOTIFY: SPOTIFY VOLUME undefined Feb 06 13:52:29 music volumio[13029]: SPOTIFY: VOLUMIO VOLUME 86 Feb 06 13:52:29 music volumio[13029]: info: Aligning Spotify Volume to Volumio Volume Feb 06 13:52:29 music volumio[13029]: info: CoreCommandRouter::volumioGetState Feb 06 13:52:29 music volumio[13029]: info: CorePlayQueue::getTrack 0 Feb 06 13:52:29 music volumio[13029]: info: Setting Spotify Volume from Volumio: 86 Feb 06 13:52:29 music volumio[13029]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 06 13:52:30 music go-librespot[13319]: time="2026-02-06T13:52:30-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 06 13:52:30 music go-librespot[13319]: time="2026-02-06T13:52:30-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:30 music go-librespot[13319]: time="2026-02-06T13:52:30-05:00" level=debug msg="completed challenge" Feb 06 13:52:30 music go-librespot[13319]: time="2026-02-06T13:52:30-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:30 music go-librespot[13319]: time="2026-02-06T13:52:30-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:30 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 06 13:52:30 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 06 13:52:30 music volumio[13029]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 06 13:52:30 music volumio[13029]: Error: socket hang up Feb 06 13:52:30 music volumio[13029]: at connResetException (node:internal/errors:720:14) Feb 06 13:52:30 music volumio[13029]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 06 13:52:30 music volumio[13029]: at Socket.emit (node:events:526:35) Feb 06 13:52:30 music volumio[13029]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 06 13:52:30 music volumio[13029]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 06 13:52:30 music volumio[13029]: code: 'ECONNRESET', Feb 06 13:52:30 music volumio[13029]: response: undefined Feb 06 13:52:30 music volumio[13029]: } Feb 06 13:52:30 music volumio[13029]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 06 13:52:31 music sudo[13366]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-06 13:51' Feb 06 13:52:31 music sudo[13366]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:31 music sudo[13366]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:32 music volumio-remote-updater[31331]: [2026-02-06 13:52:32] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 06 13:52:32 music volumio-remote-updater[31331]: [2026-02-06 13:52:32] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 06 13:52:32 music systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 06 13:52:32 music systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 06 13:52:32 music systemd[1]: volumio.service: Consumed 27.065s CPU time. Feb 06 13:52:32 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 06 13:52:32 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 06 13:52:32 music systemd[1]: volumio.service: Scheduled restart job, restart counter is at 48076. Feb 06 13:52:32 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 06 13:52:32 music systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 06 13:52:32 music systemd[1]: volumio.service: Consumed 27.065s CPU time. Feb 06 13:52:32 music systemd[1]: Started volumio.service - Volumio Backend Module. Feb 06 13:52:32 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 06 13:52:33 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 06 13:52:33 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 06 13:52:33 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 06 13:52:33 music go-librespot[13396]: go-librespot daemon starting... Feb 06 13:52:33 music go-librespot[13397]: time="2026-02-06T13:52:33-05:00" level=info msg="running go-librespot 0.6.2" Feb 06 13:52:33 music go-librespot[13397]: time="2026-02-06T13:52:33-05:00" level=debug msg="app state loaded" Feb 06 13:52:33 music go-librespot[13397]: time="2026-02-06T13:52:33-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 06 13:52:33 music go-librespot[13397]: time="2026-02-06T13:52:33-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 06 13:52:33 music go-librespot[13397]: time="2026-02-06T13:52:33-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 06 13:52:33 music go-librespot[13397]: time="2026-02-06T13:52:33-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 06 13:52:33 music go-librespot[13397]: time="2026-02-06T13:52:33-05:00" level=info msg="zeroconf server listening on port 37597" Feb 06 13:52:33 music go-librespot[13397]: time="2026-02-06T13:52:33-05:00" level=debug msg="obtained new client token: AADj1ZirGq4wA5+lSPHTGvwU5yQeH2uUB5hCtqrL6keoZGN+T4IDDr6MNb48d9tH2FIifEnmemQDq4LQRwgAdHNq+Snpt5/GscKSRREO+X1jO687/Bfx8F2IOtSue38oYjSG0ogz8M/volibW0ySilv+YQq6sTodPXpPs2WIIAMzRhRq4+z59xdxHCpQMAGMLvC1UzkA9nYEfGf6aFy8VlvkMZjL/ko7sICS54I5RqeVd7pcFOWKPZw=" Feb 06 13:52:33 music go-librespot[13397]: time="2026-02-06T13:52:33-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 06 13:52:34 music go-librespot[13397]: time="2026-02-06T13:52:34-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:34 music go-librespot[13397]: time="2026-02-06T13:52:34-05:00" level=debug msg="completed challenge" Feb 06 13:52:34 music go-librespot[13397]: time="2026-02-06T13:52:34-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:34 music volumio[13381]: info: ------------------------------------------- Feb 06 13:52:34 music volumio[13381]: info: ----- Volumio3 ---- Feb 06 13:52:34 music volumio[13381]: info: ------------------------------------------- Feb 06 13:52:34 music volumio[13381]: info: ----- System startup ---- Feb 06 13:52:34 music volumio[13381]: info: ------------------------------------------- Feb 06 13:52:34 music go-librespot[13397]: time="2026-02-06T13:52:34-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 06 13:52:34 music go-librespot[13397]: time="2026-02-06T13:52:34-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:34 music go-librespot[13397]: time="2026-02-06T13:52:34-05:00" level=debug msg="completed challenge" Feb 06 13:52:34 music go-librespot[13397]: time="2026-02-06T13:52:34-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:35 music volumio[13381]: info: MYVOLUMIO Environment detected Feb 06 13:52:35 music volumio[13381]: info: Plugin folders cleanup Feb 06 13:52:35 music volumio[13381]: info: Scanning into folder /volumio/app/plugins/ Feb 06 13:52:35 music volumio[13381]: info: Scanning category audio_interface Feb 06 13:52:35 music volumio[13381]: info: Scanning category miscellanea Feb 06 13:52:35 music volumio[13381]: info: Scanning category music_service Feb 06 13:52:35 music volumio[13381]: info: Scanning category plugins.json Feb 06 13:52:35 music volumio[13381]: info: Scanning category system_controller Feb 06 13:52:35 music volumio[13381]: info: Scanning category user_interface Feb 06 13:52:35 music volumio[13381]: info: Scanning into folder /data/plugins/ Feb 06 13:52:35 music volumio[13381]: info: Scanning category music_service Feb 06 13:52:35 music volumio[13381]: info: Plugin folders cleanup completed Feb 06 13:52:35 music volumio[13381]: info: ------------------------------------------- Feb 06 13:52:35 music volumio[13381]: info: ----- Core plugins startup ---- Feb 06 13:52:35 music volumio[13381]: info: ------------------------------------------- Feb 06 13:52:35 music volumio[13381]: info: Loading plugins from folder /volumio/app/plugins/ Feb 06 13:52:35 music volumio[13381]: info: Adding plugin upnp to MyMusic Plugins Feb 06 13:52:35 music volumio[13381]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 06 13:52:35 music volumio[13381]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 06 13:52:35 music volumio[13381]: info: Loading plugins from folder /data/plugins/ Feb 06 13:52:35 music volumio[13381]: info: Loading plugin "system"... Feb 06 13:52:35 music volumio[13381]: info: Loading plugin "appearance"... Feb 06 13:52:35 music go-librespot[13397]: time="2026-02-06T13:52:35-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 06 13:52:35 music go-librespot[13397]: time="2026-02-06T13:52:35-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:35 music go-librespot[13397]: time="2026-02-06T13:52:35-05:00" level=debug msg="completed challenge" Feb 06 13:52:35 music go-librespot[13397]: time="2026-02-06T13:52:35-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:36 music go-librespot[13397]: time="2026-02-06T13:52:36-05:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 06 13:52:36 music go-librespot[13397]: time="2026-02-06T13:52:36-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 06 13:52:36 music volumio[13381]: info: Loading plugin "network"... Feb 06 13:52:36 music volumio[13381]: info: Refreshing Cached IP Addresses Feb 06 13:52:36 music go-librespot[13397]: time="2026-02-06T13:52:36-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:36 music go-librespot[13397]: time="2026-02-06T13:52:36-05:00" level=debug msg="completed challenge" Feb 06 13:52:36 music sudo[13420]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 06 13:52:36 music sudo[13420]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:36 music sudo[13422]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 06 13:52:36 music sudo[13422]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:36 music sudo[13420]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:36 music volumio[13381]: info: Loading plugin "services"... Feb 06 13:52:36 music volumio[13381]: info: Loading plugin "alsa_controller"... Feb 06 13:52:36 music sudo[13422]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:36 music sudo[13426]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 06 13:52:36 music sudo[13426]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:36 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 06 13:52:36 music volumio[13381]: info: Loading plugin "wizard"... Feb 06 13:52:36 music volumio[13381]: info: Loading plugin "networkfs"... Feb 06 13:52:36 music go-librespot[13397]: time="2026-02-06T13:52:36-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:36 music volumio[13381]: info: Starting Udev Watcher for removable devices Feb 06 13:52:36 music volumio[13381]: info: Ignoring mount for partition: boot Feb 06 13:52:36 music volumio[13381]: info: Ignoring mount for partition: volumio Feb 06 13:52:36 music volumio[13381]: info: Ignoring mount for partition: volumio_data Feb 06 13:52:36 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 06 13:52:36 music volumio[13381]: info: Loading plugin "volumio_command_line_client"... Feb 06 13:52:36 music volumio[13381]: info: Loading plugin "upnp"... Feb 06 13:52:36 music volumio[13381]: info: [1770403956667] Starting Upmpd Daemon Feb 06 13:52:36 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 06 13:52:36 music volumio[13381]: info: Loading plugin "my_music"... Feb 06 13:52:36 music volumio[13381]: info: Loading plugin "mpd"... Feb 06 13:52:37 music volumio[13381]: info: Loading plugin "upnp_browser"... Feb 06 13:52:37 music volumio-remote-updater[31331]: [2026-02-06 13:52:37] [connect] Successful connection Feb 06 13:52:37 music sudo[13426]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:37 music go-librespot[13397]: time="2026-02-06T13:52:37-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 06 13:52:37 music go-librespot[13397]: time="2026-02-06T13:52:37-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:37 music go-librespot[13397]: time="2026-02-06T13:52:37-05:00" level=debug msg="completed challenge" Feb 06 13:52:37 music go-librespot[13397]: time="2026-02-06T13:52:37-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:38 music go-librespot[13397]: time="2026-02-06T13:52:38-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.255.62:4070: connect: connection refused" Feb 06 13:52:38 music go-librespot[13397]: time="2026-02-06T13:52:38-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 06 13:52:38 music go-librespot[13397]: time="2026-02-06T13:52:38-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:38 music go-librespot[13397]: time="2026-02-06T13:52:38-05:00" level=debug msg="completed challenge" Feb 06 13:52:38 music go-librespot[13397]: time="2026-02-06T13:52:38-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:38 music go-librespot[13397]: time="2026-02-06T13:52:38-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:38 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 06 13:52:38 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 06 13:52:38 music volumio[13381]: info: Starting UPNP Browser Feb 06 13:52:38 music volumio[13381]: info: Loading plugin "alarm-clock"... Feb 06 13:52:38 music volumio[13381]: info: Loading plugin "airplay_emulation"... Feb 06 13:52:38 music volumio[13381]: info: Starting Shairport Sync Feb 06 13:52:38 music volumio[13381]: info: Loading plugin "last_100"... Feb 06 13:52:38 music volumio[13381]: info: Loading plugin "webradio"... Feb 06 13:52:38 music volumio[13381]: info: Loading plugin "i2s_dacs"... Feb 06 13:52:38 music volumio[13381]: info: I2S DAC not set, start Auto-detection Feb 06 13:52:38 music volumio[13381]: info: Loading plugin "volumiodiscovery"... Feb 06 13:52:38 music volumio[13381]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 06 13:52:38 music volumio[13381]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 06 13:52:38 music volumio[13381]: *** WARNING *** For more information see Feb 06 13:52:38 music volumio[13381]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 06 13:52:38 music volumio[13381]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 06 13:52:38 music volumio[13381]: *** WARNING *** For more information see Feb 06 13:52:38 music node[13381]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 06 13:52:38 music node[13381]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 06 13:52:38 music node[13381]: *** WARNING *** For more information see Feb 06 13:52:38 music node[13381]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 06 13:52:38 music node[13381]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 06 13:52:38 music node[13381]: *** WARNING *** For more information see Feb 06 13:52:38 music volumio[13381]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 06 13:52:38 music volumio[13381]: info: Discovery: Started advertising with name: music Feb 06 13:52:38 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 06 13:52:38 music volumio[13381]: info: Loading plugin "spop"... Feb 06 13:52:40 music volumio[13381]: info: Loading plugin "outputs"... Feb 06 13:52:40 music volumio[13381]: info: Loading plugin "albumart"... Feb 06 13:52:40 music volumio[13381]: info: Plugin example_plugin is not enabled Feb 06 13:52:40 music volumio[13381]: info: Loading plugin "inputs"... Feb 06 13:52:40 music volumio[13381]: info: Loading plugin "updater_comm"... Feb 06 13:52:40 music volumio[13381]: info: Plugin mpdemulation is not enabled Feb 06 13:52:40 music volumio[13381]: info: Loading plugin "rest_api"... Feb 06 13:52:40 music volumio[13381]: info: Loading plugin "websocket"... Feb 06 13:52:40 music volumio[13381]: info: Starting Socket.io Server version 1.7.4 Feb 06 13:52:40 music volumio[13381]: info: Loading i18n strings for locale en Feb 06 13:52:40 music volumio[13381]: Updating browse sources language Feb 06 13:52:40 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 06 13:52:40 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 06 13:52:40 music volumio[13381]: info: CoreCommandRouter::initPlayerControls Feb 06 13:52:40 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:40 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:40 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:40 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:40 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:40 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:40 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:40 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:40 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 06 13:52:40 music volumio[13381]: Express server listening on port 3000 Feb 06 13:52:40 music volumio[13381]: [Metrics] WebUI: 6s 548.35ms Feb 06 13:52:40 music volumio[13381]: info: CoreStateMachine::resetVolumioState Feb 06 13:52:40 music volumio[13381]: info: CoreStateMachine::getcurrentVolume Feb 06 13:52:40 music volumio[13381]: info: CoreCommandRouter::volumioRetrievevolume Feb 06 13:52:40 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:52:40 music volumio[13381]: info: Volumio Network Manager: Network status updated: 1 Feb 06 13:52:40 music volumio[13381]: info: VolumeController:: Volume=86 Mute =false Feb 06 13:52:40 music volumio[13381]: info: CoreStateMachine::pushState Feb 06 13:52:40 music volumio[13381]: info: CorePlayQueue::getTrack 0 Feb 06 13:52:40 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 06 13:52:40 music volumio[13381]: info: CoreCommandRouter::volumioPushState Feb 06 13:52:40 music volumio[13381]: info: CoreStateMachine::updateTrackBlock Feb 06 13:52:40 music volumio[13381]: info: CorePlayQueue::getTrackBlock Feb 06 13:52:40 music volumio[13381]: info: CoreCommandRouter::volumioRetrievevolume Feb 06 13:52:40 music volumio[13455]: Forking 3 albumart workers Feb 06 13:52:40 music volumio[13381]: info: CoreCommandRouter::volumioGetState Feb 06 13:52:40 music volumio[13381]: info: CorePlayQueue::getTrack 0 Feb 06 13:52:40 music volumio-remote-updater[31331]: [2026-02-06 13:52:40] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770403957 101 Feb 06 13:52:40 music volumio[13381]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 06 13:52:40 music volumio[13381]: info: Reloading queue from file Feb 06 13:52:40 music volumio[13381]: info: CoreStateMachine::setRepeat null single undefined Feb 06 13:52:40 music volumio[13381]: info: CoreStateMachine::pushState Feb 06 13:52:40 music volumio[13381]: info: CorePlayQueue::getTrack 0 Feb 06 13:52:40 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 06 13:52:40 music volumio[13381]: info: CoreCommandRouter::volumioPushState Feb 06 13:52:40 music volumio[13381]: info: CoreStateMachine::setRandom null Feb 06 13:52:40 music volumio[13381]: info: CoreStateMachine::pushState Feb 06 13:52:40 music volumio[13381]: info: CorePlayQueue::getTrack 0 Feb 06 13:52:40 music volumio[13381]: info: CoreCommandRouter::volumioPushState Feb 06 13:52:40 music volumio[13381]: info: Setting Device type: Raspberry PI Feb 06 13:52:40 music volumio[13381]: info: Listing playlists Feb 06 13:52:40 music volumio[13381]: info: Listing playlists Feb 06 13:52:40 music volumio[13381]: info: VolumeController:: Volume=86 Mute =false Feb 06 13:52:40 music volumio[13381]: info: CoreStateMachine::pushState Feb 06 13:52:40 music volumio[13381]: info: CorePlayQueue::getTrack 0 Feb 06 13:52:40 music volumio[13381]: info: CoreCommandRouter::volumioPushState Feb 06 13:52:40 music volumio[13381]: info: Completed loading Core Plugins Feb 06 13:52:40 music volumio[13381]: info: Preparing to generate the ALSA configuration file Feb 06 13:52:41 music volumio[13381]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 06 13:52:41 music volumio[13381]: info: Discovery: Found device music Feb 06 13:52:41 music volumio[13381]: info: CoreCommandRouter::volumioGetState Feb 06 13:52:41 music volumio[13381]: info: CorePlayQueue::getTrack 0 Feb 06 13:52:41 music volumio[13381]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 06 13:52:41 music volumio[13381]: info: Discovery: Found device music Feb 06 13:52:41 music volumio[13381]: info: CoreCommandRouter::volumioGetState Feb 06 13:52:41 music volumio[13381]: info: CorePlayQueue::getTrack 0 Feb 06 13:52:41 music volumio[13381]: info: Asound.conf file unchanged, so no further update is needed Feb 06 13:52:41 music volumio[13381]: info: Output device has changed, restarting MPD Feb 06 13:52:41 music volumio[13381]: info: Output device has changed, restarting Shairport Sync Feb 06 13:52:41 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:41 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:52:41 music sudo[13511]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 06 13:52:41 music volumio[13381]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 06 13:52:41 music sudo[13511]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:41 music sudo[13512]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 06 13:52:41 music volumio[13381]: info: ___________ START PLUGINS ___________ Feb 06 13:52:41 music sudo[13512]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:41 music sudo[13511]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:41 music volumio[13381]: info: ControllerMpd::onStart: Initializing MPD Feb 06 13:52:41 music volumio[13381]: info: Creating MPD Configuration file Feb 06 13:52:41 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 06 13:52:41 music volumio[13381]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 06 13:52:41 music systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 06 13:52:41 music volumio[13381]: info: [1770403961225] CoreMusicLibrary::Adding element Media Servers Feb 06 13:52:41 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 06 13:52:41 music sudo[13520]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 06 13:52:41 music sudo[13520]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:41 music sudo[13522]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 06 13:52:41 music sudo[13522]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:41 music sudo[13520]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:41 music volumio[13381]: info: UPNP Browser: Client initialized successfully Feb 06 13:52:41 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:41 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:52:41 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 06 13:52:41 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 06 13:52:41 music volumio[13381]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 06 13:52:41 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:41 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:52:41 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 06 13:52:41 music go-librespot[13529]: go-librespot daemon starting... Feb 06 13:52:41 music systemd[1]: mpd.service: Deactivated successfully. Feb 06 13:52:41 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 06 13:52:41 music systemd[1]: mpd.service: Consumed 4.181s CPU time. Feb 06 13:52:41 music systemd[1]: mpd.socket: Deactivated successfully. Feb 06 13:52:41 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 06 13:52:41 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 06 13:52:41 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 06 13:52:41 music volumio[13381]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 06 13:52:41 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 06 13:52:41 music volumio[13381]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 06 13:52:41 music volumio[13381]: info: [1770403961428] CoreMusicLibrary::Adding element Last_100 Feb 06 13:52:41 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 06 13:52:41 music volumio[13381]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 06 13:52:41 music volumio[13381]: info: [1770403961435] CoreMusicLibrary::Adding element Webradio Feb 06 13:52:41 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 06 13:52:41 music go-librespot[13534]: time="2026-02-06T13:52:41-05:00" level=info msg="running go-librespot 0.6.2" Feb 06 13:52:41 music go-librespot[13534]: time="2026-02-06T13:52:41-05:00" level=debug msg="app state loaded" Feb 06 13:52:41 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 06 13:52:41 music volumio[13381]: info: Initializing BBC Radios Feb 06 13:52:41 music go-librespot[13534]: time="2026-02-06T13:52:41-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 06 13:52:41 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 06 13:52:41 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:52:41 music volumio[13381]: info: Creating Spotify config file Feb 06 13:52:41 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:41 music sudo[13540]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 06 13:52:41 music sudo[13540]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 06 13:52:41 music sudo[13540]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:41 music go-librespot[13534]: time="2026-02-06T13:52:41-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Feb 06 13:52:41 music go-librespot[13534]: time="2026-02-06T13:52:41-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 06 13:52:41 music go-librespot[13534]: time="2026-02-06T13:52:41-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 06 13:52:42 music go-librespot[13534]: time="2026-02-06T13:52:42-05:00" level=info msg="zeroconf server listening on port 42155" Feb 06 13:52:42 music go-librespot[13534]: time="2026-02-06T13:52:42-05:00" level=debug msg="obtained new client token: AADT5t5J6SReLo8ZbyRg66QtxR99eoK3c0jdp2MZ4IqBi8G25Su9YLLWAhhFH8v4wwIHSuCkGINiOVFds6SNQ0tBYY6cd/nPMdgKIM+4mjWHDAg2H3+IcbcXwQkW/i4kds3cB93ugnxngIHqXC6UCjy+Q0YxJdiVna11tirPxLkk6mHBOY3zTF/LjKoRRAl2r3w6RIxlOhBfbR++SUgfDTP6POGo9xRCY8alwjQWOHkbihcNcJ3v" Feb 06 13:52:42 music go-librespot[13534]: time="2026-02-06T13:52:42-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 06 13:52:42 music volumio[13381]: info: Volumio Calling Home Feb 06 13:52:42 music go-librespot[13534]: time="2026-02-06T13:52:42-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:42 music go-librespot[13534]: time="2026-02-06T13:52:42-05:00" level=debug msg="completed challenge" Feb 06 13:52:42 music go-librespot[13534]: time="2026-02-06T13:52:42-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:42 music volumio[13472]: Starting albumart workers Feb 06 13:52:42 music volumio[13381]: info: MPD Permissions set Feb 06 13:52:42 music volumio[13381]: info: MPD Permissions set Feb 06 13:52:42 music volumio[13381]: info: Volumio called home Feb 06 13:52:42 music volumio[13381]: info: Spotify config file written Feb 06 13:52:42 music volumio[13473]: Starting albumart workers Feb 06 13:52:42 music volumio[13381]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 06 13:52:42 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:42 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:42 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:42 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:42 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:42 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:42 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:42 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:42 music sudo[13567]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 06 13:52:42 music sudo[13567]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:42 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:52:42 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:42 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:42 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:42 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:42 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:42 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:42 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:42 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:42 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:42 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:52:42 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:52:42 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 06 13:52:42 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 06 13:52:42 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 06 13:52:42 music volumio[13381]: info: No need to fix Spotify hosts Feb 06 13:52:42 music volumio[13474]: Starting albumart workers Feb 06 13:52:43 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 06 13:52:43 music go-librespot[13579]: go-librespot daemon starting... Feb 06 13:52:43 music sudo[13567]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:43 music go-librespot[13580]: time="2026-02-06T13:52:43-05:00" level=info msg="running go-librespot 0.6.2" Feb 06 13:52:43 music go-librespot[13580]: time="2026-02-06T13:52:43-05:00" level=debug msg="app state loaded" Feb 06 13:52:43 music go-librespot[13580]: time="2026-02-06T13:52:43-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 06 13:52:43 music volumio[13381]: info: Starting Shairport Sync Feb 06 13:52:43 music go-librespot[13580]: time="2026-02-06T13:52:43-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 06 13:52:43 music go-librespot[13580]: time="2026-02-06T13:52:43-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 06 13:52:43 music go-librespot[13580]: time="2026-02-06T13:52:43-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 06 13:52:43 music go-librespot[13580]: time="2026-02-06T13:52:43-05:00" level=info msg="zeroconf server listening on port 41453" Feb 06 13:52:43 music volumio[13381]: info: Starting Shairport Sync Feb 06 13:52:43 music volumio[13381]: info: Starting Shairport Sync Feb 06 13:52:43 music sudo[13590]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 06 13:52:43 music sudo[13590]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:43 music volumio[13381]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 06 13:52:43 music sudo[13592]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 06 13:52:43 music sudo[13592]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:43 music sudo[13594]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 06 13:52:43 music sudo[13594]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:43 music go-librespot[13580]: time="2026-02-06T13:52:43-05:00" level=debug msg="obtained new client token: AABDOorhwSXSLPJBQITPDWGgSOs47HI9jrYmM9xDhqqdfxttJT1xcGXWnqx1n2OumMWzLKEx9tqHM19+crwPuzllsQ1ROQihMegRu6M2NrK+PaiQjj7NfiL1jaKhWW9N7U/FbxFfmYtdZUzu0WukUuQFgL0n0sgH0q6TKn2zgrv04KISBtX7xyRggfEbG+T0ABOWXdTJ8ai8NAn08G20+qFgH+Ff07f+Fb3tDDamPup1Lls3pszww/0=" Feb 06 13:52:43 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 06 13:52:43 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 06 13:52:43 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 06 13:52:43 music systemd[1]: shairport-sync.service: Consumed 1.783s CPU time. Feb 06 13:52:43 music go-librespot[13580]: time="2026-02-06T13:52:43-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 06 13:52:44 music go-librespot[13580]: time="2026-02-06T13:52:44-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:44 music go-librespot[13580]: time="2026-02-06T13:52:44-05:00" level=debug msg="completed challenge" Feb 06 13:52:44 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 06 13:52:44 music sudo[13590]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:44 music sudo[13594]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:44 music sudo[13592]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:44 music go-librespot[13580]: time="2026-02-06T13:52:44-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:44 music volumio[13381]: info: Shairport-Sync Started Feb 06 13:52:44 music volumio[13381]: Error adding Membership: Error: addMembership EINVAL Feb 06 13:52:44 music volumio[13381]: info: Shairport-Sync Started Feb 06 13:52:44 music volumio[13381]: info: Shairport-Sync Started Feb 06 13:52:44 music volumio[13381]: info: CoreCommandRouter::volumioGetState Feb 06 13:52:44 music volumio[13381]: info: CorePlayQueue::getTrack 0 Feb 06 13:52:44 music go-librespot[13580]: time="2026-02-06T13:52:44-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 06 13:52:44 music go-librespot[13580]: time="2026-02-06T13:52:44-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:44 music go-librespot[13580]: time="2026-02-06T13:52:44-05:00" level=debug msg="completed challenge" Feb 06 13:52:44 music go-librespot[13580]: time="2026-02-06T13:52:44-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:45 music go-librespot[13580]: time="2026-02-06T13:52:45-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 06 13:52:45 music go-librespot[13580]: time="2026-02-06T13:52:45-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:45 music go-librespot[13580]: time="2026-02-06T13:52:45-05:00" level=debug msg="completed challenge" Feb 06 13:52:45 music go-librespot[13580]: time="2026-02-06T13:52:45-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:45 music volumio[13381]: info: CoreCommandRouter::volumioGetState Feb 06 13:52:45 music volumio[13381]: info: CorePlayQueue::getTrack 0 Feb 06 13:52:45 music mpd[13560]: 2026-02-06T13:52:45 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 06 13:52:45 music systemd[1]: Started mpd.service - Music Player Daemon. Feb 06 13:52:45 music sudo[13522]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:45 music sudo[13512]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:45 music volumio[13381]: info: Completed starting Core Plugins Feb 06 13:52:45 music volumio[13381]: info: ------------------------------------------- Feb 06 13:52:45 music volumio[13381]: info: ----- MyVolumio plugins startup ---- Feb 06 13:52:45 music volumio[13381]: info: ------------------------------------------- Feb 06 13:52:45 music volumio[13381]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 06 13:52:45 music volumio[13381]: error: MPD error: The expression evaluated to a falsy value: Feb 06 13:52:45 music volumio[13381]: assert.ok(self.idling) Feb 06 13:52:45 music volumio[13381]: error: The expression evaluated to a falsy value: Feb 06 13:52:45 music volumio[13381]: assert.ok(self.idling) Feb 06 13:52:45 music volumio[13381]: info: MPD running with PID13560 Feb 06 13:52:45 music volumio[13381]: ,establishing connection Feb 06 13:52:45 music volumio[13381]: error: updateQueue error: null Feb 06 13:52:45 music volumio[13381]: error: updateQueue error: null Feb 06 13:52:46 music go-librespot[13580]: time="2026-02-06T13:52:46-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 06 13:52:46 music go-librespot[13580]: time="2026-02-06T13:52:46-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:46 music go-librespot[13580]: time="2026-02-06T13:52:46-05:00" level=debug msg="completed challenge" Feb 06 13:52:46 music go-librespot[13580]: time="2026-02-06T13:52:46-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:46 music volumio[13381]: info: go-librespot daemon successfully initialized Feb 06 13:52:46 music sudo[13652]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 06 13:52:46 music sudo[13652]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:46 music sudo[13654]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 06 13:52:46 music sudo[13654]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:46 music sudo[13652]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:46 music sudo[13654]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:46 music sudo[13658]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 06 13:52:46 music sudo[13658]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:46 music sudo[13658]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:46 music volumio[13381]: info: Upmpdcli Daemon Started Feb 06 13:52:46 music go-librespot[13580]: time="2026-02-06T13:52:46-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 06 13:52:46 music go-librespot[13580]: time="2026-02-06T13:52:46-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:46 music go-librespot[13580]: time="2026-02-06T13:52:46-05:00" level=debug msg="completed challenge" Feb 06 13:52:47 music go-librespot[13580]: time="2026-02-06T13:52:47-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:47 music go-librespot[13580]: time="2026-02-06T13:52:47-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 06 13:52:47 music go-librespot[13580]: time="2026-02-06T13:52:47-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:47 music go-librespot[13580]: time="2026-02-06T13:52:47-05:00" level=debug msg="completed challenge" Feb 06 13:52:47 music go-librespot[13580]: time="2026-02-06T13:52:47-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:47 music go-librespot[13580]: time="2026-02-06T13:52:47-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:47 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 06 13:52:47 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 06 13:52:48 music sudo[13661]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 06 13:52:48 music sudo[13661]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:48 music sudo[13664]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 06 13:52:48 music sudo[13664]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:48 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 06 13:52:48 music systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 06 13:52:48 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 06 13:52:49 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 06 13:52:49 music mpd_monitor.sh[13666]: MPD Monitor Service: Starting MPD Monitor Service Feb 06 13:52:49 music sudo[13661]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:49 music volumio[13381]: info: Successfully started MPD Monitor Feb 06 13:52:49 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 06 13:52:49 music systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 06 13:52:49 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 06 13:52:49 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 06 13:52:49 music sudo[13664]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:49 music mpd_monitor.sh[13669]: MPD Monitor Service: Starting MPD Monitor Service Feb 06 13:52:49 music volumio[13381]: info: Successfully started MPD Monitor Feb 06 13:52:49 music volumio[13381]: info: Initializing connection to go-librespot Websocket Feb 06 13:52:49 music volumio[13381]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 06 13:52:50 music volumio[13381]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 06 13:52:51 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 06 13:52:51 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 06 13:52:51 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 06 13:52:51 music go-librespot[13673]: go-librespot daemon starting... Feb 06 13:52:51 music go-librespot[13674]: time="2026-02-06T13:52:51-05:00" level=info msg="running go-librespot 0.6.2" Feb 06 13:52:51 music go-librespot[13674]: time="2026-02-06T13:52:51-05:00" level=debug msg="app state loaded" Feb 06 13:52:51 music go-librespot[13674]: time="2026-02-06T13:52:51-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 06 13:52:51 music go-librespot[13674]: time="2026-02-06T13:52:51-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 06 13:52:51 music go-librespot[13674]: time="2026-02-06T13:52:51-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 06 13:52:51 music go-librespot[13674]: time="2026-02-06T13:52:51-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 06 13:52:51 music go-librespot[13674]: time="2026-02-06T13:52:51-05:00" level=info msg="zeroconf server listening on port 39523" Feb 06 13:52:51 music go-librespot[13674]: time="2026-02-06T13:52:51-05:00" level=debug msg="obtained new client token: AAC3GmrkgcFUIVqXcPAEIKYW8PRayxKUbWmLURzkyQ1Em36I3AH1T2MebinfTzFD9sBoWgvoXizvkceGO9/9HCFpkFI1N8GSJxa8re5oeEn3dqFWLjUE9ZPMrorgUClSlmt8JoJpXpBubwYPi59Knl5qrOtlmMemW8/xlwA6bSDvEKW5oHUDTnVCoCAjFRNCU9BB2WynPOPqTmHtKTJg5RehQgIM3sboS84r39tLql5YOYPsXVsOiJ4=" Feb 06 13:52:51 music go-librespot[13674]: time="2026-02-06T13:52:51-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 06 13:52:51 music go-librespot[13674]: time="2026-02-06T13:52:51-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:51 music go-librespot[13674]: time="2026-02-06T13:52:51-05:00" level=debug msg="completed challenge" Feb 06 13:52:51 music go-librespot[13674]: time="2026-02-06T13:52:51-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:52 music go-librespot[13674]: time="2026-02-06T13:52:52-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 06 13:52:52 music go-librespot[13674]: time="2026-02-06T13:52:52-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:52 music go-librespot[13674]: time="2026-02-06T13:52:52-05:00" level=debug msg="completed challenge" Feb 06 13:52:52 music go-librespot[13674]: time="2026-02-06T13:52:52-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:52 music volumio[13381]: info: Initializing connection to go-librespot Websocket Feb 06 13:52:52 music go-librespot[13674]: time="2026-02-06T13:52:52-05:00" level=debug msg="new websocket client" Feb 06 13:52:52 music volumio[13381]: info: Connection to go-librespot Websocket established Feb 06 13:52:53 music go-librespot[13674]: time="2026-02-06T13:52:53-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 06 13:52:53 music go-librespot[13674]: time="2026-02-06T13:52:53-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:53 music go-librespot[13674]: time="2026-02-06T13:52:53-05:00" level=debug msg="completed challenge" Feb 06 13:52:53 music go-librespot[13674]: time="2026-02-06T13:52:53-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:54 music go-librespot[13674]: time="2026-02-06T13:52:54-05:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 06 13:52:54 music volumio[13381]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 06 13:52:54 music volumio[13381]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 06 13:52:54 music volumio[13381]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 06 13:52:54 music volumio[13381]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 06 13:52:54 music volumio[13381]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 06 13:52:54 music volumio[13381]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 06 13:52:54 music volumio[13381]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 06 13:52:54 music volumio[13381]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 06 13:52:54 music volumio[13381]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 06 13:52:54 music volumio[13381]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 06 13:52:54 music volumio[13381]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 06 13:52:54 music volumio[13381]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 06 13:52:54 music volumio[13381]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 06 13:52:54 music volumio[13381]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 06 13:52:54 music volumio[13381]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 06 13:52:54 music volumio[13381]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 06 13:52:54 music volumio[13381]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 06 13:52:54 music volumio[13381]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 06 13:52:54 music volumio[13381]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 06 13:52:54 music volumio[13381]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 06 13:52:54 music volumio[13381]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 06 13:52:54 music volumio[13381]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 06 13:52:54 music volumio[13381]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 06 13:52:54 music volumio[13381]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 06 13:52:54 music volumio[13381]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 06 13:52:54 music volumio[13381]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 06 13:52:54 music volumio[13381]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 06 13:52:54 music volumio[13381]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 06 13:52:54 music volumio[13381]: info: Adding plugin bluetooth to MyMusic Plugins Feb 06 13:52:54 music volumio[13381]: info: Adding plugin multiroom to MyMusic Plugins Feb 06 13:52:54 music volumio[13381]: info: Adding plugin metavolumio to MyMusic Plugins Feb 06 13:52:54 music volumio[13381]: info: Adding plugin cd_controller to MyMusic Plugins Feb 06 13:52:54 music volumio[13381]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 06 13:52:54 music volumio[13381]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 06 13:52:54 music volumio[13381]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 06 13:52:54 music volumio[13381]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 06 13:52:54 music go-librespot[13674]: time="2026-02-06T13:52:54-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:54 music go-librespot[13674]: time="2026-02-06T13:52:54-05:00" level=debug msg="completed challenge" Feb 06 13:52:54 music go-librespot[13674]: time="2026-02-06T13:52:54-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:55 music volumio[13381]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 06 13:52:55 music volumio[13381]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 06 13:52:55 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:52:55 music volumio[13381]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:52:55 music volumio[13381]: info: Starting MyVolumio Remote Streaming Endpoints Feb 06 13:52:55 music volumio[13381]: info: MyVolumio login type: Token Feb 06 13:52:55 music volumio[13381]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 06 13:52:55 music volumio[13381]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 06 13:52:55 music go-librespot[13674]: time="2026-02-06T13:52:55-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 06 13:52:55 music go-librespot[13674]: time="2026-02-06T13:52:55-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:55 music go-librespot[13674]: time="2026-02-06T13:52:55-05:00" level=debug msg="completed challenge" Feb 06 13:52:55 music go-librespot[13674]: time="2026-02-06T13:52:55-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:56 music volumio[13381]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 06 13:52:56 music volumio[13381]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 06 13:52:56 music volumio[13381]: info: Streaming services startup Feb 06 13:52:56 music volumio[13381]: info: Starting Streaming Daemon Feb 06 13:52:56 music go-librespot[13674]: time="2026-02-06T13:52:56-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 06 13:52:56 music sudo[13685]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 06 13:52:56 music sudo[13685]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:56 music volumio[13381]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 06 13:52:56 music sudo[13685]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:56 music volumio[13381]: info: Getting Spotify volume Feb 06 13:52:56 music volumio[13381]: error: Cannot start Volumio Streaming Daemon Feb 06 13:52:56 music volumio[13381]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 06 13:52:56 music volumio[13381]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 06 13:52:56 music volumio[13381]: info: CoreCommandRouter::volumioGetState Feb 06 13:52:56 music volumio[13381]: info: CorePlayQueue::getTrack 0 Feb 06 13:52:56 music volumio[13381]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 06 13:52:56 music volumio[13381]: info: Listing playlists Feb 06 13:52:56 music volumio[13381]: info: Listing playlists Feb 06 13:52:56 music volumio[13381]: info: CoreCommandRouter::volumioGetState Feb 06 13:52:56 music volumio[13381]: info: CorePlayQueue::getTrack 0 Feb 06 13:52:56 music volumio[13381]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Feb 06 13:52:56 music volumio[13381]: SPOTIFY: SPOTIFY VOLUME undefined Feb 06 13:52:56 music volumio[13381]: SPOTIFY: VOLUMIO VOLUME 86 Feb 06 13:52:56 music volumio[13381]: info: Aligning Spotify Volume to Volumio Volume Feb 06 13:52:56 music volumio[13381]: info: CoreCommandRouter::volumioGetState Feb 06 13:52:56 music volumio[13381]: info: CorePlayQueue::getTrack 0 Feb 06 13:52:56 music volumio[13381]: info: Setting Spotify Volume from Volumio: 86 Feb 06 13:52:56 music volumio[13381]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 06 13:52:56 music go-librespot[13674]: time="2026-02-06T13:52:56-05:00" level=debug msg="completed keyexchange" Feb 06 13:52:56 music go-librespot[13674]: time="2026-02-06T13:52:56-05:00" level=debug msg="completed challenge" Feb 06 13:52:56 music go-librespot[13674]: time="2026-02-06T13:52:56-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:56 music go-librespot[13674]: time="2026-02-06T13:52:56-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:52:56 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 06 13:52:56 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 06 13:52:56 music volumio[13381]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 06 13:52:56 music volumio[13381]: Error: socket hang up Feb 06 13:52:56 music volumio[13381]: at connResetException (node:internal/errors:720:14) Feb 06 13:52:56 music volumio[13381]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 06 13:52:56 music volumio[13381]: at Socket.emit (node:events:526:35) Feb 06 13:52:56 music volumio[13381]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 06 13:52:56 music volumio[13381]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 06 13:52:56 music volumio[13381]: code: 'ECONNRESET', Feb 06 13:52:56 music volumio[13381]: response: undefined Feb 06 13:52:56 music volumio[13381]: } Feb 06 13:52:56 music volumio[13381]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 06 13:52:57 music sudo[13719]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-06 13:51' Feb 06 13:52:57 music sudo[13719]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:52:57 music sudo[13719]: pam_unix(sudo:session): session closed for user root Feb 06 13:52:58 music volumio-remote-updater[31331]: [2026-02-06 13:52:58] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 06 13:52:58 music systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 06 13:52:58 music volumio-remote-updater[31331]: [2026-02-06 13:52:58] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 06 13:52:58 music systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 06 13:52:58 music systemd[1]: volumio.service: Consumed 26.999s CPU time. Feb 06 13:52:58 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 06 13:52:58 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 06 13:52:58 music systemd[1]: volumio.service: Scheduled restart job, restart counter is at 48077. Feb 06 13:52:58 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 06 13:52:58 music systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 06 13:52:58 music systemd[1]: volumio.service: Consumed 26.999s CPU time. Feb 06 13:52:58 music systemd[1]: Started volumio.service - Volumio Backend Module. Feb 06 13:52:58 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 06 13:53:00 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 06 13:53:00 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 06 13:53:00 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 06 13:53:00 music go-librespot[13748]: go-librespot daemon starting... Feb 06 13:53:00 music go-librespot[13749]: time="2026-02-06T13:53:00-05:00" level=info msg="running go-librespot 0.6.2" Feb 06 13:53:00 music go-librespot[13749]: time="2026-02-06T13:53:00-05:00" level=debug msg="app state loaded" Feb 06 13:53:00 music go-librespot[13749]: time="2026-02-06T13:53:00-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 06 13:53:00 music volumio[13733]: info: ------------------------------------------- Feb 06 13:53:00 music volumio[13733]: info: ----- Volumio3 ---- Feb 06 13:53:00 music volumio[13733]: info: ------------------------------------------- Feb 06 13:53:00 music volumio[13733]: info: ----- System startup ---- Feb 06 13:53:00 music volumio[13733]: info: ------------------------------------------- Feb 06 13:53:00 music go-librespot[13749]: time="2026-02-06T13:53:00-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 06 13:53:00 music go-librespot[13749]: time="2026-02-06T13:53:00-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 06 13:53:00 music go-librespot[13749]: time="2026-02-06T13:53:00-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 06 13:53:00 music go-librespot[13749]: time="2026-02-06T13:53:00-05:00" level=info msg="zeroconf server listening on port 36045" Feb 06 13:53:00 music go-librespot[13749]: time="2026-02-06T13:53:00-05:00" level=debug msg="obtained new client token: AABQ3hgrAs9E3OF890qGZAk2tiTxcu6Gn/D+wcwsHfFJq15z+b6xbE1WaospJHh3hbMr9l7yHqQS2yAwdx4t3iPHbIaCMsufj/d8I1Amre0Eox48dtT7DN1EteDVWu6+Lbl9pWgnUjn2PERsDbPvIgsHQKTUKqiZnMV1hP1uss8GjHpaZwQgA+B5nnZXLacLDo4Pjv0buf0cxyy1DsUexGjY8D0n5IG/XBFQiZ4x+soe6wNfc8lD950=" Feb 06 13:53:00 music go-librespot[13749]: time="2026-02-06T13:53:00-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 06 13:53:00 music go-librespot[13749]: time="2026-02-06T13:53:00-05:00" level=debug msg="completed keyexchange" Feb 06 13:53:00 music go-librespot[13749]: time="2026-02-06T13:53:00-05:00" level=debug msg="completed challenge" Feb 06 13:53:00 music go-librespot[13749]: time="2026-02-06T13:53:00-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:01 music volumio[13733]: info: MYVOLUMIO Environment detected Feb 06 13:53:01 music volumio[13733]: info: Plugin folders cleanup Feb 06 13:53:01 music volumio[13733]: info: Scanning into folder /volumio/app/plugins/ Feb 06 13:53:01 music volumio[13733]: info: Scanning category audio_interface Feb 06 13:53:01 music volumio[13733]: info: Scanning category miscellanea Feb 06 13:53:01 music volumio[13733]: info: Scanning category music_service Feb 06 13:53:01 music volumio[13733]: info: Scanning category plugins.json Feb 06 13:53:01 music volumio[13733]: info: Scanning category system_controller Feb 06 13:53:01 music volumio[13733]: info: Scanning category user_interface Feb 06 13:53:01 music volumio[13733]: info: Scanning into folder /data/plugins/ Feb 06 13:53:01 music volumio[13733]: info: Scanning category music_service Feb 06 13:53:01 music volumio[13733]: info: Plugin folders cleanup completed Feb 06 13:53:01 music volumio[13733]: info: ------------------------------------------- Feb 06 13:53:01 music volumio[13733]: info: ----- Core plugins startup ---- Feb 06 13:53:01 music volumio[13733]: info: ------------------------------------------- Feb 06 13:53:01 music volumio[13733]: info: Loading plugins from folder /volumio/app/plugins/ Feb 06 13:53:01 music volumio[13733]: info: Adding plugin upnp to MyMusic Plugins Feb 06 13:53:01 music volumio[13733]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 06 13:53:01 music volumio[13733]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 06 13:53:01 music volumio[13733]: info: Loading plugins from folder /data/plugins/ Feb 06 13:53:01 music volumio[13733]: info: Loading plugin "system"... Feb 06 13:53:01 music volumio[13733]: info: Loading plugin "appearance"... Feb 06 13:53:01 music go-librespot[13749]: time="2026-02-06T13:53:01-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 06 13:53:01 music go-librespot[13749]: time="2026-02-06T13:53:01-05:00" level=debug msg="completed keyexchange" Feb 06 13:53:01 music go-librespot[13749]: time="2026-02-06T13:53:01-05:00" level=debug msg="completed challenge" Feb 06 13:53:01 music go-librespot[13749]: time="2026-02-06T13:53:01-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:02 music go-librespot[13749]: time="2026-02-06T13:53:02-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:80, retrying with a different AP" error="dial tcp 34.158.255.62:80: connect: connection refused" Feb 06 13:53:02 music go-librespot[13749]: time="2026-02-06T13:53:02-05:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 06 13:53:02 music volumio[13733]: info: Loading plugin "network"... Feb 06 13:53:02 music volumio[13733]: info: Refreshing Cached IP Addresses Feb 06 13:53:02 music sudo[13771]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 06 13:53:02 music sudo[13771]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:53:02 music sudo[13773]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 06 13:53:02 music sudo[13771]: pam_unix(sudo:session): session closed for user root Feb 06 13:53:02 music sudo[13773]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:53:02 music volumio[13733]: info: Loading plugin "services"... Feb 06 13:53:02 music sudo[13773]: pam_unix(sudo:session): session closed for user root Feb 06 13:53:02 music volumio[13733]: info: Loading plugin "alsa_controller"... Feb 06 13:53:02 music sudo[13781]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 06 13:53:02 music sudo[13781]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:53:02 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 06 13:53:02 music volumio[13733]: info: Loading plugin "wizard"... Feb 06 13:53:02 music volumio[13733]: info: Loading plugin "networkfs"... Feb 06 13:53:02 music go-librespot[13749]: time="2026-02-06T13:53:02-05:00" level=debug msg="completed keyexchange" Feb 06 13:53:02 music go-librespot[13749]: time="2026-02-06T13:53:02-05:00" level=debug msg="completed challenge" Feb 06 13:53:02 music volumio[13733]: info: Starting Udev Watcher for removable devices Feb 06 13:53:02 music volumio[13733]: info: Ignoring mount for partition: boot Feb 06 13:53:02 music volumio[13733]: info: Ignoring mount for partition: volumio Feb 06 13:53:02 music volumio[13733]: info: Ignoring mount for partition: volumio_data Feb 06 13:53:02 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 06 13:53:02 music volumio[13733]: info: Loading plugin "volumio_command_line_client"... Feb 06 13:53:02 music volumio[13733]: info: Loading plugin "upnp"... Feb 06 13:53:02 music volumio[13733]: info: [1770403982610] Starting Upmpd Daemon Feb 06 13:53:02 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 06 13:53:02 music volumio[13733]: info: Loading plugin "my_music"... Feb 06 13:53:02 music volumio[13733]: info: Loading plugin "mpd"... Feb 06 13:53:02 music go-librespot[13749]: time="2026-02-06T13:53:02-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:02 music volumio[13733]: info: Loading plugin "upnp_browser"... Feb 06 13:53:03 music volumio-remote-updater[31331]: [2026-02-06 13:53:03] [connect] Successful connection Feb 06 13:53:03 music sudo[13781]: pam_unix(sudo:session): session closed for user root Feb 06 13:53:03 music go-librespot[13749]: time="2026-02-06T13:53:03-05:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.65.9:443: connect: connection refused" Feb 06 13:53:03 music go-librespot[13749]: time="2026-02-06T13:53:03-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 06 13:53:03 music go-librespot[13749]: time="2026-02-06T13:53:03-05:00" level=debug msg="completed keyexchange" Feb 06 13:53:03 music go-librespot[13749]: time="2026-02-06T13:53:03-05:00" level=debug msg="completed challenge" Feb 06 13:53:03 music go-librespot[13749]: time="2026-02-06T13:53:03-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:04 music go-librespot[13749]: time="2026-02-06T13:53:04-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 06 13:53:04 music go-librespot[13749]: time="2026-02-06T13:53:04-05:00" level=debug msg="completed keyexchange" Feb 06 13:53:04 music go-librespot[13749]: time="2026-02-06T13:53:04-05:00" level=debug msg="completed challenge" Feb 06 13:53:04 music go-librespot[13749]: time="2026-02-06T13:53:04-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:04 music volumio[13733]: info: Starting UPNP Browser Feb 06 13:53:04 music volumio[13733]: info: Loading plugin "alarm-clock"... Feb 06 13:53:04 music volumio[13733]: info: Loading plugin "airplay_emulation"... Feb 06 13:53:04 music volumio[13733]: info: Starting Shairport Sync Feb 06 13:53:04 music volumio[13733]: info: Loading plugin "last_100"... Feb 06 13:53:04 music volumio[13733]: info: Loading plugin "webradio"... Feb 06 13:53:04 music volumio[13733]: info: Loading plugin "i2s_dacs"... Feb 06 13:53:04 music volumio[13733]: info: I2S DAC not set, start Auto-detection Feb 06 13:53:04 music volumio[13733]: info: Loading plugin "volumiodiscovery"... Feb 06 13:53:04 music volumio[13733]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 06 13:53:04 music volumio[13733]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 06 13:53:04 music volumio[13733]: *** WARNING *** For more information see Feb 06 13:53:04 music volumio[13733]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 06 13:53:04 music volumio[13733]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 06 13:53:04 music volumio[13733]: *** WARNING *** For more information see Feb 06 13:53:04 music node[13733]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 06 13:53:04 music node[13733]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 06 13:53:04 music node[13733]: *** WARNING *** For more information see Feb 06 13:53:04 music node[13733]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 06 13:53:04 music node[13733]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 06 13:53:04 music node[13733]: *** WARNING *** For more information see Feb 06 13:53:04 music volumio[13733]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 06 13:53:04 music volumio[13733]: info: Discovery: Started advertising with name: music Feb 06 13:53:04 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 06 13:53:04 music volumio[13733]: info: Loading plugin "spop"... Feb 06 13:53:05 music go-librespot[13749]: time="2026-02-06T13:53:05-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.255.62:443: connect: connection refused" Feb 06 13:53:05 music go-librespot[13749]: time="2026-02-06T13:53:05-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 06 13:53:05 music go-librespot[13749]: time="2026-02-06T13:53:05-05:00" level=debug msg="completed keyexchange" Feb 06 13:53:05 music go-librespot[13749]: time="2026-02-06T13:53:05-05:00" level=debug msg="completed challenge" Feb 06 13:53:05 music go-librespot[13749]: time="2026-02-06T13:53:05-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:05 music go-librespot[13749]: time="2026-02-06T13:53:05-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:05 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 06 13:53:05 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 06 13:53:06 music volumio[13733]: info: Loading plugin "outputs"... Feb 06 13:53:06 music volumio[13733]: info: Loading plugin "albumart"... Feb 06 13:53:06 music volumio[13733]: info: Plugin example_plugin is not enabled Feb 06 13:53:06 music volumio[13733]: info: Loading plugin "inputs"... Feb 06 13:53:06 music volumio[13733]: info: Loading plugin "updater_comm"... Feb 06 13:53:06 music volumio[13733]: info: Plugin mpdemulation is not enabled Feb 06 13:53:06 music volumio[13733]: info: Loading plugin "rest_api"... Feb 06 13:53:06 music volumio[13733]: info: Loading plugin "websocket"... Feb 06 13:53:06 music volumio[13733]: info: Starting Socket.io Server version 1.7.4 Feb 06 13:53:06 music volumio[13733]: info: Loading i18n strings for locale en Feb 06 13:53:06 music volumio[13733]: Updating browse sources language Feb 06 13:53:06 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 06 13:53:06 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 06 13:53:06 music volumio[13733]: info: CoreCommandRouter::initPlayerControls Feb 06 13:53:06 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:06 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:06 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:06 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:06 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:06 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:06 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:06 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:06 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 06 13:53:06 music volumio[13733]: Express server listening on port 3000 Feb 06 13:53:06 music volumio[13733]: [Metrics] WebUI: 6s 638.87ms Feb 06 13:53:06 music volumio[13733]: info: CoreStateMachine::resetVolumioState Feb 06 13:53:06 music volumio[13733]: info: CoreStateMachine::getcurrentVolume Feb 06 13:53:06 music volumio[13733]: info: CoreCommandRouter::volumioRetrievevolume Feb 06 13:53:06 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:53:06 music volumio[13733]: info: Volumio Network Manager: Network status updated: 1 Feb 06 13:53:06 music volumio-remote-updater[31331]: [2026-02-06 13:53:06] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770403983 101 Feb 06 13:53:06 music volumio[13806]: Forking 3 albumart workers Feb 06 13:53:06 music volumio[13733]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 06 13:53:06 music volumio[13733]: info: VolumeController:: Volume=86 Mute =false Feb 06 13:53:06 music volumio[13733]: info: CoreStateMachine::pushState Feb 06 13:53:06 music volumio[13733]: info: CorePlayQueue::getTrack 0 Feb 06 13:53:06 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 06 13:53:06 music volumio[13733]: info: CoreCommandRouter::volumioPushState Feb 06 13:53:06 music volumio[13733]: info: CoreStateMachine::updateTrackBlock Feb 06 13:53:06 music volumio[13733]: info: CorePlayQueue::getTrackBlock Feb 06 13:53:06 music volumio[13733]: info: CoreCommandRouter::volumioRetrievevolume Feb 06 13:53:06 music volumio[13733]: info: Reloading queue from file Feb 06 13:53:06 music volumio[13733]: info: CoreCommandRouter::volumioGetState Feb 06 13:53:06 music volumio[13733]: info: CorePlayQueue::getTrack 0 Feb 06 13:53:06 music volumio[13733]: info: Setting Device type: Raspberry PI Feb 06 13:53:06 music volumio[13733]: info: CoreStateMachine::setRepeat null single undefined Feb 06 13:53:06 music volumio[13733]: info: CoreStateMachine::pushState Feb 06 13:53:06 music volumio[13733]: info: CorePlayQueue::getTrack 0 Feb 06 13:53:06 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 06 13:53:06 music volumio[13733]: info: CoreCommandRouter::volumioPushState Feb 06 13:53:06 music volumio[13733]: info: CoreStateMachine::setRandom null Feb 06 13:53:06 music volumio[13733]: info: CoreStateMachine::pushState Feb 06 13:53:06 music volumio[13733]: info: CorePlayQueue::getTrack 0 Feb 06 13:53:06 music volumio[13733]: info: CoreCommandRouter::volumioPushState Feb 06 13:53:06 music volumio[13733]: info: VolumeController:: Volume=86 Mute =false Feb 06 13:53:06 music volumio[13733]: info: CoreStateMachine::pushState Feb 06 13:53:06 music volumio[13733]: info: CorePlayQueue::getTrack 0 Feb 06 13:53:06 music volumio[13733]: info: CoreCommandRouter::volumioPushState Feb 06 13:53:06 music volumio[13733]: info: Completed loading Core Plugins Feb 06 13:53:06 music volumio[13733]: info: Preparing to generate the ALSA configuration file Feb 06 13:53:06 music volumio[13733]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 06 13:53:06 music volumio[13733]: info: Discovery: Found device music Feb 06 13:53:06 music volumio[13733]: info: CoreCommandRouter::volumioGetState Feb 06 13:53:06 music volumio[13733]: info: CorePlayQueue::getTrack 0 Feb 06 13:53:06 music volumio[13733]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 06 13:53:06 music volumio[13733]: info: Discovery: Found device music Feb 06 13:53:06 music volumio[13733]: info: CoreCommandRouter::volumioGetState Feb 06 13:53:06 music volumio[13733]: info: CorePlayQueue::getTrack 0 Feb 06 13:53:06 music volumio[13733]: info: Asound.conf file unchanged, so no further update is needed Feb 06 13:53:06 music volumio[13733]: info: Output device has changed, restarting MPD Feb 06 13:53:07 music volumio[13733]: info: Output device has changed, restarting Shairport Sync Feb 06 13:53:07 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:07 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:53:07 music sudo[13862]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 06 13:53:07 music sudo[13862]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:53:07 music sudo[13862]: pam_unix(sudo:session): session closed for user root Feb 06 13:53:07 music sudo[13864]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 06 13:53:07 music sudo[13864]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:53:07 music volumio[13733]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 06 13:53:07 music volumio[13733]: info: ___________ START PLUGINS ___________ Feb 06 13:53:07 music volumio[13733]: info: ControllerMpd::onStart: Initializing MPD Feb 06 13:53:07 music volumio[13733]: info: Creating MPD Configuration file Feb 06 13:53:07 music systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 06 13:53:07 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 06 13:53:07 music volumio[13733]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 06 13:53:07 music volumio[13733]: info: [1770403987167] CoreMusicLibrary::Adding element Media Servers Feb 06 13:53:07 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 06 13:53:07 music sudo[13872]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 06 13:53:07 music volumio[13733]: info: UPNP Browser: Client initialized successfully Feb 06 13:53:07 music sudo[13872]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:53:07 music sudo[13874]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 06 13:53:07 music sudo[13874]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:53:07 music sudo[13872]: pam_unix(sudo:session): session closed for user root Feb 06 13:53:07 music systemd[1]: mpd.service: Deactivated successfully. Feb 06 13:53:07 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 06 13:53:07 music systemd[1]: mpd.service: Consumed 4.136s CPU time. Feb 06 13:53:07 music systemd[1]: mpd.socket: Deactivated successfully. Feb 06 13:53:07 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 06 13:53:07 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 06 13:53:07 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:07 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:53:07 music volumio[13733]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 06 13:53:07 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:07 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:53:07 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 06 13:53:07 music volumio[13733]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 06 13:53:07 music volumio[13733]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 06 13:53:07 music volumio[13733]: info: [1770403987335] CoreMusicLibrary::Adding element Last_100 Feb 06 13:53:07 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 06 13:53:07 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 06 13:53:07 music volumio[13733]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 06 13:53:07 music volumio[13733]: info: [1770403987356] CoreMusicLibrary::Adding element Webradio Feb 06 13:53:07 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 06 13:53:07 music systemd[1]: mpd.service: Deactivated successfully. Feb 06 13:53:07 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 06 13:53:07 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 06 13:53:07 music systemd[1]: mpd.socket: Deactivated successfully. Feb 06 13:53:07 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 06 13:53:07 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 06 13:53:07 music volumio[13733]: info: Initializing BBC Radios Feb 06 13:53:07 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 06 13:53:07 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 06 13:53:07 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 06 13:53:07 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:53:07 music volumio[13733]: info: Creating Spotify config file Feb 06 13:53:07 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:07 music sudo[13891]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 06 13:53:07 music sudo[13891]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 06 13:53:07 music sudo[13891]: pam_unix(sudo:session): session closed for user root Feb 06 13:53:08 music volumio[13733]: info: Volumio Calling Home Feb 06 13:53:08 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 06 13:53:08 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 06 13:53:08 music go-librespot[13907]: go-librespot daemon starting... Feb 06 13:53:08 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 06 13:53:08 music go-librespot[13908]: time="2026-02-06T13:53:08-05:00" level=info msg="running go-librespot 0.6.2" Feb 06 13:53:08 music go-librespot[13908]: time="2026-02-06T13:53:08-05:00" level=debug msg="app state loaded" Feb 06 13:53:08 music volumio[13733]: info: MPD Permissions set Feb 06 13:53:08 music volumio[13733]: info: MPD Permissions set Feb 06 13:53:08 music go-librespot[13908]: time="2026-02-06T13:53:08-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 06 13:53:08 music volumio[13733]: info: Spotify config file written Feb 06 13:53:08 music sudo[13917]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 06 13:53:08 music sudo[13917]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:53:08 music volumio[13823]: Starting albumart workers Feb 06 13:53:08 music volumio[13733]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 06 13:53:08 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:08 music volumio[13825]: Starting albumart workers Feb 06 13:53:08 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:08 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:08 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:08 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:08 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:08 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:08 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:08 music systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Feb 06 13:53:08 music volumio[13824]: Starting albumart workers Feb 06 13:53:08 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:53:08 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 06 13:53:08 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:08 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:08 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 06 13:53:08 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 06 13:53:08 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:08 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:08 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:08 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:08 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:08 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:08 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 06 13:53:08 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:08 music go-librespot[13929]: go-librespot daemon starting... Feb 06 13:53:08 music sudo[13917]: pam_unix(sudo:session): session closed for user root Feb 06 13:53:09 music go-librespot[13932]: time="2026-02-06T13:53:09-05:00" level=info msg="running go-librespot 0.6.2" Feb 06 13:53:09 music go-librespot[13932]: time="2026-02-06T13:53:09-05:00" level=debug msg="app state loaded" Feb 06 13:53:09 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:53:09 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:09 music go-librespot[13932]: time="2026-02-06T13:53:09-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 06 13:53:09 music volumio[13733]: info: No need to fix Spotify hosts Feb 06 13:53:09 music go-librespot[13932]: time="2026-02-06T13:53:09-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Feb 06 13:53:09 music go-librespot[13932]: time="2026-02-06T13:53:09-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 06 13:53:09 music go-librespot[13932]: time="2026-02-06T13:53:09-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 06 13:53:09 music go-librespot[13932]: time="2026-02-06T13:53:09-05:00" level=info msg="zeroconf server listening on port 41169" Feb 06 13:53:09 music go-librespot[13932]: time="2026-02-06T13:53:09-05:00" level=debug msg="obtained new client token: AAC3wl+logu9j8CH1PLTnye7Dw0WlAoPPiTdiK+7R/AkcMJvA3RVKEZBoilAQ73nLHv7zsvf9t8DcVDpTFnR/rx8I/x02QZuUOYZXbmT9VBVCfUig8INKnxxO5sMlJHQtolrYHRUxCshK3Y2GgqJcVfTqKfUxKeRcAMLsSRMaTrKsX2pCDBGV4eJx76b+hKf9PTdsC+1+rIn8igjVmtarfSZNwKOY40g1MGLb8kmq/Lykmtz7lyIOFA=" Feb 06 13:53:09 music go-librespot[13932]: time="2026-02-06T13:53:09-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.255.62:4070: connect: connection refused" Feb 06 13:53:09 music go-librespot[13932]: time="2026-02-06T13:53:09-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 06 13:53:09 music go-librespot[13932]: time="2026-02-06T13:53:09-05:00" level=debug msg="completed keyexchange" Feb 06 13:53:09 music go-librespot[13932]: time="2026-02-06T13:53:09-05:00" level=debug msg="completed challenge" Feb 06 13:53:09 music go-librespot[13932]: time="2026-02-06T13:53:09-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:10 music volumio[13733]: info: Volumio called home Feb 06 13:53:10 music volumio[13733]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 06 13:53:10 music volumio[13733]: info: Starting Shairport Sync Feb 06 13:53:10 music volumio[13733]: info: Starting Shairport Sync Feb 06 13:53:10 music volumio[13733]: info: Starting Shairport Sync Feb 06 13:53:10 music sudo[13963]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 06 13:53:10 music sudo[13963]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:53:10 music sudo[13965]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 06 13:53:10 music sudo[13965]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:53:10 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 06 13:53:10 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 06 13:53:10 music sudo[13968]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 06 13:53:10 music sudo[13968]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:53:10 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 06 13:53:10 music systemd[1]: shairport-sync.service: Consumed 1.792s CPU time. Feb 06 13:53:10 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 06 13:53:10 music sudo[13963]: pam_unix(sudo:session): session closed for user root Feb 06 13:53:10 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 06 13:53:10 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 06 13:53:10 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 06 13:53:10 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 06 13:53:10 music go-librespot[13932]: time="2026-02-06T13:53:10-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 06 13:53:10 music sudo[13965]: pam_unix(sudo:session): session closed for user root Feb 06 13:53:10 music sudo[13968]: pam_unix(sudo:session): session closed for user root Feb 06 13:53:10 music go-librespot[13932]: time="2026-02-06T13:53:10-05:00" level=debug msg="completed keyexchange" Feb 06 13:53:10 music go-librespot[13932]: time="2026-02-06T13:53:10-05:00" level=debug msg="completed challenge" Feb 06 13:53:10 music go-librespot[13932]: time="2026-02-06T13:53:10-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:10 music volumio[13733]: info: Shairport-Sync Started Feb 06 13:53:10 music volumio[13733]: Error adding Membership: Error: addMembership EINVAL Feb 06 13:53:10 music volumio[13733]: info: Shairport-Sync Started Feb 06 13:53:10 music volumio[13733]: info: Shairport-Sync Started Feb 06 13:53:10 music volumio[13733]: info: CoreCommandRouter::volumioGetState Feb 06 13:53:10 music volumio[13733]: info: CorePlayQueue::getTrack 0 Feb 06 13:53:10 music systemd[1]: setdatetime-helper.service: Deactivated successfully. Feb 06 13:53:10 music systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Feb 06 13:53:10 music systemd[1]: setdatetime-helper.service: Consumed 1.301s CPU time. Feb 06 13:53:11 music go-librespot[13932]: time="2026-02-06T13:53:11-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 06 13:53:11 music go-librespot[13932]: time="2026-02-06T13:53:11-05:00" level=debug msg="completed keyexchange" Feb 06 13:53:11 music go-librespot[13932]: time="2026-02-06T13:53:11-05:00" level=debug msg="completed challenge" Feb 06 13:53:11 music go-librespot[13932]: time="2026-02-06T13:53:11-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:12 music go-librespot[13932]: time="2026-02-06T13:53:12-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 06 13:53:12 music mpd[13903]: 2026-02-06T13:53:12 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 06 13:53:12 music systemd[1]: Started mpd.service - Music Player Daemon. Feb 06 13:53:12 music sudo[13874]: pam_unix(sudo:session): session closed for user root Feb 06 13:53:12 music sudo[13864]: pam_unix(sudo:session): session closed for user root Feb 06 13:53:12 music volumio[13733]: info: Completed starting Core Plugins Feb 06 13:53:12 music volumio[13733]: info: ------------------------------------------- Feb 06 13:53:12 music volumio[13733]: info: ----- MyVolumio plugins startup ---- Feb 06 13:53:12 music volumio[13733]: info: ------------------------------------------- Feb 06 13:53:12 music volumio[13733]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 06 13:53:12 music volumio[13733]: error: MPD error: The expression evaluated to a falsy value: Feb 06 13:53:12 music volumio[13733]: assert.ok(self.idling) Feb 06 13:53:12 music volumio[13733]: error: The expression evaluated to a falsy value: Feb 06 13:53:12 music volumio[13733]: assert.ok(self.idling) Feb 06 13:53:12 music volumio[13733]: info: MPD running with PID13903 Feb 06 13:53:12 music volumio[13733]: ,establishing connection Feb 06 13:53:12 music volumio[13733]: error: updateQueue error: null Feb 06 13:53:12 music volumio[13733]: error: updateQueue error: null Feb 06 13:53:12 music go-librespot[13932]: time="2026-02-06T13:53:12-05:00" level=debug msg="completed keyexchange" Feb 06 13:53:12 music go-librespot[13932]: time="2026-02-06T13:53:12-05:00" level=debug msg="completed challenge" Feb 06 13:53:12 music go-librespot[13932]: time="2026-02-06T13:53:12-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:12 music sudo[14032]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 06 13:53:12 music sudo[14032]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:53:12 music sudo[14032]: pam_unix(sudo:session): session closed for user root Feb 06 13:53:12 music sudo[14034]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 06 13:53:12 music sudo[14034]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:53:12 music sudo[14034]: pam_unix(sudo:session): session closed for user root Feb 06 13:53:12 music sudo[14037]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 06 13:53:12 music sudo[14037]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:53:12 music sudo[14037]: pam_unix(sudo:session): session closed for user root Feb 06 13:53:12 music volumio[13733]: info: Upmpdcli Daemon Started Feb 06 13:53:13 music volumio[13733]: info: go-librespot daemon successfully initialized Feb 06 13:53:13 music go-librespot[13932]: time="2026-02-06T13:53:13-05:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:80, retrying with a different AP" error="dial tcp 104.199.65.9:80: connect: connection refused" Feb 06 13:53:13 music go-librespot[13932]: time="2026-02-06T13:53:13-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 06 13:53:13 music go-librespot[13932]: time="2026-02-06T13:53:13-05:00" level=debug msg="completed keyexchange" Feb 06 13:53:13 music go-librespot[13932]: time="2026-02-06T13:53:13-05:00" level=debug msg="completed challenge" Feb 06 13:53:13 music go-librespot[13932]: time="2026-02-06T13:53:13-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:13 music go-librespot[13932]: time="2026-02-06T13:53:13-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 06 13:53:13 music go-librespot[13932]: time="2026-02-06T13:53:13-05:00" level=debug msg="completed keyexchange" Feb 06 13:53:13 music go-librespot[13932]: time="2026-02-06T13:53:13-05:00" level=debug msg="completed challenge" Feb 06 13:53:14 music go-librespot[13932]: time="2026-02-06T13:53:14-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:14 music go-librespot[13932]: time="2026-02-06T13:53:14-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:14 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 06 13:53:14 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 06 13:53:15 music sudo[14041]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 06 13:53:15 music sudo[14041]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:53:15 music sudo[14044]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 06 13:53:15 music sudo[14044]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:53:15 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 06 13:53:15 music systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 06 13:53:15 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 06 13:53:15 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 06 13:53:15 music sudo[14041]: pam_unix(sudo:session): session closed for user root Feb 06 13:53:15 music mpd_monitor.sh[14046]: MPD Monitor Service: Starting MPD Monitor Service Feb 06 13:53:15 music volumio[13733]: info: Successfully started MPD Monitor Feb 06 13:53:15 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 06 13:53:15 music systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 06 13:53:15 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 06 13:53:15 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 06 13:53:15 music sudo[14044]: pam_unix(sudo:session): session closed for user root Feb 06 13:53:15 music mpd_monitor.sh[14049]: MPD Monitor Service: Starting MPD Monitor Service Feb 06 13:53:15 music volumio[13733]: info: Successfully started MPD Monitor Feb 06 13:53:15 music volumio[13733]: info: CoreCommandRouter::volumioGetState Feb 06 13:53:15 music volumio[13733]: info: CorePlayQueue::getTrack 0 Feb 06 13:53:15 music volumio[13733]: info: Listing playlists Feb 06 13:53:15 music volumio[13733]: info: Listing playlists Feb 06 13:53:16 music volumio[13733]: info: Initializing connection to go-librespot Websocket Feb 06 13:53:16 music volumio[13733]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 06 13:53:17 music volumio[13733]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 06 13:53:17 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 06 13:53:17 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 06 13:53:17 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 06 13:53:17 music go-librespot[14053]: go-librespot daemon starting... Feb 06 13:53:17 music go-librespot[14054]: time="2026-02-06T13:53:17-05:00" level=info msg="running go-librespot 0.6.2" Feb 06 13:53:17 music go-librespot[14054]: time="2026-02-06T13:53:17-05:00" level=debug msg="app state loaded" Feb 06 13:53:17 music go-librespot[14054]: time="2026-02-06T13:53:17-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 06 13:53:17 music go-librespot[14054]: time="2026-02-06T13:53:17-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Feb 06 13:53:17 music go-librespot[14054]: time="2026-02-06T13:53:17-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 06 13:53:17 music go-librespot[14054]: time="2026-02-06T13:53:17-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 06 13:53:17 music go-librespot[14054]: time="2026-02-06T13:53:17-05:00" level=info msg="zeroconf server listening on port 37217" Feb 06 13:53:17 music go-librespot[14054]: time="2026-02-06T13:53:17-05:00" level=debug msg="obtained new client token: AABO3OqiAGiDMBgqe2km5/VgiW7t2s+DpX1ByVceMpoWsyH0X/Si+7/NOrxvfV76qKDMu3CUv0qfL1MDRHK86MvPAKvw7zQUjI/WiqxEkYaCcg+CYBKc3+FRju/QpsTzp6phsEq3GNi1WOQn+7DgrGpT7RYCdRNwzMDIJXMOH3QSfs2VGhSo3HVwwhxGbu8M6005IPUcZKqL1c5IuHMeFD5sKEQr4nI91RXIPFGu0YgIiGQfnEsAhV0=" Feb 06 13:53:17 music go-librespot[14054]: time="2026-02-06T13:53:17-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 06 13:53:18 music go-librespot[14054]: time="2026-02-06T13:53:18-05:00" level=debug msg="completed keyexchange" Feb 06 13:53:18 music go-librespot[14054]: time="2026-02-06T13:53:18-05:00" level=debug msg="completed challenge" Feb 06 13:53:18 music go-librespot[14054]: time="2026-02-06T13:53:18-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:18 music go-librespot[14054]: time="2026-02-06T13:53:18-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 06 13:53:18 music go-librespot[14054]: time="2026-02-06T13:53:18-05:00" level=debug msg="completed keyexchange" Feb 06 13:53:18 music go-librespot[14054]: time="2026-02-06T13:53:18-05:00" level=debug msg="completed challenge" Feb 06 13:53:18 music go-librespot[14054]: time="2026-02-06T13:53:18-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:19 music volumio[13733]: info: Initializing connection to go-librespot Websocket Feb 06 13:53:19 music go-librespot[14054]: time="2026-02-06T13:53:19-05:00" level=debug msg="new websocket client" Feb 06 13:53:19 music volumio[13733]: info: Connection to go-librespot Websocket established Feb 06 13:53:19 music go-librespot[14054]: time="2026-02-06T13:53:19-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 06 13:53:19 music go-librespot[14054]: time="2026-02-06T13:53:19-05:00" level=debug msg="completed keyexchange" Feb 06 13:53:19 music go-librespot[14054]: time="2026-02-06T13:53:19-05:00" level=debug msg="completed challenge" Feb 06 13:53:19 music go-librespot[14054]: time="2026-02-06T13:53:19-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:20 music go-librespot[14054]: time="2026-02-06T13:53:20-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 06 13:53:20 music go-librespot[14054]: time="2026-02-06T13:53:20-05:00" level=debug msg="completed keyexchange" Feb 06 13:53:20 music go-librespot[14054]: time="2026-02-06T13:53:20-05:00" level=debug msg="completed challenge" Feb 06 13:53:20 music go-librespot[14054]: time="2026-02-06T13:53:20-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:20 music volumio[13733]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 06 13:53:20 music volumio[13733]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 06 13:53:20 music volumio[13733]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 06 13:53:20 music volumio[13733]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 06 13:53:20 music volumio[13733]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 06 13:53:20 music volumio[13733]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 06 13:53:20 music volumio[13733]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 06 13:53:20 music volumio[13733]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 06 13:53:20 music volumio[13733]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 06 13:53:20 music volumio[13733]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 06 13:53:20 music volumio[13733]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 06 13:53:20 music volumio[13733]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 06 13:53:20 music volumio[13733]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 06 13:53:20 music volumio[13733]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 06 13:53:20 music volumio[13733]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 06 13:53:20 music volumio[13733]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 06 13:53:20 music volumio[13733]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 06 13:53:20 music volumio[13733]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 06 13:53:20 music volumio[13733]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 06 13:53:20 music volumio[13733]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 06 13:53:20 music volumio[13733]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 06 13:53:20 music volumio[13733]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 06 13:53:20 music volumio[13733]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 06 13:53:20 music volumio[13733]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 06 13:53:20 music volumio[13733]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 06 13:53:20 music volumio[13733]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 06 13:53:20 music volumio[13733]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 06 13:53:20 music volumio[13733]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 06 13:53:20 music volumio[13733]: info: Adding plugin bluetooth to MyMusic Plugins Feb 06 13:53:20 music volumio[13733]: info: Adding plugin multiroom to MyMusic Plugins Feb 06 13:53:20 music volumio[13733]: info: Adding plugin metavolumio to MyMusic Plugins Feb 06 13:53:20 music volumio[13733]: info: Adding plugin cd_controller to MyMusic Plugins Feb 06 13:53:20 music volumio[13733]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 06 13:53:20 music volumio[13733]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 06 13:53:20 music volumio[13733]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 06 13:53:20 music volumio[13733]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 06 13:53:20 music go-librespot[14054]: time="2026-02-06T13:53:20-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 06 13:53:21 music go-librespot[14054]: time="2026-02-06T13:53:21-05:00" level=debug msg="completed keyexchange" Feb 06 13:53:21 music go-librespot[14054]: time="2026-02-06T13:53:21-05:00" level=debug msg="completed challenge" Feb 06 13:53:21 music volumio[13733]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 06 13:53:21 music volumio[13733]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 06 13:53:21 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:53:21 music volumio[13733]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:53:21 music volumio[13733]: info: Starting MyVolumio Remote Streaming Endpoints Feb 06 13:53:21 music volumio[13733]: info: MyVolumio login type: Token Feb 06 13:53:21 music volumio[13733]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 06 13:53:21 music volumio[13733]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 06 13:53:21 music go-librespot[14054]: time="2026-02-06T13:53:21-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:22 music go-librespot[14054]: time="2026-02-06T13:53:22-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 06 13:53:22 music volumio[13733]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 06 13:53:22 music volumio[13733]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 06 13:53:22 music volumio[13733]: info: Streaming services startup Feb 06 13:53:22 music volumio[13733]: info: Starting Streaming Daemon Feb 06 13:53:22 music sudo[14064]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 06 13:53:22 music sudo[14064]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:53:22 music volumio[13733]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 06 13:53:22 music go-librespot[14054]: time="2026-02-06T13:53:22-05:00" level=debug msg="completed keyexchange" Feb 06 13:53:22 music go-librespot[14054]: time="2026-02-06T13:53:22-05:00" level=debug msg="completed challenge" Feb 06 13:53:22 music sudo[14064]: pam_unix(sudo:session): session closed for user root Feb 06 13:53:22 music volumio[13733]: info: Getting Spotify volume Feb 06 13:53:22 music volumio[13733]: error: Cannot start Volumio Streaming Daemon Feb 06 13:53:22 music volumio[13733]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 06 13:53:22 music volumio[13733]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 06 13:53:22 music go-librespot[14054]: time="2026-02-06T13:53:22-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:22 music go-librespot[14054]: time="2026-02-06T13:53:22-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:22 music volumio[13733]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 06 13:53:22 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 06 13:53:22 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 06 13:53:22 music volumio[13733]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 06 13:53:22 music volumio[13733]: Error: socket hang up Feb 06 13:53:22 music volumio[13733]: at connResetException (node:internal/errors:720:14) Feb 06 13:53:22 music volumio[13733]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 06 13:53:22 music volumio[13733]: at Socket.emit (node:events:526:35) Feb 06 13:53:22 music volumio[13733]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 06 13:53:22 music volumio[13733]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 06 13:53:22 music volumio[13733]: code: 'ECONNRESET', Feb 06 13:53:22 music volumio[13733]: response: undefined Feb 06 13:53:22 music volumio[13733]: } Feb 06 13:53:22 music volumio[13733]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 06 13:53:23 music sudo[14098]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-06 13:52' Feb 06 13:53:23 music sudo[14098]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:53:23 music sudo[14098]: pam_unix(sudo:session): session closed for user root Feb 06 13:53:23 music volumio-remote-updater[31331]: [2026-02-06 13:53:23] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 06 13:53:23 music volumio-remote-updater[31331]: [2026-02-06 13:53:23] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 06 13:53:23 music systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 06 13:53:23 music systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 06 13:53:23 music systemd[1]: volumio.service: Consumed 26.735s CPU time. Feb 06 13:53:23 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 06 13:53:23 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 06 13:53:24 music systemd[1]: volumio.service: Scheduled restart job, restart counter is at 48078. Feb 06 13:53:24 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 06 13:53:24 music systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 06 13:53:24 music systemd[1]: volumio.service: Consumed 26.735s CPU time. Feb 06 13:53:24 music systemd[1]: Started volumio.service - Volumio Backend Module. Feb 06 13:53:24 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 06 13:53:25 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 06 13:53:25 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 06 13:53:25 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 06 13:53:25 music go-librespot[14125]: go-librespot daemon starting... Feb 06 13:53:25 music go-librespot[14126]: time="2026-02-06T13:53:25-05:00" level=info msg="running go-librespot 0.6.2" Feb 06 13:53:25 music go-librespot[14126]: time="2026-02-06T13:53:25-05:00" level=debug msg="app state loaded" Feb 06 13:53:25 music go-librespot[14126]: time="2026-02-06T13:53:25-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 06 13:53:26 music volumio[14110]: info: ------------------------------------------- Feb 06 13:53:26 music volumio[14110]: info: ----- Volumio3 ---- Feb 06 13:53:26 music volumio[14110]: info: ------------------------------------------- Feb 06 13:53:26 music volumio[14110]: info: ----- System startup ---- Feb 06 13:53:26 music volumio[14110]: info: ------------------------------------------- Feb 06 13:53:26 music go-librespot[14126]: time="2026-02-06T13:53:26-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Feb 06 13:53:26 music go-librespot[14126]: time="2026-02-06T13:53:26-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 06 13:53:26 music go-librespot[14126]: time="2026-02-06T13:53:26-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 06 13:53:26 music go-librespot[14126]: time="2026-02-06T13:53:26-05:00" level=info msg="zeroconf server listening on port 40547" Feb 06 13:53:26 music go-librespot[14126]: time="2026-02-06T13:53:26-05:00" level=debug msg="obtained new client token: AADtAlZhPLYlbSxZ/IGS9D8ALJ8rEh3drPf/13W8/7qgiWUgmdZQHLW5QpBPVGxGkNghPQvAJzuyMn7vM9TkUbuW0LMvMAD0VSvPCkifoElfuiQlL6AChrgwWh1zWRZzVxt8UAdVWHVTJgQIutjsYS8ote3giyWPUxRUWYeZXXm4dWOnk1yV8Cf2ex5lrTzQbr0AcxN9OQ2WKilsuriuLrauDtXTOzbKgn7s4xqzo3c7EejH1ThM4Mc=" Feb 06 13:53:26 music go-librespot[14126]: time="2026-02-06T13:53:26-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 06 13:53:26 music go-librespot[14126]: time="2026-02-06T13:53:26-05:00" level=debug msg="completed keyexchange" Feb 06 13:53:26 music go-librespot[14126]: time="2026-02-06T13:53:26-05:00" level=debug msg="completed challenge" Feb 06 13:53:26 music go-librespot[14126]: time="2026-02-06T13:53:26-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:26 music volumio[14110]: info: MYVOLUMIO Environment detected Feb 06 13:53:27 music volumio[14110]: info: Plugin folders cleanup Feb 06 13:53:27 music volumio[14110]: info: Scanning into folder /volumio/app/plugins/ Feb 06 13:53:27 music volumio[14110]: info: Scanning category audio_interface Feb 06 13:53:27 music volumio[14110]: info: Scanning category miscellanea Feb 06 13:53:27 music volumio[14110]: info: Scanning category music_service Feb 06 13:53:27 music volumio[14110]: info: Scanning category plugins.json Feb 06 13:53:27 music volumio[14110]: info: Scanning category system_controller Feb 06 13:53:27 music volumio[14110]: info: Scanning category user_interface Feb 06 13:53:27 music volumio[14110]: info: Scanning into folder /data/plugins/ Feb 06 13:53:27 music volumio[14110]: info: Scanning category music_service Feb 06 13:53:27 music volumio[14110]: info: Plugin folders cleanup completed Feb 06 13:53:27 music volumio[14110]: info: ------------------------------------------- Feb 06 13:53:27 music volumio[14110]: info: ----- Core plugins startup ---- Feb 06 13:53:27 music volumio[14110]: info: ------------------------------------------- Feb 06 13:53:27 music volumio[14110]: info: Loading plugins from folder /volumio/app/plugins/ Feb 06 13:53:27 music volumio[14110]: info: Adding plugin upnp to MyMusic Plugins Feb 06 13:53:27 music volumio[14110]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 06 13:53:27 music volumio[14110]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 06 13:53:27 music volumio[14110]: info: Loading plugins from folder /data/plugins/ Feb 06 13:53:27 music volumio[14110]: info: Loading plugin "system"... Feb 06 13:53:27 music volumio[14110]: info: Loading plugin "appearance"... Feb 06 13:53:27 music go-librespot[14126]: time="2026-02-06T13:53:27-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 06 13:53:27 music go-librespot[14126]: time="2026-02-06T13:53:27-05:00" level=debug msg="completed keyexchange" Feb 06 13:53:27 music go-librespot[14126]: time="2026-02-06T13:53:27-05:00" level=debug msg="completed challenge" Feb 06 13:53:27 music go-librespot[14126]: time="2026-02-06T13:53:27-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:27 music go-librespot[14126]: time="2026-02-06T13:53:27-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 06 13:53:27 music go-librespot[14126]: time="2026-02-06T13:53:27-05:00" level=debug msg="completed keyexchange" Feb 06 13:53:27 music go-librespot[14126]: time="2026-02-06T13:53:27-05:00" level=debug msg="completed challenge" Feb 06 13:53:28 music go-librespot[14126]: time="2026-02-06T13:53:28-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:28 music volumio[14110]: info: Loading plugin "network"... Feb 06 13:53:28 music volumio[14110]: info: Refreshing Cached IP Addresses Feb 06 13:53:28 music sudo[14148]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 06 13:53:28 music sudo[14148]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:53:28 music sudo[14150]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 06 13:53:28 music sudo[14150]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:53:28 music sudo[14148]: pam_unix(sudo:session): session closed for user root Feb 06 13:53:28 music volumio[14110]: info: Loading plugin "services"... Feb 06 13:53:28 music sudo[14150]: pam_unix(sudo:session): session closed for user root Feb 06 13:53:28 music volumio[14110]: info: Loading plugin "alsa_controller"... Feb 06 13:53:28 music sudo[14158]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 06 13:53:28 music sudo[14158]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:53:28 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 06 13:53:28 music volumio[14110]: info: Loading plugin "wizard"... Feb 06 13:53:28 music volumio[14110]: info: Loading plugin "networkfs"... Feb 06 13:53:28 music volumio[14110]: info: Starting Udev Watcher for removable devices Feb 06 13:53:28 music volumio[14110]: info: Ignoring mount for partition: boot Feb 06 13:53:28 music volumio[14110]: info: Ignoring mount for partition: volumio Feb 06 13:53:28 music volumio[14110]: info: Ignoring mount for partition: volumio_data Feb 06 13:53:28 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 06 13:53:28 music volumio[14110]: info: Loading plugin "volumio_command_line_client"... Feb 06 13:53:28 music volumio[14110]: info: Loading plugin "upnp"... Feb 06 13:53:28 music volumio[14110]: info: [1770404008408] Starting Upmpd Daemon Feb 06 13:53:28 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 06 13:53:28 music volumio[14110]: info: Loading plugin "my_music"... Feb 06 13:53:28 music volumio[14110]: info: Loading plugin "mpd"... Feb 06 13:53:28 music go-librespot[14126]: time="2026-02-06T13:53:28-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 06 13:53:28 music go-librespot[14126]: time="2026-02-06T13:53:28-05:00" level=debug msg="completed keyexchange" Feb 06 13:53:28 music go-librespot[14126]: time="2026-02-06T13:53:28-05:00" level=debug msg="completed challenge" Feb 06 13:53:28 music go-librespot[14126]: time="2026-02-06T13:53:28-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:28 music volumio-remote-updater[31331]: [2026-02-06 13:53:28] [connect] Successful connection Feb 06 13:53:28 music volumio[14110]: info: Loading plugin "upnp_browser"... Feb 06 13:53:28 music sudo[14158]: pam_unix(sudo:session): session closed for user root Feb 06 13:53:29 music go-librespot[14126]: time="2026-02-06T13:53:29-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 06 13:53:29 music go-librespot[14126]: time="2026-02-06T13:53:29-05:00" level=debug msg="completed keyexchange" Feb 06 13:53:29 music go-librespot[14126]: time="2026-02-06T13:53:29-05:00" level=debug msg="completed challenge" Feb 06 13:53:29 music go-librespot[14126]: time="2026-02-06T13:53:29-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:30 music volumio[14110]: info: Starting UPNP Browser Feb 06 13:53:30 music volumio[14110]: info: Loading plugin "alarm-clock"... Feb 06 13:53:30 music go-librespot[14126]: time="2026-02-06T13:53:30-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 06 13:53:30 music volumio[14110]: info: Loading plugin "airplay_emulation"... Feb 06 13:53:30 music volumio[14110]: info: Starting Shairport Sync Feb 06 13:53:30 music volumio[14110]: info: Loading plugin "last_100"... Feb 06 13:53:30 music volumio[14110]: info: Loading plugin "webradio"... Feb 06 13:53:30 music go-librespot[14126]: time="2026-02-06T13:53:30-05:00" level=debug msg="completed keyexchange" Feb 06 13:53:30 music go-librespot[14126]: time="2026-02-06T13:53:30-05:00" level=debug msg="completed challenge" Feb 06 13:53:30 music volumio[14110]: info: Loading plugin "i2s_dacs"... Feb 06 13:53:30 music volumio[14110]: info: I2S DAC not set, start Auto-detection Feb 06 13:53:30 music volumio[14110]: info: Loading plugin "volumiodiscovery"... Feb 06 13:53:30 music go-librespot[14126]: time="2026-02-06T13:53:30-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:30 music go-librespot[14126]: time="2026-02-06T13:53:30-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:30 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 06 13:53:30 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 06 13:53:30 music volumio[14110]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 06 13:53:30 music volumio[14110]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 06 13:53:30 music volumio[14110]: *** WARNING *** For more information see Feb 06 13:53:30 music volumio[14110]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 06 13:53:30 music volumio[14110]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 06 13:53:30 music volumio[14110]: *** WARNING *** For more information see Feb 06 13:53:30 music node[14110]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 06 13:53:30 music node[14110]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 06 13:53:30 music node[14110]: *** WARNING *** For more information see Feb 06 13:53:30 music node[14110]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 06 13:53:30 music node[14110]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 06 13:53:30 music node[14110]: *** WARNING *** For more information see Feb 06 13:53:30 music volumio[14110]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 06 13:53:30 music volumio[14110]: info: Discovery: Started advertising with name: music Feb 06 13:53:30 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 06 13:53:30 music volumio[14110]: info: Loading plugin "spop"... Feb 06 13:53:31 music volumio[14110]: info: Loading plugin "outputs"... Feb 06 13:53:31 music volumio[14110]: info: Loading plugin "albumart"... Feb 06 13:53:31 music volumio[14110]: info: Plugin example_plugin is not enabled Feb 06 13:53:31 music volumio[14110]: info: Loading plugin "inputs"... Feb 06 13:53:31 music volumio[14110]: info: Loading plugin "updater_comm"... Feb 06 13:53:31 music volumio[14110]: info: Plugin mpdemulation is not enabled Feb 06 13:53:31 music volumio[14110]: info: Loading plugin "rest_api"... Feb 06 13:53:32 music volumio[14110]: info: Loading plugin "websocket"... Feb 06 13:53:32 music volumio[14110]: info: Starting Socket.io Server version 1.7.4 Feb 06 13:53:32 music volumio[14110]: info: Loading i18n strings for locale en Feb 06 13:53:32 music volumio[14110]: Updating browse sources language Feb 06 13:53:32 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 06 13:53:32 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 06 13:53:32 music volumio[14110]: info: CoreCommandRouter::initPlayerControls Feb 06 13:53:32 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:32 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:32 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:32 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:32 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:32 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:32 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:32 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:32 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 06 13:53:32 music volumio[14110]: Express server listening on port 3000 Feb 06 13:53:32 music volumio[14110]: [Metrics] WebUI: 6s 642.61ms Feb 06 13:53:32 music volumio[14110]: info: CoreStateMachine::resetVolumioState Feb 06 13:53:32 music volumio[14110]: info: CoreStateMachine::getcurrentVolume Feb 06 13:53:32 music volumio[14110]: info: CoreCommandRouter::volumioRetrievevolume Feb 06 13:53:32 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:53:32 music volumio[14110]: info: Volumio Network Manager: Network status updated: 1 Feb 06 13:53:32 music volumio[14110]: info: CoreCommandRouter::volumioGetState Feb 06 13:53:32 music volumio[14183]: Forking 3 albumart workers Feb 06 13:53:32 music volumio[14110]: info: CorePlayQueue::getTrack 0 Feb 06 13:53:32 music volumio-remote-updater[31331]: [2026-02-06 13:53:32] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770404008 101 Feb 06 13:53:32 music volumio[14110]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 06 13:53:32 music volumio[14110]: info: VolumeController:: Volume=86 Mute =false Feb 06 13:53:32 music volumio[14110]: info: CoreStateMachine::pushState Feb 06 13:53:32 music volumio[14110]: info: CorePlayQueue::getTrack 0 Feb 06 13:53:32 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 06 13:53:32 music volumio[14110]: info: CoreCommandRouter::volumioPushState Feb 06 13:53:32 music volumio[14110]: info: CoreStateMachine::updateTrackBlock Feb 06 13:53:32 music volumio[14110]: info: CorePlayQueue::getTrackBlock Feb 06 13:53:32 music volumio[14110]: info: CoreCommandRouter::volumioRetrievevolume Feb 06 13:53:32 music volumio[14110]: info: Reloading queue from file Feb 06 13:53:32 music volumio[14110]: info: CoreStateMachine::setRepeat null single undefined Feb 06 13:53:32 music volumio[14110]: info: CoreStateMachine::pushState Feb 06 13:53:32 music volumio[14110]: info: CorePlayQueue::getTrack 0 Feb 06 13:53:32 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 06 13:53:32 music volumio[14110]: info: CoreCommandRouter::volumioPushState Feb 06 13:53:32 music volumio[14110]: info: CoreStateMachine::setRandom null Feb 06 13:53:32 music volumio[14110]: info: CoreStateMachine::pushState Feb 06 13:53:32 music volumio[14110]: info: CorePlayQueue::getTrack 0 Feb 06 13:53:32 music volumio[14110]: info: CoreCommandRouter::volumioPushState Feb 06 13:53:32 music volumio[14110]: info: Setting Device type: Raspberry PI Feb 06 13:53:32 music volumio[14110]: info: Listing playlists Feb 06 13:53:32 music volumio[14110]: info: Listing playlists Feb 06 13:53:32 music volumio[14110]: info: VolumeController:: Volume=86 Mute =false Feb 06 13:53:32 music volumio[14110]: info: CoreStateMachine::pushState Feb 06 13:53:32 music volumio[14110]: info: CorePlayQueue::getTrack 0 Feb 06 13:53:32 music volumio[14110]: info: CoreCommandRouter::volumioPushState Feb 06 13:53:32 music volumio[14110]: info: Completed loading Core Plugins Feb 06 13:53:32 music volumio[14110]: info: Preparing to generate the ALSA configuration file Feb 06 13:53:32 music volumio[14110]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 06 13:53:32 music volumio[14110]: info: Discovery: Found device music Feb 06 13:53:32 music volumio[14110]: info: CoreCommandRouter::volumioGetState Feb 06 13:53:32 music volumio[14110]: info: CorePlayQueue::getTrack 0 Feb 06 13:53:32 music volumio[14110]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 06 13:53:32 music volumio[14110]: info: Discovery: Found device music Feb 06 13:53:32 music volumio[14110]: info: CoreCommandRouter::volumioGetState Feb 06 13:53:32 music volumio[14110]: info: CorePlayQueue::getTrack 0 Feb 06 13:53:32 music volumio[14110]: info: Asound.conf file unchanged, so no further update is needed Feb 06 13:53:32 music volumio[14110]: info: Output device has changed, restarting MPD Feb 06 13:53:32 music volumio[14110]: info: Output device has changed, restarting Shairport Sync Feb 06 13:53:32 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:32 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:53:32 music sudo[14238]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 06 13:53:32 music volumio[14110]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 06 13:53:32 music sudo[14238]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:53:32 music sudo[14240]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 06 13:53:32 music sudo[14240]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:53:32 music volumio[14110]: info: ___________ START PLUGINS ___________ Feb 06 13:53:32 music sudo[14238]: pam_unix(sudo:session): session closed for user root Feb 06 13:53:32 music volumio[14110]: info: ControllerMpd::onStart: Initializing MPD Feb 06 13:53:32 music volumio[14110]: info: Creating MPD Configuration file Feb 06 13:53:32 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 06 13:53:32 music volumio[14110]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 06 13:53:32 music volumio[14110]: info: [1770404012958] CoreMusicLibrary::Adding element Media Servers Feb 06 13:53:32 music sudo[14248]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 06 13:53:32 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 06 13:53:32 music systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 06 13:53:32 music sudo[14248]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:53:33 music sudo[14248]: pam_unix(sudo:session): session closed for user root Feb 06 13:53:33 music volumio[14110]: info: UPNP Browser: Client initialized successfully Feb 06 13:53:33 music sudo[14250]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 06 13:53:33 music systemd[1]: mpd.service: Deactivated successfully. Feb 06 13:53:33 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 06 13:53:33 music systemd[1]: mpd.service: Consumed 4.270s CPU time. Feb 06 13:53:33 music sudo[14250]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:53:33 music systemd[1]: mpd.socket: Deactivated successfully. Feb 06 13:53:33 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 06 13:53:33 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 06 13:53:33 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:33 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:53:33 music volumio[14110]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 06 13:53:33 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:33 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:53:33 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 06 13:53:33 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 06 13:53:33 music volumio[14110]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 06 13:53:33 music volumio[14110]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 06 13:53:33 music volumio[14110]: info: [1770404013186] CoreMusicLibrary::Adding element Last_100 Feb 06 13:53:33 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 06 13:53:33 music systemd[1]: mpd.service: Deactivated successfully. Feb 06 13:53:33 music volumio[14110]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 06 13:53:33 music volumio[14110]: info: [1770404013197] CoreMusicLibrary::Adding element Webradio Feb 06 13:53:33 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 06 13:53:33 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 06 13:53:33 music systemd[1]: mpd.socket: Deactivated successfully. Feb 06 13:53:33 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 06 13:53:33 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 06 13:53:33 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 06 13:53:33 music volumio[14110]: info: Initializing BBC Radios Feb 06 13:53:33 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 06 13:53:33 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 06 13:53:33 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 06 13:53:33 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:53:33 music volumio[14110]: info: Creating Spotify config file Feb 06 13:53:33 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:33 music sudo[14267]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 06 13:53:33 music sudo[14267]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 06 13:53:33 music sudo[14267]: pam_unix(sudo:session): session closed for user root Feb 06 13:53:33 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 06 13:53:33 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 06 13:53:33 music volumio[14110]: info: Volumio Calling Home Feb 06 13:53:33 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 06 13:53:33 music go-librespot[14280]: go-librespot daemon starting... Feb 06 13:53:33 music go-librespot[14282]: time="2026-02-06T13:53:33-05:00" level=info msg="running go-librespot 0.6.2" Feb 06 13:53:34 music volumio[14201]: Starting albumart workers Feb 06 13:53:34 music volumio[14200]: Starting albumart workers Feb 06 13:53:34 music go-librespot[14282]: time="2026-02-06T13:53:34-05:00" level=info msg="zeroconf server listening on port 36421" Feb 06 13:53:34 music volumio[14199]: Starting albumart workers Feb 06 13:53:34 music volumio[14110]: info: MPD Permissions set Feb 06 13:53:34 music volumio[14110]: info: MPD Permissions set Feb 06 13:53:34 music volumio[14110]: info: Volumio called home Feb 06 13:53:34 music volumio[14110]: info: Spotify config file written Feb 06 13:53:34 music volumio[14110]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 06 13:53:34 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:34 music sudo[14294]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 06 13:53:34 music sudo[14294]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:53:34 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:34 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:34 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:34 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:34 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:34 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:34 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:34 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 06 13:53:34 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 06 13:53:34 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 06 13:53:34 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:53:34 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:34 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:34 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:34 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:34 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:34 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:34 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:34 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:34 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:34 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 06 13:53:34 music go-librespot[14301]: go-librespot daemon starting... Feb 06 13:53:34 music sudo[14294]: pam_unix(sudo:session): session closed for user root Feb 06 13:53:35 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:53:35 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 06 13:53:35 music volumio[14110]: info: No need to fix Spotify hosts Feb 06 13:53:35 music go-librespot[14303]: time="2026-02-06T13:53:35-05:00" level=info msg="running go-librespot 0.6.2" Feb 06 13:53:35 music go-librespot[14303]: time="2026-02-06T13:53:35-05:00" level=debug msg="app state loaded" Feb 06 13:53:35 music go-librespot[14303]: time="2026-02-06T13:53:35-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 06 13:53:35 music go-librespot[14303]: time="2026-02-06T13:53:35-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 06 13:53:35 music go-librespot[14303]: time="2026-02-06T13:53:35-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 06 13:53:35 music go-librespot[14303]: time="2026-02-06T13:53:35-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 06 13:53:35 music go-librespot[14303]: time="2026-02-06T13:53:35-05:00" level=info msg="zeroconf server listening on port 34035" Feb 06 13:53:35 music volumio[14110]: info: Starting Shairport Sync Feb 06 13:53:35 music go-librespot[14303]: time="2026-02-06T13:53:35-05:00" level=debug msg="obtained new client token: AACkzyRfvze5Q4gW5MalYdDFvdEOYs3IToP0qdZtggJGJsWRIUnHvGynVxrLEFSWS6fq7lNC4RQKOZIkh6bd+BAWzHOdxjODK/zP+BQr5AFtPBHXfU4I3gqUBB/YdI2Y7ilzCpHAKpbCAF+X5Kuv+gMbt3U1uA1fv0BCQjxH7oFi4MPtgLu/knunk7lyhoHNh6ErsQBxDNXxUPsYe676DZD3hiuml8zk3jGJnK97wguv5mWBZcl7cbM=" Feb 06 13:53:35 music volumio[14110]: info: Starting Shairport Sync Feb 06 13:53:35 music volumio[14110]: info: Starting Shairport Sync Feb 06 13:53:35 music sudo[14332]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 06 13:53:35 music sudo[14332]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:53:35 music sudo[14334]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 06 13:53:35 music sudo[14334]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:53:35 music go-librespot[14303]: time="2026-02-06T13:53:35-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 06 13:53:35 music sudo[14337]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 06 13:53:35 music sudo[14337]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:53:35 music go-librespot[14303]: time="2026-02-06T13:53:35-05:00" level=debug msg="completed keyexchange" Feb 06 13:53:35 music go-librespot[14303]: time="2026-02-06T13:53:35-05:00" level=debug msg="completed challenge" Feb 06 13:53:35 music volumio[14110]: info: CoreCommandRouter::volumioGetState Feb 06 13:53:35 music volumio[14110]: info: CorePlayQueue::getTrack 0 Feb 06 13:53:35 music volumio[14110]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 06 13:53:35 music go-librespot[14303]: time="2026-02-06T13:53:35-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:35 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 06 13:53:35 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 06 13:53:36 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 06 13:53:36 music systemd[1]: shairport-sync.service: Consumed 1.769s CPU time. Feb 06 13:53:36 music volumio[14110]: info: CoreCommandRouter::volumioGetState Feb 06 13:53:36 music volumio[14110]: info: CorePlayQueue::getTrack 0 Feb 06 13:53:36 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 06 13:53:36 music sudo[14332]: pam_unix(sudo:session): session closed for user root Feb 06 13:53:36 music sudo[14334]: pam_unix(sudo:session): session closed for user root Feb 06 13:53:36 music sudo[14337]: pam_unix(sudo:session): session closed for user root Feb 06 13:53:36 music volumio[14110]: info: Shairport-Sync Started Feb 06 13:53:36 music volumio[14110]: Error adding Membership: Error: addMembership EINVAL Feb 06 13:53:36 music volumio[14110]: info: Shairport-Sync Started Feb 06 13:53:36 music volumio[14110]: info: Shairport-Sync Started Feb 06 13:53:36 music go-librespot[14303]: time="2026-02-06T13:53:36-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.255.62:443: connect: connection refused" Feb 06 13:53:36 music go-librespot[14303]: time="2026-02-06T13:53:36-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 06 13:53:36 music go-librespot[14303]: time="2026-02-06T13:53:36-05:00" level=debug msg="completed keyexchange" Feb 06 13:53:36 music go-librespot[14303]: time="2026-02-06T13:53:36-05:00" level=debug msg="completed challenge" Feb 06 13:53:36 music go-librespot[14303]: time="2026-02-06T13:53:36-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:37 music go-librespot[14303]: time="2026-02-06T13:53:37-05:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 06 13:53:37 music go-librespot[14303]: time="2026-02-06T13:53:37-05:00" level=debug msg="completed keyexchange" Feb 06 13:53:37 music go-librespot[14303]: time="2026-02-06T13:53:37-05:00" level=debug msg="completed challenge" Feb 06 13:53:37 music mpd[14279]: 2026-02-06T13:53:37 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 06 13:53:37 music systemd[1]: Started mpd.service - Music Player Daemon. Feb 06 13:53:37 music sudo[14250]: pam_unix(sudo:session): session closed for user root Feb 06 13:53:37 music sudo[14240]: pam_unix(sudo:session): session closed for user root Feb 06 13:53:37 music volumio[14110]: info: Completed starting Core Plugins Feb 06 13:53:37 music volumio[14110]: info: ------------------------------------------- Feb 06 13:53:37 music volumio[14110]: info: ----- MyVolumio plugins startup ---- Feb 06 13:53:37 music volumio[14110]: info: ------------------------------------------- Feb 06 13:53:37 music volumio[14110]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 06 13:53:37 music volumio[14110]: error: MPD error: The expression evaluated to a falsy value: Feb 06 13:53:37 music volumio[14110]: assert.ok(self.idling) Feb 06 13:53:37 music volumio[14110]: error: The expression evaluated to a falsy value: Feb 06 13:53:37 music volumio[14110]: assert.ok(self.idling) Feb 06 13:53:37 music volumio[14110]: info: MPD running with PID14279 Feb 06 13:53:37 music volumio[14110]: ,establishing connection Feb 06 13:53:37 music volumio[14110]: error: updateQueue error: null Feb 06 13:53:37 music volumio[14110]: error: updateQueue error: null Feb 06 13:53:37 music go-librespot[14303]: time="2026-02-06T13:53:37-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:38 music sudo[14381]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 06 13:53:38 music sudo[14381]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:53:38 music sudo[14381]: pam_unix(sudo:session): session closed for user root Feb 06 13:53:38 music sudo[14383]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 06 13:53:38 music sudo[14383]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:53:38 music sudo[14383]: pam_unix(sudo:session): session closed for user root Feb 06 13:53:38 music sudo[14385]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 06 13:53:38 music sudo[14385]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:53:38 music go-librespot[14303]: time="2026-02-06T13:53:38-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 06 13:53:38 music sudo[14385]: pam_unix(sudo:session): session closed for user root Feb 06 13:53:38 music volumio[14110]: info: Upmpdcli Daemon Started Feb 06 13:53:38 music go-librespot[14303]: time="2026-02-06T13:53:38-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:48102->104.199.65.9:443: read: connection reset by peer" Feb 06 13:53:38 music volumio[14110]: info: go-librespot daemon successfully initialized Feb 06 13:53:39 music go-librespot[14303]: time="2026-02-06T13:53:39-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 06 13:53:39 music go-librespot[14303]: time="2026-02-06T13:53:39-05:00" level=debug msg="completed keyexchange" Feb 06 13:53:39 music go-librespot[14303]: time="2026-02-06T13:53:39-05:00" level=debug msg="completed challenge" Feb 06 13:53:39 music go-librespot[14303]: time="2026-02-06T13:53:39-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:40 music go-librespot[14303]: time="2026-02-06T13:53:40-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 06 13:53:40 music go-librespot[14303]: time="2026-02-06T13:53:40-05:00" level=debug msg="completed keyexchange" Feb 06 13:53:40 music go-librespot[14303]: time="2026-02-06T13:53:40-05:00" level=debug msg="completed challenge" Feb 06 13:53:40 music go-librespot[14303]: time="2026-02-06T13:53:40-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:40 music go-librespot[14303]: time="2026-02-06T13:53:40-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:40 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 06 13:53:40 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 06 13:53:40 music sudo[14390]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 06 13:53:40 music sudo[14390]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:53:40 music sudo[14392]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 06 13:53:40 music sudo[14392]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:53:40 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 06 13:53:40 music systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 06 13:53:40 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 06 13:53:40 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 06 13:53:40 music sudo[14390]: pam_unix(sudo:session): session closed for user root Feb 06 13:53:40 music mpd_monitor.sh[14395]: MPD Monitor Service: Starting MPD Monitor Service Feb 06 13:53:40 music sudo[14392]: pam_unix(sudo:session): session closed for user root Feb 06 13:53:40 music volumio[14110]: info: Successfully started MPD Monitor Feb 06 13:53:40 music volumio[14110]: info: Successfully started MPD Monitor Feb 06 13:53:41 music volumio[14110]: info: Initializing connection to go-librespot Websocket Feb 06 13:53:41 music volumio[14110]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 06 13:53:42 music volumio[14110]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 06 13:53:43 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 06 13:53:43 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 06 13:53:43 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 06 13:53:43 music go-librespot[14399]: go-librespot daemon starting... Feb 06 13:53:43 music go-librespot[14400]: time="2026-02-06T13:53:43-05:00" level=info msg="running go-librespot 0.6.2" Feb 06 13:53:43 music go-librespot[14400]: time="2026-02-06T13:53:43-05:00" level=debug msg="app state loaded" Feb 06 13:53:43 music go-librespot[14400]: time="2026-02-06T13:53:43-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 06 13:53:43 music go-librespot[14400]: time="2026-02-06T13:53:43-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 06 13:53:43 music go-librespot[14400]: time="2026-02-06T13:53:43-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 06 13:53:43 music go-librespot[14400]: time="2026-02-06T13:53:43-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 06 13:53:43 music go-librespot[14400]: time="2026-02-06T13:53:43-05:00" level=info msg="zeroconf server listening on port 35037" Feb 06 13:53:43 music go-librespot[14400]: time="2026-02-06T13:53:43-05:00" level=debug msg="obtained new client token: AACHG2/ppsM7Uh7AOIdGHoPPvB8721qd/yjCPoFzx48yPfK2YH2AFi78njzn3qYeQThdfqZkxgBA4YuCHcx5ZebzYrabxQYo1fox2e7Y2PRGO8Y2W4mDTv5PaPTiTAZEanBYWpEBnJb48knsNjdwvmN8cLu2HycBI8YFiNm+tQDf2ca95ZFfxhKmquNqIYe6eimQcbcYriLoX3dlHDjrCIoikjeDuzKxGlfFxIt48EQt0CvdGHWaMZQ=" Feb 06 13:53:43 music go-librespot[14400]: time="2026-02-06T13:53:43-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 06 13:53:43 music go-librespot[14400]: time="2026-02-06T13:53:43-05:00" level=debug msg="completed keyexchange" Feb 06 13:53:43 music go-librespot[14400]: time="2026-02-06T13:53:43-05:00" level=debug msg="completed challenge" Feb 06 13:53:44 music go-librespot[14400]: time="2026-02-06T13:53:44-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:44 music go-librespot[14400]: time="2026-02-06T13:53:44-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 06 13:53:44 music go-librespot[14400]: time="2026-02-06T13:53:44-05:00" level=debug msg="completed keyexchange" Feb 06 13:53:44 music go-librespot[14400]: time="2026-02-06T13:53:44-05:00" level=debug msg="completed challenge" Feb 06 13:53:44 music volumio[14110]: info: Initializing connection to go-librespot Websocket Feb 06 13:53:44 music go-librespot[14400]: time="2026-02-06T13:53:44-05:00" level=debug msg="new websocket client" Feb 06 13:53:44 music volumio[14110]: info: Connection to go-librespot Websocket established Feb 06 13:53:44 music go-librespot[14400]: time="2026-02-06T13:53:44-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:45 music go-librespot[14400]: time="2026-02-06T13:53:45-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 06 13:53:45 music go-librespot[14400]: time="2026-02-06T13:53:45-05:00" level=debug msg="completed keyexchange" Feb 06 13:53:45 music go-librespot[14400]: time="2026-02-06T13:53:45-05:00" level=debug msg="completed challenge" Feb 06 13:53:45 music go-librespot[14400]: time="2026-02-06T13:53:45-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:45 music volumio[14110]: info: CoreCommandRouter::volumioGetState Feb 06 13:53:45 music volumio[14110]: info: CorePlayQueue::getTrack 0 Feb 06 13:53:45 music go-librespot[14400]: time="2026-02-06T13:53:45-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 06 13:53:45 music volumio[14110]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 06 13:53:45 music volumio[14110]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 06 13:53:45 music volumio[14110]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 06 13:53:45 music volumio[14110]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 06 13:53:45 music volumio[14110]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 06 13:53:45 music volumio[14110]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 06 13:53:45 music volumio[14110]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 06 13:53:45 music volumio[14110]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 06 13:53:45 music volumio[14110]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 06 13:53:45 music volumio[14110]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 06 13:53:45 music volumio[14110]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 06 13:53:45 music volumio[14110]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 06 13:53:45 music volumio[14110]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 06 13:53:45 music volumio[14110]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 06 13:53:45 music volumio[14110]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 06 13:53:45 music volumio[14110]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 06 13:53:45 music volumio[14110]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 06 13:53:45 music volumio[14110]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 06 13:53:45 music volumio[14110]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 06 13:53:45 music volumio[14110]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 06 13:53:45 music volumio[14110]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 06 13:53:45 music volumio[14110]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 06 13:53:45 music volumio[14110]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 06 13:53:45 music volumio[14110]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 06 13:53:45 music volumio[14110]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 06 13:53:45 music volumio[14110]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 06 13:53:45 music volumio[14110]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 06 13:53:45 music volumio[14110]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 06 13:53:45 music volumio[14110]: info: Adding plugin bluetooth to MyMusic Plugins Feb 06 13:53:45 music volumio[14110]: info: Adding plugin multiroom to MyMusic Plugins Feb 06 13:53:45 music volumio[14110]: info: Adding plugin metavolumio to MyMusic Plugins Feb 06 13:53:45 music volumio[14110]: info: Adding plugin cd_controller to MyMusic Plugins Feb 06 13:53:45 music volumio[14110]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 06 13:53:45 music volumio[14110]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 06 13:53:45 music volumio[14110]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 06 13:53:45 music volumio[14110]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 06 13:53:46 music go-librespot[14400]: time="2026-02-06T13:53:46-05:00" level=debug msg="completed keyexchange" Feb 06 13:53:46 music go-librespot[14400]: time="2026-02-06T13:53:46-05:00" level=debug msg="completed challenge" Feb 06 13:53:46 music go-librespot[14400]: time="2026-02-06T13:53:46-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:46 music go-librespot[14400]: time="2026-02-06T13:53:46-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 06 13:53:46 music go-librespot[14400]: time="2026-02-06T13:53:46-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:53944->104.199.65.9:443: read: connection reset by peer" Feb 06 13:53:47 music volumio[14110]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 06 13:53:47 music volumio[14110]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 06 13:53:47 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:53:47 music volumio[14110]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 13:53:47 music volumio[14110]: info: Starting MyVolumio Remote Streaming Endpoints Feb 06 13:53:47 music volumio[14110]: info: MyVolumio login type: Token Feb 06 13:53:47 music volumio[14110]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 06 13:53:47 music volumio[14110]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 06 13:53:47 music go-librespot[14400]: time="2026-02-06T13:53:47-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 06 13:53:47 music go-librespot[14400]: time="2026-02-06T13:53:47-05:00" level=debug msg="completed keyexchange" Feb 06 13:53:47 music go-librespot[14400]: time="2026-02-06T13:53:47-05:00" level=debug msg="completed challenge" Feb 06 13:53:47 music go-librespot[14400]: time="2026-02-06T13:53:47-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:47 music go-librespot[14400]: time="2026-02-06T13:53:47-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 06 13:53:47 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 06 13:53:47 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 06 13:53:48 music volumio[14110]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 06 13:53:48 music volumio[14110]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 06 13:53:48 music volumio[14110]: info: Streaming services startup Feb 06 13:53:48 music volumio[14110]: info: Starting Streaming Daemon Feb 06 13:53:48 music sudo[14411]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 06 13:53:48 music sudo[14411]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 06 13:53:48 music volumio[14110]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 06 13:53:48 music sudo[14411]: pam_unix(sudo:session): session closed for user root Feb 06 13:53:48 music volumio[14110]: info: Getting Spotify volume Feb 06 13:53:48 music volumio[14110]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 06 13:53:48 music volumio[14110]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 06 13:53:48 music volumio[14110]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 06 13:53:48 music volumio[14110]: errno: -111, Feb 06 13:53:48 music volumio[14110]: code: 'ECONNREFUSED', Feb 06 13:53:48 music volumio[14110]: syscall: 'connect', Feb 06 13:53:48 music volumio[14110]: address: '127.0.0.1', Feb 06 13:53:48 music volumio[14110]: port: 9879, Feb 06 13:53:48 music volumio[14110]: response: undefined Feb 06 13:53:48 music volumio[14110]: } Feb 06 13:53:48 music volumio[14110]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 06 13:53:48 music sudo[14445]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-06 13:52' Feb 06 13:53:48 music sudo[14445]: 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"