Feb 09 21:44:00 music go-librespot[16016]: time="2026-02-09T21:44:00-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 09 21:44:00 music go-librespot[16016]: time="2026-02-09T21:44:00-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:00 music go-librespot[16016]: time="2026-02-09T21:44:00-05:00" level=debug msg="completed challenge" Feb 09 21:44:00 music go-librespot[16016]: time="2026-02-09T21:44:00-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:00 music volumio[15734]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 09 21:44:00 music volumio[15734]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 09 21:44:00 music volumio[15734]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:44:00 music volumio[15734]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:44:00 music volumio[15734]: info: Starting MyVolumio Remote Streaming Endpoints Feb 09 21:44:00 music volumio[15734]: info: MyVolumio login type: Token Feb 09 21:44:00 music volumio[15734]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 09 21:44:00 music volumio[15734]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 09 21:44:01 music go-librespot[16016]: time="2026-02-09T21:44:01-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.255.62:4070: connect: connection refused" Feb 09 21:44:01 music go-librespot[16016]: time="2026-02-09T21:44:01-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.255.62:443: connect: connection refused" Feb 09 21:44:01 music go-librespot[16016]: time="2026-02-09T21:44:01-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 09 21:44:01 music go-librespot[16016]: time="2026-02-09T21:44:01-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:01 music go-librespot[16016]: time="2026-02-09T21:44:01-05:00" level=debug msg="completed challenge" Feb 09 21:44:01 music go-librespot[16016]: time="2026-02-09T21:44:01-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:01 music volumio[15734]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 09 21:44:01 music volumio[15734]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 09 21:44:01 music volumio[15734]: info: Streaming services startup Feb 09 21:44:01 music volumio[15734]: info: Starting Streaming Daemon Feb 09 21:44:01 music sudo[16026]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 09 21:44:01 music sudo[16026]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:01 music volumio[15734]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 09 21:44:01 music sudo[16026]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:01 music volumio[15734]: info: Getting Spotify volume Feb 09 21:44:01 music volumio[15734]: error: Cannot start Volumio Streaming Daemon Feb 09 21:44:01 music volumio[15734]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 09 21:44:01 music volumio[15734]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 09 21:44:01 music volumio[15734]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 09 21:44:01 music volumio[15734]: info: CoreCommandRouter::volumioGetState Feb 09 21:44:01 music volumio[15734]: info: CorePlayQueue::getTrack 0 Feb 09 21:44:01 music go-librespot[16016]: time="2026-02-09T21:44:01-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 09 21:44:01 music volumio[15734]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Feb 09 21:44:01 music volumio[15734]: SPOTIFY: SPOTIFY VOLUME undefined Feb 09 21:44:01 music volumio[15734]: SPOTIFY: VOLUMIO VOLUME 86 Feb 09 21:44:01 music volumio[15734]: info: Aligning Spotify Volume to Volumio Volume Feb 09 21:44:01 music volumio[15734]: info: CoreCommandRouter::volumioGetState Feb 09 21:44:01 music volumio[15734]: info: CorePlayQueue::getTrack 0 Feb 09 21:44:01 music volumio[15734]: info: Setting Spotify Volume from Volumio: 86 Feb 09 21:44:02 music go-librespot[16016]: time="2026-02-09T21:44:02-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:02 music go-librespot[16016]: time="2026-02-09T21:44:02-05:00" level=debug msg="completed challenge" Feb 09 21:44:02 music go-librespot[16016]: time="2026-02-09T21:44:02-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:02 music go-librespot[16016]: time="2026-02-09T21:44:02-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:02 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 21:44:02 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 21:44:02 music volumio[15734]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 09 21:44:02 music volumio[15734]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 21:44:02 music volumio[15734]: Error: socket hang up Feb 09 21:44:02 music volumio[15734]: at connResetException (node:internal/errors:720:14) Feb 09 21:44:02 music volumio[15734]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 09 21:44:02 music volumio[15734]: at Socket.emit (node:events:526:35) Feb 09 21:44:02 music volumio[15734]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 09 21:44:02 music volumio[15734]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 09 21:44:02 music volumio[15734]: code: 'ECONNRESET', Feb 09 21:44:02 music volumio[15734]: response: undefined Feb 09 21:44:02 music volumio[15734]: } Feb 09 21:44:02 music volumio[15734]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 21:44:02 music sudo[16060]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-09 21:43' Feb 09 21:44:02 music sudo[16060]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:03 music sudo[16060]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:04 music volumio-remote-updater[30265]: [2026-02-09 21:44:04] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 09 21:44:04 music volumio-remote-updater[30265]: [2026-02-09 21:44:04] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 09 21:44:04 music systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 09 21:44:04 music systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 09 21:44:04 music systemd[1]: volumio.service: Consumed 26.864s CPU time. Feb 09 21:44:04 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 09 21:44:04 music systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Feb 09 21:44:04 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 09 21:44:04 music systemd[1]: volumio.service: Scheduled restart job, restart counter is at 53395. Feb 09 21:44:04 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 09 21:44:04 music systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 09 21:44:04 music systemd[1]: volumio.service: Consumed 26.864s CPU time. Feb 09 21:44:04 music systemd[1]: Started volumio.service - Volumio Backend Module. Feb 09 21:44:04 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 09 21:44:05 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 09 21:44:05 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 21:44:05 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 21:44:05 music go-librespot[16116]: go-librespot daemon starting... Feb 09 21:44:05 music go-librespot[16117]: time="2026-02-09T21:44:05-05:00" level=info msg="running go-librespot 0.6.2" Feb 09 21:44:05 music go-librespot[16117]: time="2026-02-09T21:44:05-05:00" level=debug msg="app state loaded" Feb 09 21:44:05 music go-librespot[16117]: time="2026-02-09T21:44:05-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 21:44:05 music systemd[1]: setdatetime-helper.service: Deactivated successfully. Feb 09 21:44:05 music systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Feb 09 21:44:05 music systemd[1]: setdatetime-helper.service: Consumed 1.092s CPU time. Feb 09 21:44:05 music go-librespot[16117]: time="2026-02-09T21:44:05-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 21:44:05 music go-librespot[16117]: time="2026-02-09T21:44:05-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 21:44:05 music go-librespot[16117]: time="2026-02-09T21:44:05-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 21:44:05 music go-librespot[16117]: time="2026-02-09T21:44:05-05:00" level=info msg="zeroconf server listening on port 36459" Feb 09 21:44:05 music go-librespot[16117]: time="2026-02-09T21:44:05-05:00" level=debug msg="obtained new client token: AADrh4F5ovC3jP6pd5UsFBu/+5d+3/+FPILXXQPsKGhkomDAxCJ+UcYLFjjblu/SHZjaGFQN3uWDFeBgp3m+iPFvdPuOm3NR+WFEBdIriJRlpYhMf1HTydjKEUh6iLQ59kimqwBWZW7IFdx7BPvH9nIOwCr9HNiaIjfVRr3eigZdmh7Oq7pntWevl+L2AlE4WDksvgU/+bpzCYh/MXQg5VacNM06+YvE+e7nzUgux0oan3r/8zpRuFE=" Feb 09 21:44:06 music go-librespot[16117]: time="2026-02-09T21:44:06-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 09 21:44:06 music go-librespot[16117]: time="2026-02-09T21:44:06-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:06 music go-librespot[16117]: time="2026-02-09T21:44:06-05:00" level=debug msg="completed challenge" Feb 09 21:44:06 music go-librespot[16117]: time="2026-02-09T21:44:06-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:06 music volumio[16092]: info: ------------------------------------------- Feb 09 21:44:06 music volumio[16092]: info: ----- Volumio3 ---- Feb 09 21:44:06 music volumio[16092]: info: ------------------------------------------- Feb 09 21:44:06 music volumio[16092]: info: ----- System startup ---- Feb 09 21:44:06 music volumio[16092]: info: ------------------------------------------- Feb 09 21:44:06 music go-librespot[16117]: time="2026-02-09T21:44:06-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 09 21:44:06 music go-librespot[16117]: time="2026-02-09T21:44:06-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:06 music go-librespot[16117]: time="2026-02-09T21:44:06-05:00" level=debug msg="completed challenge" Feb 09 21:44:06 music go-librespot[16117]: time="2026-02-09T21:44:06-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:07 music volumio[16092]: info: MYVOLUMIO Environment detected Feb 09 21:44:07 music volumio[16092]: info: Plugin folders cleanup Feb 09 21:44:07 music volumio[16092]: info: Scanning into folder /volumio/app/plugins/ Feb 09 21:44:07 music volumio[16092]: info: Scanning category audio_interface Feb 09 21:44:07 music volumio[16092]: info: Scanning category miscellanea Feb 09 21:44:07 music volumio[16092]: info: Scanning category music_service Feb 09 21:44:07 music volumio[16092]: info: Scanning category plugins.json Feb 09 21:44:07 music volumio[16092]: info: Scanning category system_controller Feb 09 21:44:07 music volumio[16092]: info: Scanning category user_interface Feb 09 21:44:07 music volumio[16092]: info: Scanning into folder /data/plugins/ Feb 09 21:44:07 music volumio[16092]: info: Scanning category music_service Feb 09 21:44:07 music volumio[16092]: info: Plugin folders cleanup completed Feb 09 21:44:07 music volumio[16092]: info: ------------------------------------------- Feb 09 21:44:07 music volumio[16092]: info: ----- Core plugins startup ---- Feb 09 21:44:07 music volumio[16092]: info: ------------------------------------------- Feb 09 21:44:07 music volumio[16092]: info: Loading plugins from folder /volumio/app/plugins/ Feb 09 21:44:07 music volumio[16092]: info: Adding plugin upnp to MyMusic Plugins Feb 09 21:44:07 music volumio[16092]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 09 21:44:07 music volumio[16092]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 09 21:44:07 music volumio[16092]: info: Loading plugins from folder /data/plugins/ Feb 09 21:44:07 music volumio[16092]: info: Loading plugin "system"... Feb 09 21:44:07 music volumio[16092]: info: Loading plugin "appearance"... Feb 09 21:44:07 music go-librespot[16117]: time="2026-02-09T21:44:07-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 09 21:44:07 music go-librespot[16117]: time="2026-02-09T21:44:07-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:07 music go-librespot[16117]: time="2026-02-09T21:44:07-05:00" level=debug msg="completed challenge" Feb 09 21:44:07 music go-librespot[16117]: time="2026-02-09T21:44:07-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:08 music go-librespot[16117]: time="2026-02-09T21:44:08-05:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 21:44:08 music go-librespot[16117]: time="2026-02-09T21:44:08-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:08 music go-librespot[16117]: time="2026-02-09T21:44:08-05:00" level=debug msg="completed challenge" Feb 09 21:44:08 music volumio[16092]: info: Loading plugin "network"... Feb 09 21:44:08 music volumio[16092]: info: Refreshing Cached IP Addresses Feb 09 21:44:08 music sudo[16143]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 21:44:08 music sudo[16143]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:08 music sudo[16143]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:08 music sudo[16145]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 21:44:08 music sudo[16145]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:08 music volumio[16092]: info: Loading plugin "services"... Feb 09 21:44:08 music sudo[16145]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:08 music volumio[16092]: info: Loading plugin "alsa_controller"... Feb 09 21:44:08 music sudo[16153]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 09 21:44:08 music sudo[16153]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:08 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 21:44:08 music volumio[16092]: info: Loading plugin "wizard"... Feb 09 21:44:08 music volumio[16092]: info: Loading plugin "networkfs"... Feb 09 21:44:08 music go-librespot[16117]: time="2026-02-09T21:44:08-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:08 music volumio[16092]: info: Starting Udev Watcher for removable devices Feb 09 21:44:08 music volumio[16092]: info: Ignoring mount for partition: boot Feb 09 21:44:08 music volumio[16092]: info: Ignoring mount for partition: volumio Feb 09 21:44:08 music volumio[16092]: info: Ignoring mount for partition: volumio_data Feb 09 21:44:08 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 21:44:08 music volumio[16092]: info: Loading plugin "volumio_command_line_client"... Feb 09 21:44:08 music volumio[16092]: info: Loading plugin "upnp"... Feb 09 21:44:08 music volumio[16092]: info: [1770691448751] Starting Upmpd Daemon Feb 09 21:44:08 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 21:44:08 music volumio[16092]: info: Loading plugin "my_music"... Feb 09 21:44:08 music volumio[16092]: info: Loading plugin "mpd"... Feb 09 21:44:09 music volumio-remote-updater[30265]: [2026-02-09 21:44:09] [connect] Successful connection Feb 09 21:44:09 music volumio[16092]: info: Loading plugin "upnp_browser"... Feb 09 21:44:09 music sudo[16153]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:09 music go-librespot[16117]: time="2026-02-09T21:44:09-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 09 21:44:09 music go-librespot[16117]: time="2026-02-09T21:44:09-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:09 music go-librespot[16117]: time="2026-02-09T21:44:09-05:00" level=debug msg="completed challenge" Feb 09 21:44:09 music go-librespot[16117]: time="2026-02-09T21:44:09-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:10 music go-librespot[16117]: time="2026-02-09T21:44:10-05:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:80, retrying with a different AP" error="dial tcp 34.158.1.133:80: connect: connection refused" Feb 09 21:44:10 music go-librespot[16117]: time="2026-02-09T21:44:10-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 09 21:44:10 music go-librespot[16117]: time="2026-02-09T21:44:10-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:10 music go-librespot[16117]: time="2026-02-09T21:44:10-05:00" level=debug msg="completed challenge" Feb 09 21:44:10 music go-librespot[16117]: time="2026-02-09T21:44:10-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:10 music go-librespot[16117]: time="2026-02-09T21:44:10-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:10 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 21:44:10 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 21:44:10 music volumio[16092]: info: Starting UPNP Browser Feb 09 21:44:10 music volumio[16092]: info: Loading plugin "alarm-clock"... Feb 09 21:44:10 music volumio[16092]: info: Loading plugin "airplay_emulation"... Feb 09 21:44:10 music volumio[16092]: info: Starting Shairport Sync Feb 09 21:44:10 music volumio[16092]: info: Loading plugin "last_100"... Feb 09 21:44:10 music volumio[16092]: info: Loading plugin "webradio"... Feb 09 21:44:10 music volumio[16092]: info: Loading plugin "i2s_dacs"... Feb 09 21:44:11 music volumio[16092]: info: I2S DAC not set, start Auto-detection Feb 09 21:44:11 music volumio[16092]: info: Loading plugin "volumiodiscovery"... Feb 09 21:44:11 music volumio[16092]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 21:44:11 music volumio[16092]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 21:44:11 music volumio[16092]: *** WARNING *** For more information see Feb 09 21:44:11 music volumio[16092]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 21:44:11 music volumio[16092]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 21:44:11 music volumio[16092]: *** WARNING *** For more information see Feb 09 21:44:11 music node[16092]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 21:44:11 music node[16092]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 21:44:11 music node[16092]: *** WARNING *** For more information see Feb 09 21:44:11 music node[16092]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 21:44:11 music node[16092]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 21:44:11 music node[16092]: *** WARNING *** For more information see Feb 09 21:44:11 music volumio[16092]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 09 21:44:11 music volumio[16092]: info: Discovery: Started advertising with name: music Feb 09 21:44:11 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 21:44:11 music volumio[16092]: info: Loading plugin "spop"... Feb 09 21:44:12 music volumio[16092]: info: Loading plugin "outputs"... Feb 09 21:44:12 music volumio[16092]: info: Loading plugin "albumart"... Feb 09 21:44:12 music volumio[16092]: info: Plugin example_plugin is not enabled Feb 09 21:44:12 music volumio[16092]: info: Loading plugin "inputs"... Feb 09 21:44:12 music volumio[16092]: info: Loading plugin "updater_comm"... Feb 09 21:44:12 music volumio[16092]: info: Plugin mpdemulation is not enabled Feb 09 21:44:12 music volumio[16092]: info: Loading plugin "rest_api"... Feb 09 21:44:12 music volumio[16092]: info: Loading plugin "websocket"... Feb 09 21:44:12 music volumio[16092]: info: Starting Socket.io Server version 1.7.4 Feb 09 21:44:12 music volumio[16092]: info: Loading i18n strings for locale en Feb 09 21:44:12 music volumio[16092]: Updating browse sources language Feb 09 21:44:12 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 21:44:12 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 21:44:12 music volumio[16092]: info: CoreCommandRouter::initPlayerControls Feb 09 21:44:12 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:12 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:12 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:12 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:12 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:12 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:12 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:12 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:12 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 21:44:12 music volumio[16092]: Express server listening on port 3000 Feb 09 21:44:12 music volumio[16092]: [Metrics] WebUI: 6s 569.28ms Feb 09 21:44:12 music volumio[16092]: info: CoreStateMachine::resetVolumioState Feb 09 21:44:12 music volumio[16092]: info: CoreStateMachine::getcurrentVolume Feb 09 21:44:12 music volumio[16092]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 21:44:12 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:44:12 music volumio[16092]: info: Volumio Network Manager: Network status updated: 1 Feb 09 21:44:12 music volumio-remote-updater[30265]: [2026-02-09 21:44:12] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770691449 101 Feb 09 21:44:12 music volumio[16178]: Forking 3 albumart workers Feb 09 21:44:12 music volumio[16092]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 09 21:44:12 music volumio[16092]: info: VolumeController:: Volume=86 Mute =false Feb 09 21:44:12 music volumio[16092]: info: CoreStateMachine::pushState Feb 09 21:44:12 music volumio[16092]: info: CorePlayQueue::getTrack 0 Feb 09 21:44:12 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 21:44:12 music volumio[16092]: info: CoreCommandRouter::volumioPushState Feb 09 21:44:12 music volumio[16092]: info: CoreStateMachine::updateTrackBlock Feb 09 21:44:12 music volumio[16092]: info: CorePlayQueue::getTrackBlock Feb 09 21:44:12 music volumio[16092]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 21:44:12 music volumio[16092]: info: Reloading queue from file Feb 09 21:44:12 music volumio[16092]: info: CoreStateMachine::setRepeat null single undefined Feb 09 21:44:12 music volumio[16092]: info: CoreStateMachine::pushState Feb 09 21:44:12 music volumio[16092]: info: CorePlayQueue::getTrack 0 Feb 09 21:44:12 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 21:44:12 music volumio[16092]: info: CoreCommandRouter::volumioPushState Feb 09 21:44:12 music volumio[16092]: info: CoreStateMachine::setRandom null Feb 09 21:44:12 music volumio[16092]: info: CoreStateMachine::pushState Feb 09 21:44:12 music volumio[16092]: info: CorePlayQueue::getTrack 0 Feb 09 21:44:12 music volumio[16092]: info: CoreCommandRouter::volumioPushState Feb 09 21:44:12 music volumio[16092]: info: Setting Device type: Raspberry PI Feb 09 21:44:12 music volumio[16092]: info: VolumeController:: Volume=86 Mute =false Feb 09 21:44:12 music volumio[16092]: info: CoreStateMachine::pushState Feb 09 21:44:12 music volumio[16092]: info: CorePlayQueue::getTrack 0 Feb 09 21:44:12 music volumio[16092]: info: CoreCommandRouter::volumioPushState Feb 09 21:44:12 music volumio[16092]: info: Completed loading Core Plugins Feb 09 21:44:13 music volumio[16092]: info: Preparing to generate the ALSA configuration file Feb 09 21:44:13 music volumio[16092]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 09 21:44:13 music volumio[16092]: info: Discovery: Found device music Feb 09 21:44:13 music volumio[16092]: info: CoreCommandRouter::volumioGetState Feb 09 21:44:13 music volumio[16092]: info: CorePlayQueue::getTrack 0 Feb 09 21:44:13 music volumio[16092]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 09 21:44:13 music volumio[16092]: info: Discovery: Found device music Feb 09 21:44:13 music volumio[16092]: info: CoreCommandRouter::volumioGetState Feb 09 21:44:13 music volumio[16092]: info: CorePlayQueue::getTrack 0 Feb 09 21:44:13 music volumio[16092]: info: CoreCommandRouter::volumioGetState Feb 09 21:44:13 music volumio[16092]: info: CorePlayQueue::getTrack 0 Feb 09 21:44:13 music volumio[16092]: info: Asound.conf file unchanged, so no further update is needed Feb 09 21:44:13 music volumio[16092]: info: Output device has changed, restarting MPD Feb 09 21:44:13 music volumio[16092]: info: Output device has changed, restarting Shairport Sync Feb 09 21:44:13 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:13 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:44:13 music sudo[16233]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 21:44:13 music sudo[16233]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:13 music volumio[16092]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 21:44:13 music volumio[16092]: info: ___________ START PLUGINS ___________ Feb 09 21:44:13 music sudo[16233]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:13 music sudo[16235]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 21:44:13 music sudo[16235]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:13 music volumio[16092]: info: ControllerMpd::onStart: Initializing MPD Feb 09 21:44:13 music volumio[16092]: info: Creating MPD Configuration file Feb 09 21:44:13 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 21:44:13 music volumio[16092]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 21:44:13 music volumio[16092]: info: [1770691453246] CoreMusicLibrary::Adding element Media Servers Feb 09 21:44:13 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 21:44:13 music volumio[16092]: info: UPNP Browser: Client initialized successfully Feb 09 21:44:13 music sudo[16243]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 21:44:13 music sudo[16243]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:13 music sudo[16245]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 21:44:13 music sudo[16245]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:13 music sudo[16243]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:13 music systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 09 21:44:13 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:13 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:44:13 music volumio[16092]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 21:44:13 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:13 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:44:13 music systemd[1]: mpd.service: Deactivated successfully. Feb 09 21:44:13 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 09 21:44:13 music systemd[1]: mpd.service: Consumed 4.074s CPU time. Feb 09 21:44:13 music systemd[1]: mpd.socket: Deactivated successfully. Feb 09 21:44:13 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 09 21:44:13 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 09 21:44:13 music volumio[16092]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 21:44:13 music volumio[16092]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 21:44:13 music volumio[16092]: info: [1770691453412] CoreMusicLibrary::Adding element Last_100 Feb 09 21:44:13 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 21:44:13 music volumio[16092]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 21:44:13 music volumio[16092]: info: [1770691453426] CoreMusicLibrary::Adding element Webradio Feb 09 21:44:13 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 21:44:13 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 21:44:13 music volumio[16092]: info: Initializing BBC Radios Feb 09 21:44:13 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 09 21:44:13 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 09 21:44:13 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 09 21:44:13 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 21:44:13 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 21:44:13 music go-librespot[16266]: go-librespot daemon starting... Feb 09 21:44:13 music systemd[1]: mpd.service: Deactivated successfully. Feb 09 21:44:13 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 09 21:44:13 music systemd[1]: mpd.socket: Deactivated successfully. Feb 09 21:44:13 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 09 21:44:13 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 09 21:44:13 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 09 21:44:13 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 09 21:44:13 music go-librespot[16268]: time="2026-02-09T21:44:13-05:00" level=info msg="running go-librespot 0.6.2" Feb 09 21:44:13 music go-librespot[16268]: time="2026-02-09T21:44:13-05:00" level=debug msg="app state loaded" Feb 09 21:44:13 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 21:44:13 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:44:13 music go-librespot[16268]: time="2026-02-09T21:44:13-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 21:44:13 music volumio[16092]: info: Creating Spotify config file Feb 09 21:44:13 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:13 music sudo[16278]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 09 21:44:13 music sudo[16278]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 09 21:44:13 music sudo[16278]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:14 music go-librespot[16268]: time="2026-02-09T21:44:14-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 21:44:14 music go-librespot[16268]: time="2026-02-09T21:44:14-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 21:44:14 music go-librespot[16268]: time="2026-02-09T21:44:14-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 21:44:14 music go-librespot[16268]: time="2026-02-09T21:44:14-05:00" level=info msg="zeroconf server listening on port 41499" Feb 09 21:44:14 music volumio[16092]: info: Volumio Calling Home Feb 09 21:44:14 music go-librespot[16268]: time="2026-02-09T21:44:14-05:00" level=debug msg="obtained new client token: AAA5sDwbQoje2sAaJhQZO2tJ3kf4qUVGzppQx1eNoFgXyqLG7+5qDP9X1cW0oynKqKGo9dnmRlSH8lZTh9ArItR+G3bHe2zHzrG+acSoQelXDJLOeqC9R4/lOkM5V/ofZE8DSSbRjqgimvBZsEOB/oB1TJOb9e74iNStCc4KRYDeMVg152MDgjc7MmtPPwIMy+FK1EYdHU7yij7GsTsX0UIpSBthIC/3mirtbH46CwV+DwutHg+l" Feb 09 21:44:14 music go-librespot[16268]: time="2026-02-09T21:44:14-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 09 21:44:14 music go-librespot[16268]: time="2026-02-09T21:44:14-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:14 music go-librespot[16268]: time="2026-02-09T21:44:14-05:00" level=debug msg="completed challenge" Feb 09 21:44:14 music go-librespot[16268]: time="2026-02-09T21:44:14-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:14 music volumio[16092]: info: Listing playlists Feb 09 21:44:14 music volumio[16092]: info: Listing playlists Feb 09 21:44:14 music volumio[16092]: info: MPD Permissions set Feb 09 21:44:14 music volumio[16092]: info: MPD Permissions set Feb 09 21:44:14 music volumio[16092]: info: Spotify config file written Feb 09 21:44:14 music volumio[16196]: Starting albumart workers Feb 09 21:44:14 music sudo[16291]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 09 21:44:14 music sudo[16291]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:14 music volumio[16195]: Starting albumart workers Feb 09 21:44:14 music volumio[16092]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 09 21:44:14 music volumio[16092]: info: Volumio called home Feb 09 21:44:14 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:14 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:14 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:14 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:14 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:14 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:14 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:14 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:15 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:44:15 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 09 21:44:15 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:15 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 09 21:44:15 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 21:44:15 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:15 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:15 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:15 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:15 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:15 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:15 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:15 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:15 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 21:44:15 music go-librespot[16298]: go-librespot daemon starting... Feb 09 21:44:15 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:44:15 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:15 music sudo[16291]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:15 music volumio[16092]: info: No need to fix Spotify hosts Feb 09 21:44:15 music go-librespot[16303]: time="2026-02-09T21:44:15-05:00" level=info msg="running go-librespot 0.6.2" Feb 09 21:44:15 music go-librespot[16303]: time="2026-02-09T21:44:15-05:00" level=debug msg="app state loaded" Feb 09 21:44:15 music volumio[16194]: Starting albumart workers Feb 09 21:44:15 music go-librespot[16303]: time="2026-02-09T21:44:15-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 21:44:15 music go-librespot[16303]: time="2026-02-09T21:44:15-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 21:44:15 music go-librespot[16303]: time="2026-02-09T21:44:15-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 21:44:15 music go-librespot[16303]: time="2026-02-09T21:44:15-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 21:44:15 music go-librespot[16303]: time="2026-02-09T21:44:15-05:00" level=info msg="zeroconf server listening on port 32959" Feb 09 21:44:15 music go-librespot[16303]: time="2026-02-09T21:44:15-05:00" level=debug msg="obtained new client token: AACN5GOEal1TjotFytV1160/jGSjzHMzW42MypguVdpPZ8ZzSMrUv/3WCFpSBHGvM1SNwdynb0KP8uJsPmzbcEWOIZtk/FJWeZQsIskwtgVyNEW/tXc61gXIknat+4ajmqmDxyxmyTZ71phTBXUyIG4Jb92XYOJeUnqFg+xTqw9FVfdp7upEvMYc+f2cjhB0UMKF6j7/yHIUxHwrjLuKMc4YFGSDiaVybiDJ0ors3+Tu7y8z49M2VaM=" Feb 09 21:44:15 music volumio[16092]: info: Starting Shairport Sync Feb 09 21:44:15 music go-librespot[16303]: time="2026-02-09T21:44:15-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.255.62:4070: connect: connection refused" Feb 09 21:44:15 music volumio[16092]: info: Starting Shairport Sync Feb 09 21:44:15 music volumio[16092]: info: Starting Shairport Sync Feb 09 21:44:15 music go-librespot[16303]: time="2026-02-09T21:44:15-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 09 21:44:15 music sudo[16314]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 21:44:15 music sudo[16314]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:15 music volumio[16092]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 09 21:44:16 music sudo[16318]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 21:44:16 music sudo[16318]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:16 music go-librespot[16303]: time="2026-02-09T21:44:16-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:16 music go-librespot[16303]: time="2026-02-09T21:44:16-05:00" level=debug msg="completed challenge" Feb 09 21:44:16 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 09 21:44:16 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 09 21:44:16 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 21:44:16 music systemd[1]: shairport-sync.service: Consumed 1.896s CPU time. Feb 09 21:44:16 music sudo[16316]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 21:44:16 music sudo[16316]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:16 music go-librespot[16303]: time="2026-02-09T21:44:16-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:16 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 21:44:16 music sudo[16314]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:16 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 09 21:44:16 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 09 21:44:16 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 21:44:16 music volumio[16092]: info: Shairport-Sync Started Feb 09 21:44:16 music volumio[16092]: Error adding Membership: Error: addMembership EINVAL Feb 09 21:44:16 music volumio[16092]: info: CoreCommandRouter::volumioGetState Feb 09 21:44:16 music volumio[16092]: info: CorePlayQueue::getTrack 0 Feb 09 21:44:16 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 21:44:16 music sudo[16316]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:16 music sudo[16318]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:16 music volumio[16092]: info: Shairport-Sync Started Feb 09 21:44:16 music volumio[16092]: info: Shairport-Sync Started Feb 09 21:44:16 music go-librespot[16303]: time="2026-02-09T21:44:16-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 09 21:44:16 music go-librespot[16303]: time="2026-02-09T21:44:16-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:16 music go-librespot[16303]: time="2026-02-09T21:44:16-05:00" level=debug msg="completed challenge" Feb 09 21:44:16 music go-librespot[16303]: time="2026-02-09T21:44:16-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:17 music go-librespot[16303]: time="2026-02-09T21:44:17-05:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 21:44:17 music go-librespot[16303]: time="2026-02-09T21:44:17-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:17 music go-librespot[16303]: time="2026-02-09T21:44:17-05:00" level=debug msg="completed challenge" Feb 09 21:44:17 music go-librespot[16303]: time="2026-02-09T21:44:17-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:18 music mpd[16284]: 2026-02-09T21:44:18 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 09 21:44:18 music systemd[1]: Started mpd.service - Music Player Daemon. Feb 09 21:44:18 music sudo[16245]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:18 music sudo[16235]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:18 music volumio[16092]: info: Completed starting Core Plugins Feb 09 21:44:18 music volumio[16092]: info: ------------------------------------------- Feb 09 21:44:18 music volumio[16092]: info: ----- MyVolumio plugins startup ---- Feb 09 21:44:18 music volumio[16092]: info: ------------------------------------------- Feb 09 21:44:18 music volumio[16092]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 09 21:44:18 music volumio[16092]: error: MPD error: The expression evaluated to a falsy value: Feb 09 21:44:18 music volumio[16092]: assert.ok(self.idling) Feb 09 21:44:18 music volumio[16092]: error: The expression evaluated to a falsy value: Feb 09 21:44:18 music volumio[16092]: assert.ok(self.idling) Feb 09 21:44:18 music volumio[16092]: info: MPD running with PID16284 Feb 09 21:44:18 music volumio[16092]: ,establishing connection Feb 09 21:44:18 music volumio[16092]: error: updateQueue error: null Feb 09 21:44:18 music volumio[16092]: error: updateQueue error: null Feb 09 21:44:18 music go-librespot[16303]: time="2026-02-09T21:44:18-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 09 21:44:18 music volumio[16092]: info: go-librespot daemon successfully initialized Feb 09 21:44:18 music go-librespot[16303]: time="2026-02-09T21:44:18-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:18 music go-librespot[16303]: time="2026-02-09T21:44:18-05:00" level=debug msg="completed challenge" Feb 09 21:44:18 music sudo[16377]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 21:44:18 music sudo[16377]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:18 music go-librespot[16303]: time="2026-02-09T21:44:18-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:18 music sudo[16379]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 21:44:18 music sudo[16379]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:18 music sudo[16377]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:18 music sudo[16379]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:18 music sudo[16382]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 09 21:44:18 music sudo[16382]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:18 music sudo[16382]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:18 music volumio[16092]: info: Upmpdcli Daemon Started Feb 09 21:44:19 music go-librespot[16303]: time="2026-02-09T21:44:19-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 09 21:44:19 music go-librespot[16303]: time="2026-02-09T21:44:19-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:19 music go-librespot[16303]: time="2026-02-09T21:44:19-05:00" level=debug msg="completed challenge" Feb 09 21:44:19 music go-librespot[16303]: time="2026-02-09T21:44:19-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:20 music go-librespot[16303]: time="2026-02-09T21:44:20-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 09 21:44:20 music go-librespot[16303]: time="2026-02-09T21:44:20-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:20 music go-librespot[16303]: time="2026-02-09T21:44:20-05:00" level=debug msg="completed challenge" Feb 09 21:44:20 music go-librespot[16303]: time="2026-02-09T21:44:20-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:20 music go-librespot[16303]: time="2026-02-09T21:44:20-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:20 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 21:44:20 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 21:44:21 music sudo[16386]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 09 21:44:21 music sudo[16386]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:21 music sudo[16388]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 09 21:44:21 music sudo[16388]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:21 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 09 21:44:21 music systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 09 21:44:21 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 09 21:44:21 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 09 21:44:21 music sudo[16386]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:21 music mpd_monitor.sh[16391]: MPD Monitor Service: Starting MPD Monitor Service Feb 09 21:44:21 music volumio[16092]: info: Successfully started MPD Monitor Feb 09 21:44:21 music sudo[16388]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:21 music volumio[16092]: info: Successfully started MPD Monitor Feb 09 21:44:21 music volumio[16092]: info: Initializing connection to go-librespot Websocket Feb 09 21:44:21 music volumio[16092]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 21:44:23 music volumio[16092]: info: CoreCommandRouter::volumioGetState Feb 09 21:44:23 music volumio[16092]: info: CorePlayQueue::getTrack 0 Feb 09 21:44:23 music volumio[16092]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 09 21:44:23 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 09 21:44:23 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 21:44:23 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 21:44:23 music go-librespot[16395]: go-librespot daemon starting... Feb 09 21:44:23 music go-librespot[16396]: time="2026-02-09T21:44:23-05:00" level=info msg="running go-librespot 0.6.2" Feb 09 21:44:23 music go-librespot[16396]: time="2026-02-09T21:44:23-05:00" level=debug msg="app state loaded" Feb 09 21:44:23 music go-librespot[16396]: time="2026-02-09T21:44:23-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 21:44:23 music go-librespot[16396]: time="2026-02-09T21:44:23-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 21:44:23 music go-librespot[16396]: time="2026-02-09T21:44:23-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 21:44:23 music go-librespot[16396]: time="2026-02-09T21:44:23-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 21:44:23 music go-librespot[16396]: time="2026-02-09T21:44:23-05:00" level=info msg="zeroconf server listening on port 36181" Feb 09 21:44:24 music go-librespot[16396]: time="2026-02-09T21:44:24-05:00" level=debug msg="obtained new client token: AAB32Gb0Ry4b5W/7QdhnWSdXtNrc13netg0FNCacCHSH3uTozCEdyuHixooI9QYOncqigpY/H4b+qeoidLvibzo3cVizYtiML/tb6so10KWNH2ZdY0KkzuMaNJQI73BpoCtbB3LHZMcb4JrfkG8FxNf5cVs8v9FvqYaGRAf0OXrck1XzX2cMUsKkUW+FV/QD0ZBg7zqIwBegnxJoXVvmibBNdBojGxxUiNd4KWgVQdjYsdhQSu71" Feb 09 21:44:24 music go-librespot[16396]: time="2026-02-09T21:44:24-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 09 21:44:24 music go-librespot[16396]: time="2026-02-09T21:44:24-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:24 music go-librespot[16396]: time="2026-02-09T21:44:24-05:00" level=debug msg="completed challenge" Feb 09 21:44:24 music go-librespot[16396]: time="2026-02-09T21:44:24-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:24 music volumio[16092]: info: Initializing connection to go-librespot Websocket Feb 09 21:44:24 music go-librespot[16396]: time="2026-02-09T21:44:24-05:00" level=debug msg="new websocket client" Feb 09 21:44:24 music volumio[16092]: info: Connection to go-librespot Websocket established Feb 09 21:44:24 music go-librespot[16396]: time="2026-02-09T21:44:24-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 09 21:44:25 music go-librespot[16396]: time="2026-02-09T21:44:25-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:25 music go-librespot[16396]: time="2026-02-09T21:44:25-05:00" level=debug msg="completed challenge" Feb 09 21:44:25 music go-librespot[16396]: time="2026-02-09T21:44:25-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:25 music go-librespot[16396]: time="2026-02-09T21:44:25-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 09 21:44:25 music go-librespot[16396]: time="2026-02-09T21:44:25-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:25 music go-librespot[16396]: time="2026-02-09T21:44:25-05:00" level=debug msg="completed challenge" Feb 09 21:44:25 music go-librespot[16396]: time="2026-02-09T21:44:25-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:26 music go-librespot[16396]: time="2026-02-09T21:44:26-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 09 21:44:26 music go-librespot[16396]: time="2026-02-09T21:44:26-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:26 music go-librespot[16396]: time="2026-02-09T21:44:26-05:00" level=debug msg="completed challenge" Feb 09 21:44:26 music go-librespot[16396]: time="2026-02-09T21:44:26-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:26 music volumio[16092]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 09 21:44:26 music volumio[16092]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 09 21:44:26 music volumio[16092]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 09 21:44:26 music volumio[16092]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 09 21:44:26 music volumio[16092]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 09 21:44:26 music volumio[16092]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 09 21:44:26 music volumio[16092]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 09 21:44:26 music volumio[16092]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 09 21:44:26 music volumio[16092]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 09 21:44:26 music volumio[16092]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 09 21:44:26 music volumio[16092]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 09 21:44:26 music volumio[16092]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 09 21:44:26 music volumio[16092]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 09 21:44:26 music volumio[16092]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 09 21:44:26 music volumio[16092]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 09 21:44:26 music volumio[16092]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 09 21:44:26 music volumio[16092]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 09 21:44:26 music volumio[16092]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 09 21:44:26 music volumio[16092]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 09 21:44:26 music volumio[16092]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 09 21:44:26 music volumio[16092]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 09 21:44:26 music volumio[16092]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 09 21:44:26 music volumio[16092]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 09 21:44:26 music volumio[16092]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 09 21:44:26 music volumio[16092]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 09 21:44:26 music volumio[16092]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 09 21:44:26 music volumio[16092]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 09 21:44:26 music volumio[16092]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 09 21:44:26 music volumio[16092]: info: Adding plugin bluetooth to MyMusic Plugins Feb 09 21:44:26 music volumio[16092]: info: Adding plugin multiroom to MyMusic Plugins Feb 09 21:44:26 music volumio[16092]: info: Adding plugin metavolumio to MyMusic Plugins Feb 09 21:44:26 music volumio[16092]: info: Adding plugin cd_controller to MyMusic Plugins Feb 09 21:44:26 music volumio[16092]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 09 21:44:26 music volumio[16092]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 09 21:44:26 music volumio[16092]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 09 21:44:26 music volumio[16092]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 09 21:44:27 music go-librespot[16396]: time="2026-02-09T21:44:27-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 09 21:44:27 music volumio[16092]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 09 21:44:27 music volumio[16092]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 09 21:44:27 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:44:27 music volumio[16092]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:44:27 music volumio[16092]: info: Starting MyVolumio Remote Streaming Endpoints Feb 09 21:44:27 music volumio[16092]: info: MyVolumio login type: Token Feb 09 21:44:27 music go-librespot[16396]: time="2026-02-09T21:44:27-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:27 music go-librespot[16396]: time="2026-02-09T21:44:27-05:00" level=debug msg="completed challenge" Feb 09 21:44:27 music volumio[16092]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 09 21:44:27 music volumio[16092]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 09 21:44:27 music go-librespot[16396]: time="2026-02-09T21:44:27-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:28 music go-librespot[16396]: time="2026-02-09T21:44:28-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 09 21:44:28 music volumio[16092]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 09 21:44:28 music volumio[16092]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 09 21:44:28 music volumio[16092]: info: Streaming services startup Feb 09 21:44:28 music volumio[16092]: info: Starting Streaming Daemon Feb 09 21:44:28 music go-librespot[16396]: time="2026-02-09T21:44:28-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:28 music go-librespot[16396]: time="2026-02-09T21:44:28-05:00" level=debug msg="completed challenge" Feb 09 21:44:28 music sudo[16407]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 09 21:44:28 music sudo[16407]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:28 music volumio[16092]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 09 21:44:28 music sudo[16407]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:28 music volumio[16092]: info: Getting Spotify volume Feb 09 21:44:28 music go-librespot[16396]: time="2026-02-09T21:44:28-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:28 music go-librespot[16396]: time="2026-02-09T21:44:28-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:28 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 21:44:28 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 21:44:28 music volumio[16092]: error: Cannot start Volumio Streaming Daemon Feb 09 21:44:28 music volumio[16092]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 09 21:44:28 music volumio[16092]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 09 21:44:28 music volumio[16092]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 21:44:28 music volumio[16092]: Error: socket hang up Feb 09 21:44:28 music volumio[16092]: at connResetException (node:internal/errors:720:14) Feb 09 21:44:28 music volumio[16092]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 09 21:44:28 music volumio[16092]: at Socket.emit (node:events:526:35) Feb 09 21:44:28 music volumio[16092]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 09 21:44:28 music volumio[16092]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 09 21:44:28 music volumio[16092]: code: 'ECONNRESET', Feb 09 21:44:28 music volumio[16092]: response: undefined Feb 09 21:44:28 music volumio[16092]: } Feb 09 21:44:28 music volumio[16092]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 21:44:29 music sudo[16441]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-09 21:43' Feb 09 21:44:29 music sudo[16441]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:29 music sudo[16441]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:29 music volumio-remote-updater[30265]: [2026-02-09 21:44:29] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 09 21:44:29 music volumio-remote-updater[30265]: [2026-02-09 21:44:29] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 09 21:44:29 music systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 09 21:44:29 music systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 09 21:44:29 music systemd[1]: volumio.service: Consumed 26.618s CPU time. Feb 09 21:44:29 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 09 21:44:29 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 09 21:44:30 music systemd[1]: volumio.service: Scheduled restart job, restart counter is at 53396. Feb 09 21:44:30 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 09 21:44:30 music systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 09 21:44:30 music systemd[1]: volumio.service: Consumed 26.618s CPU time. Feb 09 21:44:30 music systemd[1]: Started volumio.service - Volumio Backend Module. Feb 09 21:44:30 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 09 21:44:31 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 09 21:44:31 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 21:44:31 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 21:44:31 music go-librespot[16468]: go-librespot daemon starting... Feb 09 21:44:31 music go-librespot[16469]: time="2026-02-09T21:44:31-05:00" level=info msg="running go-librespot 0.6.2" Feb 09 21:44:31 music go-librespot[16469]: time="2026-02-09T21:44:31-05:00" level=debug msg="app state loaded" Feb 09 21:44:31 music go-librespot[16469]: time="2026-02-09T21:44:31-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 21:44:32 music volumio[16453]: info: ------------------------------------------- Feb 09 21:44:32 music volumio[16453]: info: ----- Volumio3 ---- Feb 09 21:44:32 music volumio[16453]: info: ------------------------------------------- Feb 09 21:44:32 music volumio[16453]: info: ----- System startup ---- Feb 09 21:44:32 music volumio[16453]: info: ------------------------------------------- Feb 09 21:44:32 music go-librespot[16469]: time="2026-02-09T21:44:32-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 21:44:32 music go-librespot[16469]: time="2026-02-09T21:44:32-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 21:44:32 music go-librespot[16469]: time="2026-02-09T21:44:32-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 21:44:32 music go-librespot[16469]: time="2026-02-09T21:44:32-05:00" level=info msg="zeroconf server listening on port 46469" Feb 09 21:44:32 music go-librespot[16469]: time="2026-02-09T21:44:32-05:00" level=debug msg="obtained new client token: AAAGUe0pYN4hALJ79V2Lbqq6TKw5ncMUw3fVU5Gm/qY+7VwPSAA5z4wB0LOGEAY0QAvsnbxelD5tEPGk9roi/CsGRzFkqq4PPrLSJhGT4pdtE383Xuv2oILNk8TzooZj+y3fCUO38ROf9nheUWNaWSwWXEW7DOvdhF+RhX55VkYEhnbmIA0isfNBpI61Rea8FfdeuQCEvU5kOcButu8Xazxarkb4nTLi8tRT1YqjgvC0OvUsMd6/A8o=" Feb 09 21:44:32 music go-librespot[16469]: time="2026-02-09T21:44:32-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.255.62:4070: connect: connection refused" Feb 09 21:44:32 music go-librespot[16469]: time="2026-02-09T21:44:32-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.255.62:443: connect: connection refused" Feb 09 21:44:32 music go-librespot[16469]: time="2026-02-09T21:44:32-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 09 21:44:32 music go-librespot[16469]: time="2026-02-09T21:44:32-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:32 music go-librespot[16469]: time="2026-02-09T21:44:32-05:00" level=debug msg="completed challenge" Feb 09 21:44:32 music go-librespot[16469]: time="2026-02-09T21:44:32-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:32 music volumio[16453]: info: MYVOLUMIO Environment detected Feb 09 21:44:33 music volumio[16453]: info: Plugin folders cleanup Feb 09 21:44:33 music volumio[16453]: info: Scanning into folder /volumio/app/plugins/ Feb 09 21:44:33 music volumio[16453]: info: Scanning category audio_interface Feb 09 21:44:33 music volumio[16453]: info: Scanning category miscellanea Feb 09 21:44:33 music volumio[16453]: info: Scanning category music_service Feb 09 21:44:33 music volumio[16453]: info: Scanning category plugins.json Feb 09 21:44:33 music volumio[16453]: info: Scanning category system_controller Feb 09 21:44:33 music volumio[16453]: info: Scanning category user_interface Feb 09 21:44:33 music volumio[16453]: info: Scanning into folder /data/plugins/ Feb 09 21:44:33 music volumio[16453]: info: Scanning category music_service Feb 09 21:44:33 music volumio[16453]: info: Plugin folders cleanup completed Feb 09 21:44:33 music volumio[16453]: info: ------------------------------------------- Feb 09 21:44:33 music volumio[16453]: info: ----- Core plugins startup ---- Feb 09 21:44:33 music volumio[16453]: info: ------------------------------------------- Feb 09 21:44:33 music volumio[16453]: info: Loading plugins from folder /volumio/app/plugins/ Feb 09 21:44:33 music volumio[16453]: info: Adding plugin upnp to MyMusic Plugins Feb 09 21:44:33 music volumio[16453]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 09 21:44:33 music volumio[16453]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 09 21:44:33 music volumio[16453]: info: Loading plugins from folder /data/plugins/ Feb 09 21:44:33 music volumio[16453]: info: Loading plugin "system"... Feb 09 21:44:33 music volumio[16453]: info: Loading plugin "appearance"... Feb 09 21:44:33 music go-librespot[16469]: time="2026-02-09T21:44:33-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 09 21:44:33 music go-librespot[16469]: time="2026-02-09T21:44:33-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:33 music go-librespot[16469]: time="2026-02-09T21:44:33-05:00" level=debug msg="completed challenge" Feb 09 21:44:33 music go-librespot[16469]: time="2026-02-09T21:44:33-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:34 music go-librespot[16469]: time="2026-02-09T21:44:34-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 09 21:44:34 music volumio[16453]: info: Loading plugin "network"... Feb 09 21:44:34 music volumio[16453]: info: Refreshing Cached IP Addresses Feb 09 21:44:34 music sudo[16491]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 21:44:34 music sudo[16491]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:34 music sudo[16491]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:34 music volumio[16453]: info: Loading plugin "services"... Feb 09 21:44:34 music sudo[16493]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 21:44:34 music sudo[16493]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:34 music volumio[16453]: info: Loading plugin "alsa_controller"... Feb 09 21:44:34 music sudo[16493]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:34 music sudo[16503]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 09 21:44:34 music sudo[16503]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:34 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 21:44:34 music volumio[16453]: info: Loading plugin "wizard"... Feb 09 21:44:34 music volumio[16453]: info: Loading plugin "networkfs"... Feb 09 21:44:34 music volumio[16453]: info: Starting Udev Watcher for removable devices Feb 09 21:44:34 music volumio[16453]: info: Ignoring mount for partition: boot Feb 09 21:44:34 music volumio[16453]: info: Ignoring mount for partition: volumio Feb 09 21:44:34 music volumio[16453]: info: Ignoring mount for partition: volumio_data Feb 09 21:44:34 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 21:44:34 music volumio[16453]: info: Loading plugin "volumio_command_line_client"... Feb 09 21:44:34 music volumio[16453]: info: Loading plugin "upnp"... Feb 09 21:44:34 music volumio[16453]: info: [1770691474426] Starting Upmpd Daemon Feb 09 21:44:34 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 21:44:34 music volumio[16453]: info: Loading plugin "my_music"... Feb 09 21:44:34 music volumio[16453]: info: Loading plugin "mpd"... Feb 09 21:44:34 music go-librespot[16469]: time="2026-02-09T21:44:34-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:34 music go-librespot[16469]: time="2026-02-09T21:44:34-05:00" level=debug msg="completed challenge" Feb 09 21:44:34 music volumio-remote-updater[30265]: [2026-02-09 21:44:34] [connect] Successful connection Feb 09 21:44:34 music volumio[16453]: info: Loading plugin "upnp_browser"... Feb 09 21:44:34 music go-librespot[16469]: time="2026-02-09T21:44:34-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:34 music sudo[16503]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:35 music go-librespot[16469]: time="2026-02-09T21:44:35-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 09 21:44:35 music go-librespot[16469]: time="2026-02-09T21:44:35-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:35 music go-librespot[16469]: time="2026-02-09T21:44:35-05:00" level=debug msg="completed challenge" Feb 09 21:44:35 music go-librespot[16469]: time="2026-02-09T21:44:35-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:36 music go-librespot[16469]: time="2026-02-09T21:44:36-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 09 21:44:36 music go-librespot[16469]: time="2026-02-09T21:44:36-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:36 music go-librespot[16469]: time="2026-02-09T21:44:36-05:00" level=debug msg="completed challenge" Feb 09 21:44:36 music volumio[16453]: info: Starting UPNP Browser Feb 09 21:44:36 music volumio[16453]: info: Loading plugin "alarm-clock"... Feb 09 21:44:36 music go-librespot[16469]: time="2026-02-09T21:44:36-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:36 music volumio[16453]: info: Loading plugin "airplay_emulation"... Feb 09 21:44:36 music volumio[16453]: info: Starting Shairport Sync Feb 09 21:44:36 music volumio[16453]: info: Loading plugin "last_100"... Feb 09 21:44:36 music volumio[16453]: info: Loading plugin "webradio"... Feb 09 21:44:36 music volumio[16453]: info: Loading plugin "i2s_dacs"... Feb 09 21:44:36 music volumio[16453]: info: I2S DAC not set, start Auto-detection Feb 09 21:44:36 music volumio[16453]: info: Loading plugin "volumiodiscovery"... Feb 09 21:44:36 music volumio[16453]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 21:44:36 music volumio[16453]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 21:44:36 music volumio[16453]: *** WARNING *** For more information see Feb 09 21:44:36 music volumio[16453]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 21:44:36 music volumio[16453]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 21:44:36 music volumio[16453]: *** WARNING *** For more information see Feb 09 21:44:36 music node[16453]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 21:44:36 music node[16453]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 21:44:36 music node[16453]: *** WARNING *** For more information see Feb 09 21:44:36 music node[16453]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 21:44:36 music node[16453]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 21:44:36 music node[16453]: *** WARNING *** For more information see Feb 09 21:44:36 music volumio[16453]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 09 21:44:36 music volumio[16453]: info: Discovery: Started advertising with name: music Feb 09 21:44:36 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 21:44:36 music volumio[16453]: info: Loading plugin "spop"... Feb 09 21:44:36 music go-librespot[16469]: time="2026-02-09T21:44:36-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 09 21:44:37 music go-librespot[16469]: time="2026-02-09T21:44:37-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:37 music go-librespot[16469]: time="2026-02-09T21:44:37-05:00" level=debug msg="completed challenge" Feb 09 21:44:37 music go-librespot[16469]: time="2026-02-09T21:44:37-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:37 music go-librespot[16469]: time="2026-02-09T21:44:37-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:37 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 21:44:37 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 21:44:37 music volumio[16453]: info: Loading plugin "outputs"... Feb 09 21:44:37 music volumio[16453]: info: Loading plugin "albumart"... Feb 09 21:44:37 music volumio[16453]: info: Plugin example_plugin is not enabled Feb 09 21:44:37 music volumio[16453]: info: Loading plugin "inputs"... Feb 09 21:44:37 music volumio[16453]: info: Loading plugin "updater_comm"... Feb 09 21:44:38 music volumio[16453]: info: Plugin mpdemulation is not enabled Feb 09 21:44:38 music volumio[16453]: info: Loading plugin "rest_api"... Feb 09 21:44:38 music volumio[16453]: info: Loading plugin "websocket"... Feb 09 21:44:38 music volumio[16453]: info: Starting Socket.io Server version 1.7.4 Feb 09 21:44:38 music volumio[16453]: info: Loading i18n strings for locale en Feb 09 21:44:38 music volumio[16453]: Updating browse sources language Feb 09 21:44:38 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 21:44:38 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 21:44:38 music volumio[16453]: info: CoreCommandRouter::initPlayerControls Feb 09 21:44:38 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:38 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:38 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:38 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:38 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:38 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:38 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:38 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:38 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 21:44:38 music volumio[16453]: Express server listening on port 3000 Feb 09 21:44:38 music volumio[16453]: [Metrics] WebUI: 6s 673.32ms Feb 09 21:44:38 music volumio[16453]: info: CoreStateMachine::resetVolumioState Feb 09 21:44:38 music volumio[16453]: info: CoreStateMachine::getcurrentVolume Feb 09 21:44:38 music volumio[16453]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 21:44:38 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:44:38 music volumio[16453]: info: Volumio Network Manager: Network status updated: 1 Feb 09 21:44:38 music volumio[16453]: info: VolumeController:: Volume=86 Mute =false Feb 09 21:44:38 music volumio[16453]: info: CoreStateMachine::pushState Feb 09 21:44:38 music volumio[16453]: info: CorePlayQueue::getTrack 0 Feb 09 21:44:38 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 21:44:38 music volumio[16453]: info: CoreCommandRouter::volumioPushState Feb 09 21:44:38 music volumio[16453]: info: CoreStateMachine::updateTrackBlock Feb 09 21:44:38 music volumio[16453]: info: CorePlayQueue::getTrackBlock Feb 09 21:44:38 music volumio[16453]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 21:44:38 music volumio[16526]: Forking 3 albumart workers Feb 09 21:44:38 music volumio[16453]: info: CoreCommandRouter::volumioGetState Feb 09 21:44:38 music volumio[16453]: info: CorePlayQueue::getTrack 0 Feb 09 21:44:38 music volumio-remote-updater[30265]: [2026-02-09 21:44:38] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770691474 101 Feb 09 21:44:38 music volumio[16453]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 09 21:44:38 music volumio[16453]: info: Reloading queue from file Feb 09 21:44:38 music volumio[16453]: info: CoreStateMachine::setRepeat null single undefined Feb 09 21:44:38 music volumio[16453]: info: CoreStateMachine::pushState Feb 09 21:44:38 music volumio[16453]: info: CorePlayQueue::getTrack 0 Feb 09 21:44:38 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 21:44:38 music volumio[16453]: info: CoreCommandRouter::volumioPushState Feb 09 21:44:38 music volumio[16453]: info: CoreStateMachine::setRandom null Feb 09 21:44:38 music volumio[16453]: info: CoreStateMachine::pushState Feb 09 21:44:38 music volumio[16453]: info: CorePlayQueue::getTrack 0 Feb 09 21:44:38 music volumio[16453]: info: CoreCommandRouter::volumioPushState Feb 09 21:44:38 music volumio[16453]: info: Setting Device type: Raspberry PI Feb 09 21:44:38 music volumio[16453]: info: Listing playlists Feb 09 21:44:38 music volumio[16453]: info: Listing playlists Feb 09 21:44:38 music volumio[16453]: info: VolumeController:: Volume=86 Mute =false Feb 09 21:44:38 music volumio[16453]: info: CoreStateMachine::pushState Feb 09 21:44:38 music volumio[16453]: info: CorePlayQueue::getTrack 0 Feb 09 21:44:38 music volumio[16453]: info: CoreCommandRouter::volumioPushState Feb 09 21:44:38 music volumio[16453]: info: Completed loading Core Plugins Feb 09 21:44:38 music volumio[16453]: info: Preparing to generate the ALSA configuration file Feb 09 21:44:38 music volumio[16453]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 09 21:44:38 music volumio[16453]: info: Discovery: Found device music Feb 09 21:44:38 music volumio[16453]: info: CoreCommandRouter::volumioGetState Feb 09 21:44:38 music volumio[16453]: info: CorePlayQueue::getTrack 0 Feb 09 21:44:38 music volumio[16453]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 09 21:44:38 music volumio[16453]: info: Discovery: Found device music Feb 09 21:44:38 music volumio[16453]: info: CoreCommandRouter::volumioGetState Feb 09 21:44:38 music volumio[16453]: info: CorePlayQueue::getTrack 0 Feb 09 21:44:38 music volumio[16453]: info: Asound.conf file unchanged, so no further update is needed Feb 09 21:44:38 music volumio[16453]: info: Output device has changed, restarting MPD Feb 09 21:44:38 music volumio[16453]: info: Output device has changed, restarting Shairport Sync Feb 09 21:44:38 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:38 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:44:38 music sudo[16581]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 21:44:38 music sudo[16581]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:38 music sudo[16581]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:38 music sudo[16583]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 21:44:38 music sudo[16583]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:38 music volumio[16453]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 21:44:38 music volumio[16453]: info: ___________ START PLUGINS ___________ Feb 09 21:44:38 music volumio[16453]: info: ControllerMpd::onStart: Initializing MPD Feb 09 21:44:38 music volumio[16453]: info: Creating MPD Configuration file Feb 09 21:44:38 music systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 09 21:44:39 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 21:44:39 music systemd[1]: mpd.service: Deactivated successfully. Feb 09 21:44:39 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 09 21:44:39 music systemd[1]: mpd.service: Consumed 4.166s CPU time. Feb 09 21:44:39 music systemd[1]: mpd.socket: Deactivated successfully. Feb 09 21:44:39 music volumio[16453]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 21:44:39 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 09 21:44:39 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 09 21:44:39 music volumio[16453]: info: [1770691479043] CoreMusicLibrary::Adding element Media Servers Feb 09 21:44:39 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 21:44:39 music sudo[16591]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 21:44:39 music sudo[16591]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:39 music sudo[16593]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 21:44:39 music sudo[16593]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:39 music sudo[16591]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:39 music volumio[16453]: info: UPNP Browser: Client initialized successfully Feb 09 21:44:39 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:39 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:44:39 music volumio[16453]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 21:44:39 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 09 21:44:39 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:39 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:44:39 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 09 21:44:39 music systemd[1]: mpd.service: Deactivated successfully. Feb 09 21:44:39 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 09 21:44:39 music systemd[1]: mpd.socket: Deactivated successfully. Feb 09 21:44:39 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 09 21:44:39 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 09 21:44:39 music volumio[16453]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 21:44:39 music volumio[16453]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 21:44:39 music volumio[16453]: info: [1770691479251] CoreMusicLibrary::Adding element Last_100 Feb 09 21:44:39 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 21:44:39 music volumio[16453]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 21:44:39 music volumio[16453]: info: [1770691479256] CoreMusicLibrary::Adding element Webradio Feb 09 21:44:39 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 21:44:39 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 21:44:39 music volumio[16453]: info: Initializing BBC Radios Feb 09 21:44:39 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 09 21:44:39 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 09 21:44:39 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 21:44:39 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:44:39 music volumio[16453]: info: Creating Spotify config file Feb 09 21:44:39 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:39 music sudo[16613]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 09 21:44:39 music sudo[16613]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 09 21:44:39 music sudo[16613]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:39 music volumio[16453]: info: Volumio Calling Home Feb 09 21:44:40 music volumio[16545]: Starting albumart workers Feb 09 21:44:40 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 09 21:44:40 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 21:44:40 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 21:44:40 music go-librespot[16627]: go-librespot daemon starting... Feb 09 21:44:40 music volumio[16543]: Starting albumart workers Feb 09 21:44:40 music go-librespot[16628]: time="2026-02-09T21:44:40-05:00" level=info msg="running go-librespot 0.6.2" Feb 09 21:44:40 music volumio[16544]: Starting albumart workers Feb 09 21:44:40 music volumio[16453]: info: MPD Permissions set Feb 09 21:44:40 music volumio[16453]: info: MPD Permissions set Feb 09 21:44:40 music volumio[16453]: info: Volumio called home Feb 09 21:44:40 music volumio[16453]: info: Spotify config file written Feb 09 21:44:40 music sudo[16636]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 09 21:44:40 music sudo[16636]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:40 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 09 21:44:40 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 09 21:44:40 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 21:44:40 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 21:44:41 music volumio[16453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 09 21:44:41 music go-librespot[16638]: go-librespot daemon starting... Feb 09 21:44:41 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:41 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:41 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:41 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:41 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:41 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:41 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:41 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:41 music sudo[16636]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:41 music go-librespot[16639]: time="2026-02-09T21:44:41-05:00" level=info msg="running go-librespot 0.6.2" Feb 09 21:44:41 music go-librespot[16639]: time="2026-02-09T21:44:41-05:00" level=debug msg="app state loaded" Feb 09 21:44:41 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:44:41 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:41 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:41 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:41 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:41 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:41 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:41 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:41 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:41 music go-librespot[16639]: time="2026-02-09T21:44:41-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 21:44:41 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:41 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:44:41 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:44:41 music volumio[16453]: info: No need to fix Spotify hosts Feb 09 21:44:41 music go-librespot[16639]: time="2026-02-09T21:44: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 21:44:41 music go-librespot[16639]: time="2026-02-09T21:44:41-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 21:44:41 music go-librespot[16639]: time="2026-02-09T21:44:41-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 21:44:41 music go-librespot[16639]: time="2026-02-09T21:44:41-05:00" level=info msg="zeroconf server listening on port 45419" Feb 09 21:44:41 music go-librespot[16639]: time="2026-02-09T21:44:41-05:00" level=debug msg="obtained new client token: AAChxY3swxAUObeyOYoTwmZHnsF6s+XaapBDByhXy+5YKu2IZU+Gw8oz40u5HDwo2OFrVSkluG4Pdl7VcvP5AOsH+N5QJgnPQ2qPHHIST92TwjMEibFzDiY0fioJ9/L0K6h1gZAs0ndfONXyfFpwzf+xn/m6rvEzMUBzWP41iAkZvFCX+HUAl37fOyM5G6MDb6IIJevOArOfj+W+TezMfP74P5idZ0KQbbMuIHDPL6/yodlQULUKgdE=" Feb 09 21:44:41 music go-librespot[16639]: time="2026-02-09T21:44:41-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.255.62:4070: connect: connection refused" Feb 09 21:44:41 music volumio[16453]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 09 21:44:41 music volumio[16453]: info: Starting Shairport Sync Feb 09 21:44:41 music volumio[16453]: info: Starting Shairport Sync Feb 09 21:44:41 music go-librespot[16639]: time="2026-02-09T21:44:41-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 09 21:44:41 music volumio[16453]: info: Starting Shairport Sync Feb 09 21:44:41 music sudo[16679]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 21:44:41 music sudo[16681]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 21:44:41 music sudo[16681]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:41 music sudo[16679]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:41 music sudo[16683]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 21:44:41 music sudo[16683]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:41 music go-librespot[16639]: time="2026-02-09T21:44:41-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:41 music go-librespot[16639]: time="2026-02-09T21:44:41-05:00" level=debug msg="completed challenge" Feb 09 21:44:42 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 09 21:44:42 music volumio[16453]: info: CoreCommandRouter::volumioGetState Feb 09 21:44:42 music volumio[16453]: info: CorePlayQueue::getTrack 0 Feb 09 21:44:42 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 09 21:44:42 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 21:44:42 music systemd[1]: shairport-sync.service: Consumed 1.851s CPU time. Feb 09 21:44:42 music go-librespot[16639]: time="2026-02-09T21:44:42-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:42 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 21:44:42 music sudo[16679]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:42 music sudo[16681]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:42 music volumio[16453]: info: Shairport-Sync Started Feb 09 21:44:42 music volumio[16453]: Error adding Membership: Error: addMembership EINVAL Feb 09 21:44:42 music volumio[16453]: info: Shairport-Sync Started Feb 09 21:44:42 music sudo[16683]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:42 music volumio[16453]: info: Shairport-Sync Started Feb 09 21:44:42 music go-librespot[16639]: time="2026-02-09T21:44:42-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 09 21:44:42 music go-librespot[16639]: time="2026-02-09T21:44:42-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:42 music go-librespot[16639]: time="2026-02-09T21:44:42-05:00" level=debug msg="completed challenge" Feb 09 21:44:42 music go-librespot[16639]: time="2026-02-09T21:44:42-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:43 music volumio[16453]: info: CoreCommandRouter::volumioGetState Feb 09 21:44:43 music volumio[16453]: info: CorePlayQueue::getTrack 0 Feb 09 21:44:43 music go-librespot[16639]: time="2026-02-09T21:44:43-05:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Feb 09 21:44:43 music go-librespot[16639]: time="2026-02-09T21:44:43-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 09 21:44:43 music go-librespot[16639]: time="2026-02-09T21:44:43-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:43 music go-librespot[16639]: time="2026-02-09T21:44:43-05:00" level=debug msg="completed challenge" Feb 09 21:44:43 music go-librespot[16639]: time="2026-02-09T21:44:43-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:43 music mpd[16623]: 2026-02-09T21:44:43 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 09 21:44:43 music systemd[1]: Started mpd.service - Music Player Daemon. Feb 09 21:44:43 music sudo[16593]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:43 music sudo[16583]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:43 music volumio[16453]: info: Completed starting Core Plugins Feb 09 21:44:43 music volumio[16453]: info: ------------------------------------------- Feb 09 21:44:43 music volumio[16453]: info: ----- MyVolumio plugins startup ---- Feb 09 21:44:43 music volumio[16453]: info: ------------------------------------------- Feb 09 21:44:43 music volumio[16453]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 09 21:44:43 music volumio[16453]: error: MPD error: The expression evaluated to a falsy value: Feb 09 21:44:43 music volumio[16453]: assert.ok(self.idling) Feb 09 21:44:43 music volumio[16453]: error: The expression evaluated to a falsy value: Feb 09 21:44:43 music volumio[16453]: assert.ok(self.idling) Feb 09 21:44:43 music volumio[16453]: error: updateQueue error: null Feb 09 21:44:43 music volumio[16453]: info: MPD running with PID16623 Feb 09 21:44:43 music volumio[16453]: ,establishing connection Feb 09 21:44:43 music volumio[16453]: error: updateQueue error: null Feb 09 21:44:44 music go-librespot[16639]: time="2026-02-09T21:44:44-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 09 21:44:44 music go-librespot[16639]: time="2026-02-09T21:44:44-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:44 music go-librespot[16639]: time="2026-02-09T21:44:44-05:00" level=debug msg="completed challenge" Feb 09 21:44:44 music sudo[16723]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 21:44:44 music sudo[16723]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:44 music sudo[16723]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:44 music sudo[16725]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 21:44:44 music sudo[16725]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:44 music sudo[16725]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:44 music sudo[16728]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 09 21:44:44 music sudo[16728]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:44 music sudo[16728]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:44 music volumio[16453]: info: Upmpdcli Daemon Started Feb 09 21:44:44 music go-librespot[16639]: time="2026-02-09T21:44:44-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:44 music volumio[16453]: info: go-librespot daemon successfully initialized Feb 09 21:44:45 music go-librespot[16639]: time="2026-02-09T21:44:45-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 09 21:44:45 music go-librespot[16639]: time="2026-02-09T21:44:45-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:45 music go-librespot[16639]: time="2026-02-09T21:44:45-05:00" level=debug msg="completed challenge" Feb 09 21:44:45 music go-librespot[16639]: time="2026-02-09T21:44:45-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:45 music go-librespot[16639]: time="2026-02-09T21:44:45-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 09 21:44:45 music go-librespot[16639]: time="2026-02-09T21:44:45-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:45 music go-librespot[16639]: time="2026-02-09T21:44:45-05:00" level=debug msg="completed challenge" Feb 09 21:44:45 music go-librespot[16639]: time="2026-02-09T21:44:45-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:45 music go-librespot[16639]: time="2026-02-09T21:44:45-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:45 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 21:44:45 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 21:44:46 music sudo[16732]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 09 21:44:46 music sudo[16732]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:46 music sudo[16734]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 09 21:44:46 music sudo[16734]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:46 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 09 21:44:46 music systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 09 21:44:46 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 09 21:44:46 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 09 21:44:46 music sudo[16732]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:46 music sudo[16734]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:46 music mpd_monitor.sh[16737]: MPD Monitor Service: Starting MPD Monitor Service Feb 09 21:44:46 music volumio[16453]: info: Successfully started MPD Monitor Feb 09 21:44:46 music volumio[16453]: info: Successfully started MPD Monitor Feb 09 21:44:47 music volumio[16453]: info: Initializing connection to go-librespot Websocket Feb 09 21:44:47 music volumio[16453]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 21:44:48 music volumio[16453]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 09 21:44:49 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 09 21:44:49 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 21:44:49 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 21:44:49 music go-librespot[16741]: go-librespot daemon starting... Feb 09 21:44:49 music go-librespot[16742]: time="2026-02-09T21:44:49-05:00" level=info msg="running go-librespot 0.6.2" Feb 09 21:44:49 music go-librespot[16742]: time="2026-02-09T21:44:49-05:00" level=debug msg="app state loaded" Feb 09 21:44:49 music go-librespot[16742]: time="2026-02-09T21:44:49-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 21:44:49 music go-librespot[16742]: time="2026-02-09T21:44:49-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 21:44:49 music go-librespot[16742]: time="2026-02-09T21:44:49-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 21:44:49 music go-librespot[16742]: time="2026-02-09T21:44:49-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 21:44:49 music go-librespot[16742]: time="2026-02-09T21:44:49-05:00" level=info msg="zeroconf server listening on port 43091" Feb 09 21:44:49 music go-librespot[16742]: time="2026-02-09T21:44:49-05:00" level=debug msg="obtained new client token: AAC0xe+UdkQq3EmR17u2ptqaNGL2xF5uavOg5A9RaMvj+BSOww6xWaFOqWs6DfcZ6xBOFhFgXeMPZ+Hr0FWq/ruQXKzWDTuyBDRYPoMXkRwj9lIn6JBCDU58CUCmT0oe9ylJ8EOgICEFRkCRkaLg4JNzcOBJx/kVPPgfcRiOHIegBF574RiYXKEnCIBBCtrfiBjdDJyuZNzYJtjUVIv+uP1x8Xt3Qd0EPp5bqdq12IOIZ3LzefvjtnU=" Feb 09 21:44:49 music go-librespot[16742]: time="2026-02-09T21:44:49-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 09 21:44:49 music go-librespot[16742]: time="2026-02-09T21:44:49-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:49 music go-librespot[16742]: time="2026-02-09T21:44:49-05:00" level=debug msg="completed challenge" Feb 09 21:44:49 music go-librespot[16742]: time="2026-02-09T21:44:49-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:50 music go-librespot[16742]: time="2026-02-09T21:44:50-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 09 21:44:50 music go-librespot[16742]: time="2026-02-09T21:44:50-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:50 music go-librespot[16742]: time="2026-02-09T21:44:50-05:00" level=debug msg="completed challenge" Feb 09 21:44:50 music go-librespot[16742]: time="2026-02-09T21:44:50-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:50 music volumio[16453]: info: Initializing connection to go-librespot Websocket Feb 09 21:44:50 music go-librespot[16742]: time="2026-02-09T21:44:50-05:00" level=debug msg="new websocket client" Feb 09 21:44:50 music volumio[16453]: info: Connection to go-librespot Websocket established Feb 09 21:44:51 music go-librespot[16742]: time="2026-02-09T21:44:51-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 09 21:44:51 music go-librespot[16742]: time="2026-02-09T21:44:51-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:51 music go-librespot[16742]: time="2026-02-09T21:44:51-05:00" level=debug msg="completed challenge" Feb 09 21:44:51 music go-librespot[16742]: time="2026-02-09T21:44:51-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:51 music go-librespot[16742]: time="2026-02-09T21:44:51-05:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Feb 09 21:44:51 music go-librespot[16742]: time="2026-02-09T21:44:51-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 09 21:44:51 music volumio[16453]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 09 21:44:51 music volumio[16453]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 09 21:44:51 music volumio[16453]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 09 21:44:51 music volumio[16453]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 09 21:44:51 music volumio[16453]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 09 21:44:51 music volumio[16453]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 09 21:44:51 music volumio[16453]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 09 21:44:51 music volumio[16453]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 09 21:44:51 music volumio[16453]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 09 21:44:51 music volumio[16453]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 09 21:44:51 music volumio[16453]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 09 21:44:51 music volumio[16453]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 09 21:44:51 music volumio[16453]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 09 21:44:51 music volumio[16453]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 09 21:44:51 music volumio[16453]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 09 21:44:51 music volumio[16453]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 09 21:44:51 music volumio[16453]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 09 21:44:51 music volumio[16453]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 09 21:44:51 music volumio[16453]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 09 21:44:51 music volumio[16453]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 09 21:44:51 music volumio[16453]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 09 21:44:51 music volumio[16453]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 09 21:44:51 music volumio[16453]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 09 21:44:51 music volumio[16453]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 09 21:44:51 music volumio[16453]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 09 21:44:51 music volumio[16453]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 09 21:44:51 music volumio[16453]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 09 21:44:51 music volumio[16453]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 09 21:44:51 music volumio[16453]: info: Adding plugin bluetooth to MyMusic Plugins Feb 09 21:44:51 music volumio[16453]: info: Adding plugin multiroom to MyMusic Plugins Feb 09 21:44:51 music volumio[16453]: info: Adding plugin metavolumio to MyMusic Plugins Feb 09 21:44:51 music volumio[16453]: info: Adding plugin cd_controller to MyMusic Plugins Feb 09 21:44:51 music volumio[16453]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 09 21:44:51 music volumio[16453]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 09 21:44:51 music volumio[16453]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 09 21:44:51 music volumio[16453]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 09 21:44:52 music go-librespot[16742]: time="2026-02-09T21:44:52-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:52 music go-librespot[16742]: time="2026-02-09T21:44:52-05:00" level=debug msg="completed challenge" Feb 09 21:44:52 music go-librespot[16742]: time="2026-02-09T21:44:52-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:52 music go-librespot[16742]: time="2026-02-09T21:44:52-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 09 21:44:52 music go-librespot[16742]: time="2026-02-09T21:44:52-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:52 music go-librespot[16742]: time="2026-02-09T21:44:52-05:00" level=debug msg="completed challenge" Feb 09 21:44:53 music volumio[16453]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 09 21:44:53 music volumio[16453]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 09 21:44:53 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:44:53 music volumio[16453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:44:53 music volumio[16453]: info: Starting MyVolumio Remote Streaming Endpoints Feb 09 21:44:53 music go-librespot[16742]: time="2026-02-09T21:44:53-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:53 music volumio[16453]: info: MyVolumio login type: Token Feb 09 21:44:53 music volumio[16453]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 09 21:44:53 music volumio[16453]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 09 21:44:53 music go-librespot[16742]: time="2026-02-09T21:44:53-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 09 21:44:53 music go-librespot[16742]: time="2026-02-09T21:44:53-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:53 music go-librespot[16742]: time="2026-02-09T21:44:53-05:00" level=debug msg="completed challenge" Feb 09 21:44:53 music go-librespot[16742]: time="2026-02-09T21:44:53-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:53 music go-librespot[16742]: time="2026-02-09T21:44:53-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:53 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 21:44:53 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 21:44:54 music volumio[16453]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 09 21:44:54 music volumio[16453]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 09 21:44:54 music volumio[16453]: info: Streaming services startup Feb 09 21:44:54 music volumio[16453]: info: Starting Streaming Daemon Feb 09 21:44:54 music sudo[16752]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 09 21:44:54 music sudo[16752]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:54 music volumio[16453]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 09 21:44:54 music sudo[16752]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:54 music volumio[16453]: info: Getting Spotify volume Feb 09 21:44:54 music volumio[16453]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 21:44:54 music volumio[16453]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 21:44:54 music volumio[16453]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 09 21:44:54 music volumio[16453]: errno: -111, Feb 09 21:44:54 music volumio[16453]: code: 'ECONNREFUSED', Feb 09 21:44:54 music volumio[16453]: syscall: 'connect', Feb 09 21:44:54 music volumio[16453]: address: '127.0.0.1', Feb 09 21:44:54 music volumio[16453]: port: 9879, Feb 09 21:44:54 music volumio[16453]: response: undefined Feb 09 21:44:54 music volumio[16453]: } Feb 09 21:44:54 music volumio[16453]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 21:44:54 music sudo[16786]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-09 21:43' Feb 09 21:44:54 music sudo[16786]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:44:55 music sudo[16786]: pam_unix(sudo:session): session closed for user root Feb 09 21:44:56 music volumio-remote-updater[30265]: [2026-02-09 21:44:56] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 09 21:44:56 music volumio-remote-updater[30265]: [2026-02-09 21:44:56] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 09 21:44:56 music systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 09 21:44:56 music systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 09 21:44:56 music systemd[1]: volumio.service: Consumed 26.592s CPU time. Feb 09 21:44:56 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 09 21:44:56 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 09 21:44:56 music systemd[1]: volumio.service: Scheduled restart job, restart counter is at 53397. Feb 09 21:44:56 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 09 21:44:56 music systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 09 21:44:56 music systemd[1]: volumio.service: Consumed 26.592s CPU time. Feb 09 21:44:56 music systemd[1]: Started volumio.service - Volumio Backend Module. Feb 09 21:44:56 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 09 21:44:57 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 09 21:44:57 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 21:44:57 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 21:44:57 music go-librespot[16822]: go-librespot daemon starting... Feb 09 21:44:57 music go-librespot[16823]: time="2026-02-09T21:44:57-05:00" level=info msg="running go-librespot 0.6.2" Feb 09 21:44:57 music go-librespot[16823]: time="2026-02-09T21:44:57-05:00" level=debug msg="app state loaded" Feb 09 21:44:57 music go-librespot[16823]: time="2026-02-09T21:44:57-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 21:44:57 music go-librespot[16823]: time="2026-02-09T21:44:57-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Feb 09 21:44:57 music go-librespot[16823]: time="2026-02-09T21:44:57-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 09 21:44:57 music go-librespot[16823]: time="2026-02-09T21:44:57-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 09 21:44:57 music go-librespot[16823]: time="2026-02-09T21:44:57-05:00" level=info msg="zeroconf server listening on port 43837" Feb 09 21:44:57 music go-librespot[16823]: time="2026-02-09T21:44:57-05:00" level=debug msg="obtained new client token: AAB34Z3Edxd51Mb42wvDpw88Fe2MNDUJI9qCIedvZykP4op/zWrSP1B+bhn0Scag1UBUUfPnj3wi23HzqafTD2LaX1MIdfhXNJfEpKKBmx0lrJMBiqe0BSpgelwdjyXoj7Qf6u6q0egOTMTYy4bOJwzUorty2YgWtRS7/sQJLs9jGlFw8PGEO3hJSCmmfyWwRbQc9qv2/aYKzbmOhLe2eyEyK/SZjAW26yASn5d07AGsISRugp1mUfU=" Feb 09 21:44:57 music go-librespot[16823]: time="2026-02-09T21:44:57-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 09 21:44:57 music go-librespot[16823]: time="2026-02-09T21:44:57-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:57 music go-librespot[16823]: time="2026-02-09T21:44:57-05:00" level=debug msg="completed challenge" Feb 09 21:44:57 music go-librespot[16823]: time="2026-02-09T21:44:57-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:58 music go-librespot[16823]: time="2026-02-09T21:44:58-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 09 21:44:58 music go-librespot[16823]: time="2026-02-09T21:44:58-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:58 music go-librespot[16823]: time="2026-02-09T21:44:58-05:00" level=debug msg="completed challenge" Feb 09 21:44:58 music volumio[16807]: info: ------------------------------------------- Feb 09 21:44:58 music volumio[16807]: info: ----- Volumio3 ---- Feb 09 21:44:58 music volumio[16807]: info: ------------------------------------------- Feb 09 21:44:58 music volumio[16807]: info: ----- System startup ---- Feb 09 21:44:58 music volumio[16807]: info: ------------------------------------------- Feb 09 21:44:58 music go-librespot[16823]: time="2026-02-09T21:44:58-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:59 music go-librespot[16823]: time="2026-02-09T21:44:59-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 09 21:44:59 music go-librespot[16823]: time="2026-02-09T21:44:59-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:59 music go-librespot[16823]: time="2026-02-09T21:44:59-05:00" level=debug msg="completed challenge" Feb 09 21:44:59 music go-librespot[16823]: time="2026-02-09T21:44:59-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:44:59 music volumio[16807]: info: MYVOLUMIO Environment detected Feb 09 21:44:59 music volumio[16807]: info: Plugin folders cleanup Feb 09 21:44:59 music volumio[16807]: info: Scanning into folder /volumio/app/plugins/ Feb 09 21:44:59 music volumio[16807]: info: Scanning category audio_interface Feb 09 21:44:59 music volumio[16807]: info: Scanning category miscellanea Feb 09 21:44:59 music volumio[16807]: info: Scanning category music_service Feb 09 21:44:59 music volumio[16807]: info: Scanning category plugins.json Feb 09 21:44:59 music volumio[16807]: info: Scanning category system_controller Feb 09 21:44:59 music volumio[16807]: info: Scanning category user_interface Feb 09 21:44:59 music volumio[16807]: info: Scanning into folder /data/plugins/ Feb 09 21:44:59 music volumio[16807]: info: Scanning category music_service Feb 09 21:44:59 music volumio[16807]: info: Plugin folders cleanup completed Feb 09 21:44:59 music volumio[16807]: info: ------------------------------------------- Feb 09 21:44:59 music volumio[16807]: info: ----- Core plugins startup ---- Feb 09 21:44:59 music volumio[16807]: info: ------------------------------------------- Feb 09 21:44:59 music volumio[16807]: info: Loading plugins from folder /volumio/app/plugins/ Feb 09 21:44:59 music volumio[16807]: info: Adding plugin upnp to MyMusic Plugins Feb 09 21:44:59 music volumio[16807]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 09 21:44:59 music volumio[16807]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 09 21:44:59 music volumio[16807]: info: Loading plugins from folder /data/plugins/ Feb 09 21:44:59 music volumio[16807]: info: Loading plugin "system"... Feb 09 21:44:59 music volumio[16807]: info: Loading plugin "appearance"... Feb 09 21:44:59 music go-librespot[16823]: time="2026-02-09T21:44:59-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 09 21:44:59 music go-librespot[16823]: time="2026-02-09T21:44:59-05:00" level=debug msg="completed keyexchange" Feb 09 21:44:59 music go-librespot[16823]: time="2026-02-09T21:44:59-05:00" level=debug msg="completed challenge" Feb 09 21:44:59 music go-librespot[16823]: time="2026-02-09T21:44:59-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:00 music volumio[16807]: info: Loading plugin "network"... Feb 09 21:45:00 music volumio[16807]: info: Refreshing Cached IP Addresses Feb 09 21:45:00 music sudo[16846]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 21:45:00 music sudo[16846]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:45:00 music sudo[16846]: pam_unix(sudo:session): session closed for user root Feb 09 21:45:00 music sudo[16848]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 21:45:00 music sudo[16848]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:45:00 music volumio[16807]: info: Loading plugin "services"... Feb 09 21:45:00 music volumio[16807]: info: Loading plugin "alsa_controller"... Feb 09 21:45:00 music sudo[16848]: pam_unix(sudo:session): session closed for user root Feb 09 21:45:00 music sudo[16859]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 09 21:45:00 music sudo[16859]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:45:00 music go-librespot[16823]: time="2026-02-09T21:45:00-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 09 21:45:00 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 21:45:00 music volumio[16807]: info: Loading plugin "wizard"... Feb 09 21:45:00 music volumio[16807]: info: Loading plugin "networkfs"... Feb 09 21:45:00 music volumio[16807]: info: Starting Udev Watcher for removable devices Feb 09 21:45:00 music volumio[16807]: info: Ignoring mount for partition: boot Feb 09 21:45:00 music volumio[16807]: info: Ignoring mount for partition: volumio Feb 09 21:45:00 music volumio[16807]: info: Ignoring mount for partition: volumio_data Feb 09 21:45:00 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 21:45:00 music volumio[16807]: info: Loading plugin "volumio_command_line_client"... Feb 09 21:45:00 music volumio[16807]: info: Loading plugin "upnp"... Feb 09 21:45:00 music volumio[16807]: info: [1770691500841] Starting Upmpd Daemon Feb 09 21:45:00 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 21:45:00 music volumio[16807]: info: Loading plugin "my_music"... Feb 09 21:45:00 music volumio[16807]: info: Loading plugin "mpd"... Feb 09 21:45:00 music go-librespot[16823]: time="2026-02-09T21:45:00-05:00" level=debug msg="completed keyexchange" Feb 09 21:45:00 music go-librespot[16823]: time="2026-02-09T21:45:00-05:00" level=debug msg="completed challenge" Feb 09 21:45:01 music go-librespot[16823]: time="2026-02-09T21:45:01-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:01 music volumio[16807]: info: Loading plugin "upnp_browser"... Feb 09 21:45:01 music sudo[16859]: pam_unix(sudo:session): session closed for user root Feb 09 21:45:01 music volumio-remote-updater[30265]: [2026-02-09 21:45:01] [connect] Successful connection Feb 09 21:45:01 music go-librespot[16823]: time="2026-02-09T21:45:01-05:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 09 21:45:01 music go-librespot[16823]: time="2026-02-09T21:45:01-05:00" level=debug msg="completed keyexchange" Feb 09 21:45:01 music go-librespot[16823]: time="2026-02-09T21:45:01-05:00" level=debug msg="completed challenge" Feb 09 21:45:02 music go-librespot[16823]: time="2026-02-09T21:45:02-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: failed peeking unencrypted bytes: failed peeking uncrypted: EOF" Feb 09 21:45:02 music go-librespot[16823]: time="2026-02-09T21:45:02-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed peeking unencrypted bytes: failed peeking uncrypted: EOF" Feb 09 21:45:02 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 21:45:02 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 21:45:02 music volumio[16807]: info: Starting UPNP Browser Feb 09 21:45:02 music volumio[16807]: info: Loading plugin "alarm-clock"... Feb 09 21:45:02 music volumio[16807]: info: Loading plugin "airplay_emulation"... Feb 09 21:45:02 music volumio[16807]: info: Starting Shairport Sync Feb 09 21:45:02 music volumio[16807]: info: Loading plugin "last_100"... Feb 09 21:45:02 music volumio[16807]: info: Loading plugin "webradio"... Feb 09 21:45:03 music volumio[16807]: info: Loading plugin "i2s_dacs"... Feb 09 21:45:03 music volumio[16807]: info: I2S DAC not set, start Auto-detection Feb 09 21:45:03 music volumio[16807]: info: Loading plugin "volumiodiscovery"... Feb 09 21:45:03 music volumio[16807]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 21:45:03 music volumio[16807]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 21:45:03 music volumio[16807]: *** WARNING *** For more information see Feb 09 21:45:03 music volumio[16807]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 21:45:03 music volumio[16807]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 21:45:03 music volumio[16807]: *** WARNING *** For more information see Feb 09 21:45:03 music node[16807]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 21:45:03 music node[16807]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 21:45:03 music node[16807]: *** WARNING *** For more information see Feb 09 21:45:03 music node[16807]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 21:45:03 music node[16807]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 21:45:03 music node[16807]: *** WARNING *** For more information see Feb 09 21:45:03 music volumio[16807]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 09 21:45:03 music volumio[16807]: info: Discovery: Started advertising with name: music Feb 09 21:45:03 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 21:45:03 music volumio[16807]: info: Loading plugin "spop"... Feb 09 21:45:04 music volumio[16807]: info: Loading plugin "outputs"... Feb 09 21:45:04 music volumio[16807]: info: Loading plugin "albumart"... Feb 09 21:45:04 music volumio[16807]: info: Plugin example_plugin is not enabled Feb 09 21:45:04 music volumio[16807]: info: Loading plugin "inputs"... Feb 09 21:45:04 music volumio[16807]: info: Loading plugin "updater_comm"... Feb 09 21:45:04 music volumio[16807]: info: Plugin mpdemulation is not enabled Feb 09 21:45:04 music volumio[16807]: info: Loading plugin "rest_api"... Feb 09 21:45:04 music volumio[16807]: info: Loading plugin "websocket"... Feb 09 21:45:04 music volumio[16807]: info: Starting Socket.io Server version 1.7.4 Feb 09 21:45:04 music volumio[16807]: info: Loading i18n strings for locale en Feb 09 21:45:04 music volumio[16807]: Updating browse sources language Feb 09 21:45:04 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 21:45:04 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 21:45:04 music volumio[16807]: info: CoreCommandRouter::initPlayerControls Feb 09 21:45:04 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:04 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:04 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:04 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:04 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:04 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:04 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:04 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:04 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 21:45:04 music volumio[16807]: Express server listening on port 3000 Feb 09 21:45:04 music volumio[16807]: [Metrics] WebUI: 6s 552.87ms Feb 09 21:45:04 music volumio[16807]: info: CoreStateMachine::resetVolumioState Feb 09 21:45:04 music volumio[16807]: info: CoreStateMachine::getcurrentVolume Feb 09 21:45:04 music volumio[16807]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 21:45:04 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:45:04 music volumio[16807]: info: Volumio Network Manager: Network status updated: 1 Feb 09 21:45:04 music volumio-remote-updater[30265]: [2026-02-09 21:45:04] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770691501 101 Feb 09 21:45:04 music volumio[16881]: Forking 3 albumart workers Feb 09 21:45:04 music volumio[16807]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 09 21:45:04 music volumio[16807]: info: VolumeController:: Volume=86 Mute =false Feb 09 21:45:04 music volumio[16807]: info: CoreStateMachine::pushState Feb 09 21:45:04 music volumio[16807]: info: CorePlayQueue::getTrack 0 Feb 09 21:45:04 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 21:45:04 music volumio[16807]: info: CoreCommandRouter::volumioPushState Feb 09 21:45:04 music volumio[16807]: info: CoreStateMachine::updateTrackBlock Feb 09 21:45:04 music volumio[16807]: info: CorePlayQueue::getTrackBlock Feb 09 21:45:04 music volumio[16807]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 21:45:04 music volumio[16807]: info: Reloading queue from file Feb 09 21:45:04 music volumio[16807]: info: CoreCommandRouter::volumioGetState Feb 09 21:45:04 music volumio[16807]: info: CorePlayQueue::getTrack 0 Feb 09 21:45:05 music volumio[16807]: info: Setting Device type: Raspberry PI Feb 09 21:45:05 music volumio[16807]: info: CoreStateMachine::setRepeat null single undefined Feb 09 21:45:05 music volumio[16807]: info: CoreStateMachine::pushState Feb 09 21:45:05 music volumio[16807]: info: CorePlayQueue::getTrack 0 Feb 09 21:45:05 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 21:45:05 music volumio[16807]: info: CoreCommandRouter::volumioPushState Feb 09 21:45:05 music volumio[16807]: info: CoreStateMachine::setRandom null Feb 09 21:45:05 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 09 21:45:05 music volumio[16807]: info: CoreStateMachine::pushState Feb 09 21:45:05 music volumio[16807]: info: CorePlayQueue::getTrack 0 Feb 09 21:45:05 music volumio[16807]: info: CoreCommandRouter::volumioPushState Feb 09 21:45:05 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 21:45:05 music volumio[16807]: info: Listing playlists Feb 09 21:45:05 music volumio[16807]: info: Listing playlists Feb 09 21:45:05 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 21:45:05 music go-librespot[16933]: go-librespot daemon starting... Feb 09 21:45:05 music go-librespot[16936]: time="2026-02-09T21:45:05-05:00" level=info msg="running go-librespot 0.6.2" Feb 09 21:45:05 music go-librespot[16936]: time="2026-02-09T21:45:05-05:00" level=debug msg="app state loaded" Feb 09 21:45:05 music volumio[16807]: info: VolumeController:: Volume=86 Mute =false Feb 09 21:45:05 music volumio[16807]: info: CoreStateMachine::pushState Feb 09 21:45:05 music volumio[16807]: info: CorePlayQueue::getTrack 0 Feb 09 21:45:05 music volumio[16807]: info: CoreCommandRouter::volumioPushState Feb 09 21:45:05 music go-librespot[16936]: time="2026-02-09T21:45:05-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 21:45:05 music volumio[16807]: info: Completed loading Core Plugins Feb 09 21:45:05 music volumio[16807]: info: Preparing to generate the ALSA configuration file Feb 09 21:45:05 music volumio[16807]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 09 21:45:05 music volumio[16807]: info: Discovery: Found device music Feb 09 21:45:05 music volumio[16807]: info: CoreCommandRouter::volumioGetState Feb 09 21:45:05 music volumio[16807]: info: CorePlayQueue::getTrack 0 Feb 09 21:45:05 music volumio[16807]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 09 21:45:05 music volumio[16807]: info: Discovery: Found device music Feb 09 21:45:05 music volumio[16807]: info: CoreCommandRouter::volumioGetState Feb 09 21:45:05 music volumio[16807]: info: CorePlayQueue::getTrack 0 Feb 09 21:45:05 music volumio[16807]: info: Asound.conf file unchanged, so no further update is needed Feb 09 21:45:05 music volumio[16807]: info: Output device has changed, restarting MPD Feb 09 21:45:05 music volumio[16807]: info: Output device has changed, restarting Shairport Sync Feb 09 21:45:05 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:05 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:45:05 music sudo[16945]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 21:45:05 music sudo[16945]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:45:05 music sudo[16947]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 21:45:05 music volumio[16807]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 21:45:05 music sudo[16947]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:45:05 music volumio[16807]: info: ___________ START PLUGINS ___________ Feb 09 21:45:05 music volumio[16807]: info: ControllerMpd::onStart: Initializing MPD Feb 09 21:45:05 music volumio[16807]: info: Creating MPD Configuration file Feb 09 21:45:05 music sudo[16945]: pam_unix(sudo:session): session closed for user root Feb 09 21:45:05 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 21:45:05 music systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 09 21:45:05 music volumio[16807]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 21:45:05 music volumio[16807]: info: [1770691505494] CoreMusicLibrary::Adding element Media Servers Feb 09 21:45:05 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 21:45:05 music volumio[16807]: info: UPNP Browser: Client initialized successfully Feb 09 21:45:05 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:05 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:45:05 music sudo[16955]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 21:45:05 music systemd[1]: mpd.service: Deactivated successfully. Feb 09 21:45:05 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 09 21:45:05 music systemd[1]: mpd.service: Consumed 4.080s CPU time. Feb 09 21:45:05 music sudo[16955]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:45:05 music systemd[1]: mpd.socket: Deactivated successfully. Feb 09 21:45:05 music sudo[16957]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 21:45:05 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 09 21:45:05 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 09 21:45:05 music sudo[16957]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:45:05 music sudo[16955]: pam_unix(sudo:session): session closed for user root Feb 09 21:45:05 music volumio[16807]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 21:45:05 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:05 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:45:05 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 09 21:45:05 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 09 21:45:05 music volumio[16807]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 21:45:05 music volumio[16807]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 21:45:05 music volumio[16807]: info: [1770691505696] CoreMusicLibrary::Adding element Last_100 Feb 09 21:45:05 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 21:45:05 music volumio[16807]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 21:45:05 music volumio[16807]: info: [1770691505716] CoreMusicLibrary::Adding element Webradio Feb 09 21:45:05 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 21:45:05 music systemd[1]: mpd.service: Deactivated successfully. Feb 09 21:45:05 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 09 21:45:05 music systemd[1]: mpd.socket: Deactivated successfully. Feb 09 21:45:05 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 09 21:45:05 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 09 21:45:05 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 09 21:45:05 music go-librespot[16936]: time="2026-02-09T21:45:05-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 21:45:05 music go-librespot[16936]: time="2026-02-09T21:45:05-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 21:45:05 music go-librespot[16936]: time="2026-02-09T21:45:05-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 21:45:05 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 09 21:45:05 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 21:45:05 music go-librespot[16936]: time="2026-02-09T21:45:05-05:00" level=info msg="zeroconf server listening on port 34259" Feb 09 21:45:05 music volumio[16807]: info: Initializing BBC Radios Feb 09 21:45:05 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 21:45:05 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:45:05 music volumio[16807]: info: Creating Spotify config file Feb 09 21:45:05 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:05 music go-librespot[16936]: time="2026-02-09T21:45:05-05:00" level=debug msg="obtained new client token: AAB+U7fo8Fci5dexLrK2qDA0lMjWtSWe23LXn6QUVZkppZQR98kW35jLSv8hqhv5H8fRQejlthp/g5iePVA+e4ark1nodCiKuvNPQakYPxaRWNt8bh8AD5kAB4Aqju9hTwxYWk21MeK8czdMbKA0cyjzshmMBGOFRqWpf9/bm9RwnZQyBU4aN8116GzPg8ZVkcTUJLUOYQKl2soOchVz2/Z96DlV8+ur7uAKx3ZayKehPVaVVheiDdQ=" Feb 09 21:45:06 music go-librespot[16936]: time="2026-02-09T21:45:06-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.255.62:4070: connect: connection refused" Feb 09 21:45:06 music sudo[16972]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 09 21:45:06 music sudo[16972]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 09 21:45:06 music sudo[16972]: pam_unix(sudo:session): session closed for user root Feb 09 21:45:06 music go-librespot[16936]: time="2026-02-09T21:45:06-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.255.62:443: connect: connection refused" Feb 09 21:45:06 music go-librespot[16936]: time="2026-02-09T21:45:06-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 09 21:45:06 music go-librespot[16936]: time="2026-02-09T21:45:06-05:00" level=debug msg="completed keyexchange" Feb 09 21:45:06 music go-librespot[16936]: time="2026-02-09T21:45:06-05:00" level=debug msg="completed challenge" Feb 09 21:45:06 music go-librespot[16936]: time="2026-02-09T21:45:06-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:06 music volumio[16807]: info: Volumio Calling Home Feb 09 21:45:06 music volumio[16899]: Starting albumart workers Feb 09 21:45:06 music go-librespot[16936]: time="2026-02-09T21:45:06-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 09 21:45:06 music go-librespot[16936]: time="2026-02-09T21:45:06-05:00" level=debug msg="completed keyexchange" Feb 09 21:45:06 music go-librespot[16936]: time="2026-02-09T21:45:06-05:00" level=debug msg="completed challenge" Feb 09 21:45:06 music volumio[16898]: Starting albumart workers Feb 09 21:45:06 music go-librespot[16936]: time="2026-02-09T21:45:06-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:07 music volumio[16807]: info: MPD Permissions set Feb 09 21:45:07 music volumio[16807]: info: MPD Permissions set Feb 09 21:45:07 music volumio[16807]: info: Spotify config file written Feb 09 21:45:07 music volumio[16807]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 09 21:45:07 music volumio[16897]: Starting albumart workers Feb 09 21:45:07 music volumio[16807]: info: Volumio called home Feb 09 21:45:07 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:07 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:07 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:07 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:07 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:07 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:07 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:07 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:07 music sudo[16994]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 09 21:45:07 music sudo[16994]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:45:07 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:45:07 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:07 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:07 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:07 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:07 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:07 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:07 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:07 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:07 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:07 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:45:07 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 09 21:45:07 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:07 music volumio[16807]: info: No need to fix Spotify hosts Feb 09 21:45:07 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 09 21:45:07 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 21:45:07 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 21:45:07 music go-librespot[17006]: go-librespot daemon starting... Feb 09 21:45:07 music sudo[16994]: pam_unix(sudo:session): session closed for user root Feb 09 21:45:07 music go-librespot[17007]: time="2026-02-09T21:45:07-05:00" level=info msg="running go-librespot 0.6.2" Feb 09 21:45:07 music go-librespot[17007]: time="2026-02-09T21:45:07-05:00" level=debug msg="app state loaded" Feb 09 21:45:07 music go-librespot[17007]: time="2026-02-09T21:45:07-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 21:45:08 music go-librespot[17007]: time="2026-02-09T21:45:08-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 21:45:08 music go-librespot[17007]: time="2026-02-09T21:45:08-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 21:45:08 music go-librespot[17007]: time="2026-02-09T21:45:08-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 21:45:08 music go-librespot[17007]: time="2026-02-09T21:45:08-05:00" level=info msg="zeroconf server listening on port 45205" Feb 09 21:45:08 music volumio[16807]: info: Starting Shairport Sync Feb 09 21:45:08 music volumio[16807]: info: Starting Shairport Sync Feb 09 21:45:08 music volumio[16807]: info: Starting Shairport Sync Feb 09 21:45:08 music sudo[17029]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 21:45:08 music sudo[17029]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:45:08 music sudo[17033]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 21:45:08 music sudo[17033]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:45:08 music sudo[17031]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 21:45:08 music sudo[17031]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:45:08 music go-librespot[17007]: time="2026-02-09T21:45:08-05:00" level=debug msg="obtained new client token: AADCjmqqq4CE1+qv+hNQY3QIbSE/u2y0GOHuLDy34O6AAqS9I8IJQRTiLWiNZdyN3wIt03ycPLaTdTUqfU29gmzcjNB2Aqb7laOdmQdwamoGi2XDAmBmIQXrSI2IsJVxYTjfBtj5gofWmrCg/aLSdDO/Th1h4+c+BEJiA+Ou/i1FpgsgRnOEfjLaM1qPdt7KqZZH9dyYEERE1VHIzm74OcYpmBR2GH8qBCCDeshNCqUY1hOQjIxG" Feb 09 21:45:08 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 09 21:45:08 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 09 21:45:08 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 21:45:08 music systemd[1]: shairport-sync.service: Consumed 1.885s CPU time. Feb 09 21:45:08 music go-librespot[17007]: time="2026-02-09T21:45:08-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 09 21:45:08 music volumio[16807]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 09 21:45:08 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 21:45:08 music sudo[17029]: pam_unix(sudo:session): session closed for user root Feb 09 21:45:08 music volumio[16807]: info: CoreCommandRouter::volumioGetState Feb 09 21:45:08 music volumio[16807]: info: CorePlayQueue::getTrack 0 Feb 09 21:45:08 music volumio[16807]: info: Shairport-Sync Started Feb 09 21:45:08 music volumio[16807]: Error adding Membership: Error: addMembership EINVAL Feb 09 21:45:08 music go-librespot[17007]: time="2026-02-09T21:45:08-05:00" level=debug msg="completed keyexchange" Feb 09 21:45:08 music go-librespot[17007]: time="2026-02-09T21:45:08-05:00" level=debug msg="completed challenge" Feb 09 21:45:08 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 09 21:45:08 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 09 21:45:08 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 21:45:08 music go-librespot[17007]: time="2026-02-09T21:45:08-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:08 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 21:45:08 music sudo[17031]: pam_unix(sudo:session): session closed for user root Feb 09 21:45:08 music sudo[17033]: pam_unix(sudo:session): session closed for user root Feb 09 21:45:08 music volumio[16807]: info: Shairport-Sync Started Feb 09 21:45:08 music volumio[16807]: info: Shairport-Sync Started Feb 09 21:45:09 music go-librespot[17007]: time="2026-02-09T21:45:09-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 09 21:45:09 music go-librespot[17007]: time="2026-02-09T21:45:09-05:00" level=debug msg="completed keyexchange" Feb 09 21:45:09 music go-librespot[17007]: time="2026-02-09T21:45:09-05:00" level=debug msg="completed challenge" Feb 09 21:45:09 music go-librespot[17007]: time="2026-02-09T21:45:09-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:09 music go-librespot[17007]: time="2026-02-09T21:45:09-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:80, retrying with a different AP" error="dial tcp 34.158.255.62:80: connect: connection refused" Feb 09 21:45:09 music go-librespot[17007]: time="2026-02-09T21:45:09-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 09 21:45:09 music go-librespot[17007]: time="2026-02-09T21:45:09-05:00" level=debug msg="completed keyexchange" Feb 09 21:45:09 music go-librespot[17007]: time="2026-02-09T21:45:09-05:00" level=debug msg="completed challenge" Feb 09 21:45:09 music go-librespot[17007]: time="2026-02-09T21:45:09-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:10 music mpd[16987]: 2026-02-09T21:45:10 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 09 21:45:10 music systemd[1]: Started mpd.service - Music Player Daemon. Feb 09 21:45:10 music sudo[16947]: pam_unix(sudo:session): session closed for user root Feb 09 21:45:10 music sudo[16957]: pam_unix(sudo:session): session closed for user root Feb 09 21:45:10 music volumio[16807]: info: Completed starting Core Plugins Feb 09 21:45:10 music volumio[16807]: info: ------------------------------------------- Feb 09 21:45:10 music volumio[16807]: info: ----- MyVolumio plugins startup ---- Feb 09 21:45:10 music volumio[16807]: info: ------------------------------------------- Feb 09 21:45:10 music volumio[16807]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 09 21:45:10 music volumio[16807]: error: MPD error: The expression evaluated to a falsy value: Feb 09 21:45:10 music volumio[16807]: assert.ok(self.idling) Feb 09 21:45:10 music volumio[16807]: error: The expression evaluated to a falsy value: Feb 09 21:45:10 music volumio[16807]: assert.ok(self.idling) Feb 09 21:45:10 music volumio[16807]: info: MPD running with PID16987 Feb 09 21:45:10 music volumio[16807]: ,establishing connection Feb 09 21:45:10 music volumio[16807]: error: updateQueue error: null Feb 09 21:45:10 music volumio[16807]: error: updateQueue error: null Feb 09 21:45:10 music go-librespot[17007]: time="2026-02-09T21:45:10-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 09 21:45:10 music sudo[17081]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 21:45:10 music sudo[17081]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:45:10 music sudo[17081]: pam_unix(sudo:session): session closed for user root Feb 09 21:45:10 music sudo[17083]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 21:45:10 music sudo[17083]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:45:10 music sudo[17083]: pam_unix(sudo:session): session closed for user root Feb 09 21:45:10 music go-librespot[17007]: time="2026-02-09T21:45:10-05:00" level=debug msg="completed keyexchange" Feb 09 21:45:10 music go-librespot[17007]: time="2026-02-09T21:45:10-05:00" level=debug msg="completed challenge" Feb 09 21:45:10 music sudo[17086]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 09 21:45:10 music sudo[17086]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:45:10 music sudo[17086]: pam_unix(sudo:session): session closed for user root Feb 09 21:45:10 music volumio[16807]: info: Upmpdcli Daemon Started Feb 09 21:45:11 music volumio[16807]: info: go-librespot daemon successfully initialized Feb 09 21:45:11 music go-librespot[17007]: time="2026-02-09T21:45:11-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:11 music go-librespot[17007]: time="2026-02-09T21:45:11-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 09 21:45:11 music go-librespot[17007]: time="2026-02-09T21:45:11-05:00" level=debug msg="completed keyexchange" Feb 09 21:45:11 music go-librespot[17007]: time="2026-02-09T21:45:11-05:00" level=debug msg="completed challenge" Feb 09 21:45:11 music go-librespot[17007]: time="2026-02-09T21:45:11-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:12 music go-librespot[17007]: time="2026-02-09T21:45:12-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 09 21:45:12 music go-librespot[17007]: time="2026-02-09T21:45:12-05:00" level=debug msg="completed keyexchange" Feb 09 21:45:12 music go-librespot[17007]: time="2026-02-09T21:45:12-05:00" level=debug msg="completed challenge" Feb 09 21:45:12 music go-librespot[17007]: time="2026-02-09T21:45:12-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:12 music go-librespot[17007]: time="2026-02-09T21:45:12-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:12 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 21:45:12 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 21:45:13 music volumio[16807]: info: CoreCommandRouter::volumioGetState Feb 09 21:45:13 music volumio[16807]: info: CorePlayQueue::getTrack 0 Feb 09 21:45:13 music sudo[17090]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 09 21:45:13 music sudo[17090]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:45:13 music sudo[17093]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 09 21:45:13 music sudo[17093]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:45:13 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 09 21:45:13 music systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 09 21:45:13 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 09 21:45:13 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 09 21:45:13 music sudo[17090]: pam_unix(sudo:session): session closed for user root Feb 09 21:45:13 music mpd_monitor.sh[17095]: MPD Monitor Service: Starting MPD Monitor Service Feb 09 21:45:13 music volumio[16807]: info: Successfully started MPD Monitor Feb 09 21:45:13 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 09 21:45:13 music systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 09 21:45:13 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 09 21:45:13 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 09 21:45:13 music sudo[17093]: pam_unix(sudo:session): session closed for user root Feb 09 21:45:13 music mpd_monitor.sh[17098]: MPD Monitor Service: Starting MPD Monitor Service Feb 09 21:45:13 music volumio[16807]: info: Successfully started MPD Monitor Feb 09 21:45:14 music volumio[16807]: info: Initializing connection to go-librespot Websocket Feb 09 21:45:14 music volumio[16807]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 21:45:15 music volumio[16807]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 09 21:45:15 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 09 21:45:15 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 21:45:15 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 21:45:15 music go-librespot[17102]: go-librespot daemon starting... Feb 09 21:45:15 music go-librespot[17103]: time="2026-02-09T21:45:15-05:00" level=info msg="running go-librespot 0.6.2" Feb 09 21:45:15 music go-librespot[17103]: time="2026-02-09T21:45:15-05:00" level=debug msg="app state loaded" Feb 09 21:45:15 music go-librespot[17103]: time="2026-02-09T21:45:15-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 21:45:16 music go-librespot[17103]: time="2026-02-09T21:45: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 09 21:45:16 music go-librespot[17103]: time="2026-02-09T21:45: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 09 21:45:16 music go-librespot[17103]: time="2026-02-09T21:45: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 09 21:45:16 music go-librespot[17103]: time="2026-02-09T21:45:16-05:00" level=info msg="zeroconf server listening on port 46085" Feb 09 21:45:16 music go-librespot[17103]: time="2026-02-09T21:45:16-05:00" level=debug msg="obtained new client token: AADZOWun4j4NigQsC3p6qTVB/+quHXiXE2aUJ8w7g9ZGl4j6slO7FYhpl35fFdhtQr9lBBqVdZMgNXP5FewNFWt/gZ93+vkh2lAJwJE9PjY+gib1VJUXXpKWauR/xhbwWmwhFjJQvQuoNIeKhUvrxZSRSQ5cEYmpW6t3lyb0s6X5a8bu3FbvBIzIKnahu7YsenCkt6S1as0j48S8BSNnz8nq9RJSChZ8OuBfw+/mEc3XbA5HmySYwvg=" Feb 09 21:45:16 music go-librespot[17103]: time="2026-02-09T21:45:16-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 09 21:45:16 music go-librespot[17103]: time="2026-02-09T21:45:16-05:00" level=debug msg="completed keyexchange" Feb 09 21:45:16 music go-librespot[17103]: time="2026-02-09T21:45:16-05:00" level=debug msg="completed challenge" Feb 09 21:45:16 music go-librespot[17103]: time="2026-02-09T21:45:16-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:17 music go-librespot[17103]: time="2026-02-09T21:45:17-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 09 21:45:17 music volumio[16807]: info: Initializing connection to go-librespot Websocket Feb 09 21:45:17 music go-librespot[17103]: time="2026-02-09T21:45:17-05:00" level=debug msg="new websocket client" Feb 09 21:45:17 music volumio[16807]: info: Connection to go-librespot Websocket established Feb 09 21:45:17 music go-librespot[17103]: time="2026-02-09T21:45:17-05:00" level=debug msg="completed keyexchange" Feb 09 21:45:17 music go-librespot[17103]: time="2026-02-09T21:45:17-05:00" level=debug msg="completed challenge" Feb 09 21:45:17 music go-librespot[17103]: time="2026-02-09T21:45:17-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:17 music go-librespot[17103]: time="2026-02-09T21:45:17-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 09 21:45:17 music go-librespot[17103]: time="2026-02-09T21:45:17-05:00" level=debug msg="completed keyexchange" Feb 09 21:45:17 music go-librespot[17103]: time="2026-02-09T21:45:17-05:00" level=debug msg="completed challenge" Feb 09 21:45:18 music go-librespot[17103]: time="2026-02-09T21:45:18-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:18 music volumio[16807]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 09 21:45:18 music volumio[16807]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 09 21:45:18 music volumio[16807]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 09 21:45:18 music volumio[16807]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 09 21:45:18 music volumio[16807]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 09 21:45:18 music volumio[16807]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 09 21:45:18 music volumio[16807]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 09 21:45:18 music volumio[16807]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 09 21:45:18 music volumio[16807]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 09 21:45:18 music volumio[16807]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 09 21:45:18 music volumio[16807]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 09 21:45:18 music volumio[16807]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 09 21:45:18 music volumio[16807]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 09 21:45:18 music volumio[16807]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 09 21:45:18 music volumio[16807]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 09 21:45:18 music volumio[16807]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 09 21:45:18 music volumio[16807]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 09 21:45:18 music volumio[16807]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 09 21:45:18 music volumio[16807]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 09 21:45:18 music volumio[16807]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 09 21:45:18 music volumio[16807]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 09 21:45:18 music volumio[16807]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 09 21:45:18 music volumio[16807]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 09 21:45:18 music volumio[16807]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 09 21:45:18 music volumio[16807]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 09 21:45:18 music volumio[16807]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 09 21:45:18 music volumio[16807]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 09 21:45:18 music volumio[16807]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 09 21:45:18 music volumio[16807]: info: Adding plugin bluetooth to MyMusic Plugins Feb 09 21:45:18 music volumio[16807]: info: Adding plugin multiroom to MyMusic Plugins Feb 09 21:45:18 music volumio[16807]: info: Adding plugin metavolumio to MyMusic Plugins Feb 09 21:45:18 music volumio[16807]: info: Adding plugin cd_controller to MyMusic Plugins Feb 09 21:45:18 music volumio[16807]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 09 21:45:18 music volumio[16807]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 09 21:45:18 music volumio[16807]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 09 21:45:18 music volumio[16807]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 09 21:45:18 music go-librespot[17103]: time="2026-02-09T21:45:18-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 09 21:45:18 music go-librespot[17103]: time="2026-02-09T21:45:18-05:00" level=debug msg="completed keyexchange" Feb 09 21:45:18 music go-librespot[17103]: time="2026-02-09T21:45:18-05:00" level=debug msg="completed challenge" Feb 09 21:45:18 music go-librespot[17103]: time="2026-02-09T21:45:18-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:19 music go-librespot[17103]: time="2026-02-09T21:45:19-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 09 21:45:19 music volumio[16807]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 09 21:45:19 music volumio[16807]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 09 21:45:19 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:45:19 music volumio[16807]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:45:19 music volumio[16807]: info: Starting MyVolumio Remote Streaming Endpoints Feb 09 21:45:19 music volumio[16807]: info: MyVolumio login type: Token Feb 09 21:45:19 music volumio[16807]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 09 21:45:19 music volumio[16807]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 09 21:45:19 music go-librespot[17103]: time="2026-02-09T21:45:19-05:00" level=debug msg="completed keyexchange" Feb 09 21:45:19 music go-librespot[17103]: time="2026-02-09T21:45:19-05:00" level=debug msg="completed challenge" Feb 09 21:45:19 music go-librespot[17103]: time="2026-02-09T21:45:19-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:20 music go-librespot[17103]: time="2026-02-09T21:45:20-05:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 09 21:45:20 music volumio[16807]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 09 21:45:20 music volumio[16807]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 09 21:45:20 music volumio[16807]: info: Streaming services startup Feb 09 21:45:20 music volumio[16807]: info: Starting Streaming Daemon Feb 09 21:45:20 music go-librespot[17103]: time="2026-02-09T21:45:20-05:00" level=debug msg="completed keyexchange" Feb 09 21:45:20 music go-librespot[17103]: time="2026-02-09T21:45:20-05:00" level=debug msg="completed challenge" Feb 09 21:45:20 music sudo[17113]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 09 21:45:20 music sudo[17113]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:45:20 music volumio[16807]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 09 21:45:20 music sudo[17113]: pam_unix(sudo:session): session closed for user root Feb 09 21:45:20 music volumio[16807]: info: Getting Spotify volume Feb 09 21:45:20 music volumio[16807]: error: Cannot start Volumio Streaming Daemon Feb 09 21:45:20 music volumio[16807]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 09 21:45:20 music volumio[16807]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 09 21:45:20 music go-librespot[17103]: time="2026-02-09T21:45:20-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:20 music go-librespot[17103]: time="2026-02-09T21:45:20-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:20 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 21:45:20 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 21:45:20 music volumio[16807]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 21:45:20 music volumio[16807]: Error: socket hang up Feb 09 21:45:20 music volumio[16807]: at connResetException (node:internal/errors:720:14) Feb 09 21:45:20 music volumio[16807]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 09 21:45:20 music volumio[16807]: at Socket.emit (node:events:526:35) Feb 09 21:45:20 music volumio[16807]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 09 21:45:20 music volumio[16807]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 09 21:45:20 music volumio[16807]: code: 'ECONNRESET', Feb 09 21:45:20 music volumio[16807]: response: undefined Feb 09 21:45:20 music volumio[16807]: } Feb 09 21:45:20 music volumio[16807]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 21:45:21 music sudo[17148]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-09 21:44' Feb 09 21:45:21 music sudo[17148]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:45:21 music sudo[17148]: pam_unix(sudo:session): session closed for user root Feb 09 21:45:23 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 09 21:45:23 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 21:45:23 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 21:45:23 music go-librespot[17156]: go-librespot daemon starting... Feb 09 21:45:23 music go-librespot[17157]: time="2026-02-09T21:45:23-05:00" level=info msg="running go-librespot 0.6.2" Feb 09 21:45:23 music go-librespot[17157]: time="2026-02-09T21:45:23-05:00" level=debug msg="app state loaded" Feb 09 21:45:23 music go-librespot[17157]: time="2026-02-09T21:45:23-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 21:45:23 music volumio-remote-updater[30265]: [2026-02-09 21:45:23] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 09 21:45:23 music volumio-remote-updater[30265]: [2026-02-09 21:45:23] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 09 21:45:23 music systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 09 21:45:23 music systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 09 21:45:23 music systemd[1]: volumio.service: Consumed 26.523s CPU time. Feb 09 21:45:24 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 09 21:45:24 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 09 21:45:24 music go-librespot[17157]: time="2026-02-09T21:45:24-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 21:45:24 music go-librespot[17157]: time="2026-02-09T21:45:24-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 21:45:24 music go-librespot[17157]: time="2026-02-09T21:45:24-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 21:45:24 music go-librespot[17157]: time="2026-02-09T21:45:24-05:00" level=info msg="zeroconf server listening on port 43509" Feb 09 21:45:24 music systemd[1]: volumio.service: Scheduled restart job, restart counter is at 53398. Feb 09 21:45:24 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 09 21:45:24 music systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 09 21:45:24 music systemd[1]: volumio.service: Consumed 26.523s CPU time. Feb 09 21:45:24 music systemd[1]: Started volumio.service - Volumio Backend Module. Feb 09 21:45:24 music go-librespot[17157]: time="2026-02-09T21:45:24-05:00" level=debug msg="obtained new client token: AAB5LtPCpVlqAwkdPoHSsWbKeB/Ww5NyrN0w3mxmsIUj+4V1ZrGAQe6NvTW1zVB8FcSfTr2O6KJTu7Ba2i1Asug/jvLUlIMH9hqTguLy8QqjO64s+dVuK3xvp/dYrAS6Gb4UebeTpnB05J8vfKdVaH6ugChfC/6mUTK7i2pV1Ag+zGp9TNbtBqYNNEhws2d53eULLG7bR4f7qPRyiqj9PCXB+Bj8+jqVA3hOYspamQ9XFC4+K2WxMfE=" Feb 09 21:45:24 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 09 21:45:24 music go-librespot[17157]: time="2026-02-09T21:45:24-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 09 21:45:24 music go-librespot[17157]: time="2026-02-09T21:45:24-05:00" level=debug msg="completed keyexchange" Feb 09 21:45:24 music go-librespot[17157]: time="2026-02-09T21:45:24-05:00" level=debug msg="completed challenge" Feb 09 21:45:24 music go-librespot[17157]: time="2026-02-09T21:45:24-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:25 music go-librespot[17157]: time="2026-02-09T21:45:25-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 09 21:45:25 music go-librespot[17157]: time="2026-02-09T21:45:25-05:00" level=debug msg="completed keyexchange" Feb 09 21:45:25 music go-librespot[17157]: time="2026-02-09T21:45:25-05:00" level=debug msg="completed challenge" Feb 09 21:45:25 music go-librespot[17157]: time="2026-02-09T21:45:25-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:25 music go-librespot[17157]: time="2026-02-09T21:45:25-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 09 21:45:25 music go-librespot[17157]: time="2026-02-09T21:45:25-05:00" level=debug msg="completed keyexchange" Feb 09 21:45:25 music go-librespot[17157]: time="2026-02-09T21:45:25-05:00" level=debug msg="completed challenge" Feb 09 21:45:26 music go-librespot[17157]: time="2026-02-09T21:45:26-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:26 music volumio[17179]: info: ------------------------------------------- Feb 09 21:45:26 music volumio[17179]: info: ----- Volumio3 ---- Feb 09 21:45:26 music volumio[17179]: info: ------------------------------------------- Feb 09 21:45:26 music volumio[17179]: info: ----- System startup ---- Feb 09 21:45:26 music volumio[17179]: info: ------------------------------------------- Feb 09 21:45:26 music go-librespot[17157]: time="2026-02-09T21:45:26-05:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 21:45:26 music go-librespot[17157]: time="2026-02-09T21:45:26-05:00" level=debug msg="completed keyexchange" Feb 09 21:45:26 music go-librespot[17157]: time="2026-02-09T21:45:26-05:00" level=debug msg="completed challenge" Feb 09 21:45:27 music volumio[17179]: info: MYVOLUMIO Environment detected Feb 09 21:45:27 music volumio[17179]: info: Plugin folders cleanup Feb 09 21:45:27 music volumio[17179]: info: Scanning into folder /volumio/app/plugins/ Feb 09 21:45:27 music volumio[17179]: info: Scanning category audio_interface Feb 09 21:45:27 music volumio[17179]: info: Scanning category miscellanea Feb 09 21:45:27 music go-librespot[17157]: time="2026-02-09T21:45:27-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:27 music volumio[17179]: info: Scanning category music_service Feb 09 21:45:27 music volumio[17179]: info: Scanning category plugins.json Feb 09 21:45:27 music volumio[17179]: info: Scanning category system_controller Feb 09 21:45:27 music volumio[17179]: info: Scanning category user_interface Feb 09 21:45:27 music volumio[17179]: info: Scanning into folder /data/plugins/ Feb 09 21:45:27 music volumio[17179]: info: Scanning category music_service Feb 09 21:45:27 music volumio[17179]: info: Plugin folders cleanup completed Feb 09 21:45:27 music volumio[17179]: info: ------------------------------------------- Feb 09 21:45:27 music volumio[17179]: info: ----- Core plugins startup ---- Feb 09 21:45:27 music volumio[17179]: info: ------------------------------------------- Feb 09 21:45:27 music volumio[17179]: info: Loading plugins from folder /volumio/app/plugins/ Feb 09 21:45:27 music volumio[17179]: info: Adding plugin upnp to MyMusic Plugins Feb 09 21:45:27 music volumio[17179]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 09 21:45:27 music volumio[17179]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 09 21:45:27 music volumio[17179]: info: Loading plugins from folder /data/plugins/ Feb 09 21:45:27 music volumio[17179]: info: Loading plugin "system"... Feb 09 21:45:27 music volumio[17179]: info: Loading plugin "appearance"... Feb 09 21:45:27 music go-librespot[17157]: time="2026-02-09T21:45:27-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 09 21:45:27 music go-librespot[17157]: time="2026-02-09T21:45:27-05:00" level=debug msg="completed keyexchange" Feb 09 21:45:27 music go-librespot[17157]: time="2026-02-09T21:45:27-05:00" level=debug msg="completed challenge" Feb 09 21:45:28 music go-librespot[17157]: time="2026-02-09T21:45:28-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:28 music volumio[17179]: info: Loading plugin "network"... Feb 09 21:45:28 music volumio[17179]: info: Refreshing Cached IP Addresses Feb 09 21:45:28 music sudo[17207]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 21:45:28 music sudo[17207]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:45:28 music sudo[17207]: pam_unix(sudo:session): session closed for user root Feb 09 21:45:28 music volumio[17179]: info: Loading plugin "services"... Feb 09 21:45:28 music volumio[17179]: info: Loading plugin "alsa_controller"... Feb 09 21:45:28 music sudo[17209]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 21:45:28 music sudo[17209]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:45:28 music sudo[17217]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 09 21:45:28 music sudo[17209]: pam_unix(sudo:session): session closed for user root Feb 09 21:45:28 music sudo[17217]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:45:28 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 21:45:28 music volumio[17179]: info: Loading plugin "wizard"... Feb 09 21:45:28 music volumio[17179]: info: Loading plugin "networkfs"... Feb 09 21:45:28 music volumio[17179]: info: Starting Udev Watcher for removable devices Feb 09 21:45:28 music volumio[17179]: info: Ignoring mount for partition: boot Feb 09 21:45:28 music volumio[17179]: info: Ignoring mount for partition: volumio Feb 09 21:45:28 music volumio[17179]: info: Ignoring mount for partition: volumio_data Feb 09 21:45:28 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 21:45:28 music volumio[17179]: info: Loading plugin "volumio_command_line_client"... Feb 09 21:45:28 music volumio[17179]: info: Loading plugin "upnp"... Feb 09 21:45:28 music volumio[17179]: info: [1770691528568] Starting Upmpd Daemon Feb 09 21:45:28 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 21:45:28 music volumio[17179]: info: Loading plugin "my_music"... Feb 09 21:45:28 music volumio[17179]: info: Loading plugin "mpd"... Feb 09 21:45:28 music go-librespot[17157]: time="2026-02-09T21:45:28-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 09 21:45:28 music go-librespot[17157]: time="2026-02-09T21:45:28-05:00" level=debug msg="completed keyexchange" Feb 09 21:45:28 music go-librespot[17157]: time="2026-02-09T21:45:28-05:00" level=debug msg="completed challenge" Feb 09 21:45:28 music go-librespot[17157]: time="2026-02-09T21:45:28-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:28 music go-librespot[17157]: time="2026-02-09T21:45:28-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:28 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 21:45:28 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 21:45:28 music volumio[17179]: info: Loading plugin "upnp_browser"... Feb 09 21:45:28 music volumio-remote-updater[30265]: [2026-02-09 21:45:28] [connect] Successful connection Feb 09 21:45:29 music sudo[17217]: pam_unix(sudo:session): session closed for user root Feb 09 21:45:30 music volumio[17179]: info: Starting UPNP Browser Feb 09 21:45:30 music volumio[17179]: info: Loading plugin "alarm-clock"... Feb 09 21:45:30 music volumio[17179]: info: Loading plugin "airplay_emulation"... Feb 09 21:45:30 music volumio[17179]: info: Starting Shairport Sync Feb 09 21:45:30 music volumio[17179]: info: Loading plugin "last_100"... Feb 09 21:45:30 music volumio[17179]: info: Loading plugin "webradio"... Feb 09 21:45:30 music volumio[17179]: info: Loading plugin "i2s_dacs"... Feb 09 21:45:30 music volumio[17179]: info: I2S DAC not set, start Auto-detection Feb 09 21:45:30 music volumio[17179]: info: Loading plugin "volumiodiscovery"... Feb 09 21:45:30 music volumio[17179]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 21:45:30 music volumio[17179]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 21:45:30 music volumio[17179]: *** WARNING *** For more information see Feb 09 21:45:30 music volumio[17179]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 21:45:30 music volumio[17179]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 21:45:30 music volumio[17179]: *** WARNING *** For more information see Feb 09 21:45:30 music node[17179]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 21:45:30 music node[17179]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 21:45:30 music node[17179]: *** WARNING *** For more information see Feb 09 21:45:30 music node[17179]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 21:45:30 music node[17179]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 21:45:30 music node[17179]: *** WARNING *** For more information see Feb 09 21:45:30 music volumio[17179]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 09 21:45:30 music volumio[17179]: info: Discovery: Started advertising with name: music Feb 09 21:45:30 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 21:45:30 music volumio[17179]: info: Loading plugin "spop"... Feb 09 21:45:31 music volumio[17179]: info: Loading plugin "outputs"... Feb 09 21:45:31 music volumio[17179]: info: Loading plugin "albumart"... Feb 09 21:45:32 music volumio[17179]: info: Plugin example_plugin is not enabled Feb 09 21:45:32 music volumio[17179]: info: Loading plugin "inputs"... Feb 09 21:45:32 music volumio[17179]: info: Loading plugin "updater_comm"... Feb 09 21:45:32 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 09 21:45:32 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 21:45:32 music volumio[17179]: info: Plugin mpdemulation is not enabled Feb 09 21:45:32 music volumio[17179]: info: Loading plugin "rest_api"... Feb 09 21:45:32 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 21:45:32 music go-librespot[17251]: go-librespot daemon starting... Feb 09 21:45:32 music volumio[17179]: info: Loading plugin "websocket"... Feb 09 21:45:32 music volumio[17179]: info: Starting Socket.io Server version 1.7.4 Feb 09 21:45:32 music go-librespot[17253]: time="2026-02-09T21:45:32-05:00" level=info msg="running go-librespot 0.6.2" Feb 09 21:45:32 music go-librespot[17253]: time="2026-02-09T21:45:32-05:00" level=debug msg="app state loaded" Feb 09 21:45:32 music volumio[17179]: info: Loading i18n strings for locale en Feb 09 21:45:32 music volumio[17179]: Updating browse sources language Feb 09 21:45:32 music go-librespot[17253]: time="2026-02-09T21:45:32-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 21:45:32 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 21:45:32 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 21:45:32 music volumio[17179]: info: CoreCommandRouter::initPlayerControls Feb 09 21:45:32 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:32 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:32 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:32 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:32 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:32 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:32 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:32 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:32 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 21:45:32 music volumio[17179]: Express server listening on port 3000 Feb 09 21:45:32 music volumio[17179]: [Metrics] WebUI: 6s 574.81ms Feb 09 21:45:32 music volumio[17179]: info: CoreStateMachine::resetVolumioState Feb 09 21:45:32 music volumio[17179]: info: CoreStateMachine::getcurrentVolume Feb 09 21:45:32 music volumio[17179]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 21:45:32 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:45:32 music volumio[17179]: info: Volumio Network Manager: Network status updated: 1 Feb 09 21:45:32 music go-librespot[17253]: time="2026-02-09T21:45:32-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Feb 09 21:45:32 music go-librespot[17253]: time="2026-02-09T21:45:32-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 09 21:45:32 music go-librespot[17253]: time="2026-02-09T21:45:32-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 09 21:45:32 music go-librespot[17253]: time="2026-02-09T21:45:32-05:00" level=info msg="zeroconf server listening on port 43413" Feb 09 21:45:32 music volumio-remote-updater[30265]: [2026-02-09 21:45:32] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770691528 101 Feb 09 21:45:32 music volumio[17242]: Forking 3 albumart workers Feb 09 21:45:32 music volumio[17179]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 09 21:45:32 music volumio[17179]: info: VolumeController:: Volume=86 Mute =false Feb 09 21:45:32 music volumio[17179]: info: CoreStateMachine::pushState Feb 09 21:45:32 music volumio[17179]: info: CorePlayQueue::getTrack 0 Feb 09 21:45:32 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 21:45:32 music volumio[17179]: info: CoreCommandRouter::volumioPushState Feb 09 21:45:32 music volumio[17179]: info: CoreStateMachine::updateTrackBlock Feb 09 21:45:32 music volumio[17179]: info: CorePlayQueue::getTrackBlock Feb 09 21:45:32 music volumio[17179]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 21:45:32 music volumio[17179]: info: Reloading queue from file Feb 09 21:45:32 music go-librespot[17253]: time="2026-02-09T21:45:32-05:00" level=debug msg="obtained new client token: AABPN8czkIWdms9ks1fCBfzPx99mCvCgNdhnFXhVzwye9n0OAsjnEAn2lppPfEduBN4IcRNQzZP4x3UNP1RMx1fwvTPOuo9+GkLkof0vVBwOET49zbp0oKcsmc5lCLuwMa5hu9TZ4RzLLA6CJvu1to2ilpn/eE6IOIjm5F1YBTf1g5rkVmcF2S5PrB2oT+l2ZVuWHKrQu2kN9cowgyGdJfsNieewz7CuoU7D1go6swUHbM0S+DEYgC8=" Feb 09 21:45:32 music volumio[17179]: info: CoreStateMachine::setRepeat null single undefined Feb 09 21:45:32 music volumio[17179]: info: CoreStateMachine::pushState Feb 09 21:45:32 music volumio[17179]: info: CorePlayQueue::getTrack 0 Feb 09 21:45:32 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 21:45:32 music volumio[17179]: info: CoreCommandRouter::volumioPushState Feb 09 21:45:32 music volumio[17179]: info: CoreStateMachine::setRandom null Feb 09 21:45:32 music volumio[17179]: info: CoreStateMachine::pushState Feb 09 21:45:32 music volumio[17179]: info: CorePlayQueue::getTrack 0 Feb 09 21:45:32 music volumio[17179]: info: CoreCommandRouter::volumioPushState Feb 09 21:45:32 music volumio[17179]: info: Setting Device type: Raspberry PI Feb 09 21:45:32 music go-librespot[17253]: time="2026-02-09T21:45:32-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 09 21:45:32 music volumio[17179]: info: VolumeController:: Volume=86 Mute =false Feb 09 21:45:32 music volumio[17179]: info: CoreStateMachine::pushState Feb 09 21:45:32 music volumio[17179]: info: CorePlayQueue::getTrack 0 Feb 09 21:45:32 music volumio[17179]: info: CoreCommandRouter::volumioPushState Feb 09 21:45:32 music go-librespot[17253]: time="2026-02-09T21:45:32-05:00" level=debug msg="completed keyexchange" Feb 09 21:45:32 music go-librespot[17253]: time="2026-02-09T21:45:32-05:00" level=debug msg="completed challenge" Feb 09 21:45:32 music volumio[17179]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 09 21:45:32 music volumio[17179]: info: Discovery: Found device music Feb 09 21:45:32 music volumio[17179]: info: CoreCommandRouter::volumioGetState Feb 09 21:45:32 music volumio[17179]: info: CorePlayQueue::getTrack 0 Feb 09 21:45:32 music volumio[17179]: info: Completed loading Core Plugins Feb 09 21:45:32 music volumio[17179]: info: Preparing to generate the ALSA configuration file Feb 09 21:45:32 music go-librespot[17253]: time="2026-02-09T21:45:32-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:32 music volumio[17179]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 09 21:45:32 music volumio[17179]: info: Discovery: Found device music Feb 09 21:45:32 music volumio[17179]: info: CoreCommandRouter::volumioGetState Feb 09 21:45:32 music volumio[17179]: info: CorePlayQueue::getTrack 0 Feb 09 21:45:32 music volumio[17179]: info: Asound.conf file unchanged, so no further update is needed Feb 09 21:45:32 music volumio[17179]: info: Output device has changed, restarting MPD Feb 09 21:45:32 music volumio[17179]: info: Output device has changed, restarting Shairport Sync Feb 09 21:45:32 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:32 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:45:33 music sudo[17307]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 21:45:33 music sudo[17307]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:45:33 music sudo[17309]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 21:45:33 music sudo[17309]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:45:33 music sudo[17307]: pam_unix(sudo:session): session closed for user root Feb 09 21:45:33 music volumio[17179]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 21:45:33 music volumio[17179]: info: ___________ START PLUGINS ___________ Feb 09 21:45:33 music volumio[17179]: info: ControllerMpd::onStart: Initializing MPD Feb 09 21:45:33 music volumio[17179]: info: Creating MPD Configuration file Feb 09 21:45:33 music systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 09 21:45:33 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 21:45:33 music volumio[17179]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 21:45:33 music volumio[17179]: info: [1770691533146] CoreMusicLibrary::Adding element Media Servers Feb 09 21:45:33 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 21:45:33 music systemd[1]: mpd.service: Deactivated successfully. Feb 09 21:45:33 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 09 21:45:33 music systemd[1]: mpd.service: Consumed 4.184s CPU time. Feb 09 21:45:33 music systemd[1]: mpd.socket: Deactivated successfully. Feb 09 21:45:33 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 09 21:45:33 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 09 21:45:33 music volumio[17179]: info: UPNP Browser: Client initialized successfully Feb 09 21:45:33 music sudo[17319]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 21:45:33 music sudo[17319]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:45:33 music sudo[17318]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 21:45:33 music sudo[17318]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:45:33 music sudo[17318]: pam_unix(sudo:session): session closed for user root Feb 09 21:45:33 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:33 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:45:33 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 09 21:45:33 music volumio[17179]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 21:45:33 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:33 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:45:33 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 09 21:45:33 music systemd[1]: mpd.service: Deactivated successfully. Feb 09 21:45:33 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 09 21:45:33 music systemd[1]: mpd.socket: Deactivated successfully. Feb 09 21:45:33 music volumio[17179]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 21:45:33 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 09 21:45:33 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 09 21:45:33 music volumio[17179]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 21:45:33 music volumio[17179]: info: [1770691533342] CoreMusicLibrary::Adding element Last_100 Feb 09 21:45:33 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 21:45:33 music volumio[17179]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 21:45:33 music volumio[17179]: info: [1770691533348] CoreMusicLibrary::Adding element Webradio Feb 09 21:45:33 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 21:45:33 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 09 21:45:33 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 21:45:33 music volumio[17179]: info: Initializing BBC Radios Feb 09 21:45:33 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 09 21:45:33 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 21:45:33 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:45:33 music volumio[17179]: info: Creating Spotify config file Feb 09 21:45:33 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:33 music go-librespot[17253]: time="2026-02-09T21:45:33-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.255.62:443: connect: connection refused" Feb 09 21:45:33 music go-librespot[17253]: time="2026-02-09T21:45:33-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:80, retrying with a different AP" error="dial tcp 34.158.255.62:80: connect: connection refused" Feb 09 21:45:33 music go-librespot[17253]: time="2026-02-09T21:45:33-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 09 21:45:33 music sudo[17333]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 09 21:45:33 music sudo[17333]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 09 21:45:33 music sudo[17333]: pam_unix(sudo:session): session closed for user root Feb 09 21:45:33 music go-librespot[17253]: time="2026-02-09T21:45:33-05:00" level=debug msg="completed keyexchange" Feb 09 21:45:33 music go-librespot[17253]: time="2026-02-09T21:45:33-05:00" level=debug msg="completed challenge" Feb 09 21:45:33 music go-librespot[17253]: time="2026-02-09T21:45:33-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:34 music volumio[17179]: info: Volumio Calling Home Feb 09 21:45:34 music volumio[17270]: Starting albumart workers Feb 09 21:45:34 music go-librespot[17253]: time="2026-02-09T21:45:34-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 09 21:45:34 music volumio[17269]: Starting albumart workers Feb 09 21:45:34 music volumio[17268]: Starting albumart workers Feb 09 21:45:34 music go-librespot[17253]: time="2026-02-09T21:45:34-05:00" level=debug msg="completed keyexchange" Feb 09 21:45:34 music go-librespot[17253]: time="2026-02-09T21:45:34-05:00" level=debug msg="completed challenge" Feb 09 21:45:34 music go-librespot[17253]: time="2026-02-09T21:45:34-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:34 music volumio[17179]: info: MPD Permissions set Feb 09 21:45:34 music volumio[17179]: info: MPD Permissions set Feb 09 21:45:35 music volumio[17179]: info: Volumio called home Feb 09 21:45:35 music volumio[17179]: info: Spotify config file written Feb 09 21:45:35 music volumio[17179]: info: CoreCommandRouter::volumioGetState Feb 09 21:45:35 music volumio[17179]: info: CorePlayQueue::getTrack 0 Feb 09 21:45:35 music volumio[17179]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 09 21:45:35 music sudo[17355]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 09 21:45:35 music sudo[17355]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:45:35 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:35 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:35 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:35 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:35 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:35 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:35 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:35 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:35 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 09 21:45:35 music systemd[1]: go-librespot-daemon.service: Killing process 17257 (go-librespot) with signal SIGKILL. Feb 09 21:45:35 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 09 21:45:35 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 21:45:35 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:45:35 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:35 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:35 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:35 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:35 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:35 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:35 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:35 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:35 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:35 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 21:45:35 music go-librespot[17362]: go-librespot daemon starting... Feb 09 21:45:35 music sudo[17355]: pam_unix(sudo:session): session closed for user root Feb 09 21:45:35 music go-librespot[17365]: time="2026-02-09T21:45:35-05:00" level=info msg="running go-librespot 0.6.2" Feb 09 21:45:35 music go-librespot[17365]: time="2026-02-09T21:45:35-05:00" level=debug msg="app state loaded" Feb 09 21:45:35 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:45:35 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 21:45:35 music go-librespot[17365]: time="2026-02-09T21:45:35-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 21:45:35 music volumio[17179]: info: No need to fix Spotify hosts Feb 09 21:45:35 music volumio[17179]: info: Listing playlists Feb 09 21:45:35 music volumio[17179]: info: Listing playlists Feb 09 21:45:35 music volumio[17179]: info: Starting Shairport Sync Feb 09 21:45:35 music volumio[17179]: info: Starting Shairport Sync Feb 09 21:45:35 music volumio[17179]: info: Starting Shairport Sync Feb 09 21:45:36 music sudo[17399]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 21:45:36 music sudo[17399]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:45:36 music sudo[17398]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 21:45:36 music sudo[17398]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:45:36 music volumio[17179]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 09 21:45:36 music go-librespot[17365]: time="2026-02-09T21:45:36-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 21:45:36 music go-librespot[17365]: time="2026-02-09T21:45:36-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 21:45:36 music go-librespot[17365]: time="2026-02-09T21:45:36-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 21:45:36 music go-librespot[17365]: time="2026-02-09T21:45:36-05:00" level=info msg="zeroconf server listening on port 33111" Feb 09 21:45:36 music sudo[17401]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 21:45:36 music sudo[17401]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:45:36 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 09 21:45:36 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 09 21:45:36 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 21:45:36 music systemd[1]: shairport-sync.service: Consumed 1.873s CPU time. Feb 09 21:45:36 music volumio[17179]: info: CoreCommandRouter::volumioGetState Feb 09 21:45:36 music volumio[17179]: info: CorePlayQueue::getTrack 0 Feb 09 21:45:36 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 21:45:36 music sudo[17398]: pam_unix(sudo:session): session closed for user root Feb 09 21:45:36 music sudo[17399]: pam_unix(sudo:session): session closed for user root Feb 09 21:45:36 music sudo[17401]: pam_unix(sudo:session): session closed for user root Feb 09 21:45:36 music volumio[17179]: info: Shairport-Sync Started Feb 09 21:45:36 music volumio[17179]: Error adding Membership: Error: addMembership EINVAL Feb 09 21:45:36 music volumio[17179]: info: Shairport-Sync Started Feb 09 21:45:36 music volumio[17179]: info: Shairport-Sync Started Feb 09 21:45:36 music go-librespot[17365]: time="2026-02-09T21:45:36-05:00" level=debug msg="obtained new client token: AAA7fHalRKKPx4fjiZe647Pf/VjKYRwj3O9HaMP1kSKz1IYyU0k7oEORGlEHG+cD8cbL8xBj0zHst8LT/yEA9udt14s3eeZ4C/RyNDGYsD+z5J8+go3d9rRWdd2M8qWVElYxwfrYeD89Txp8RS2YeTGjPH8KmLKK5XqR8v4qO6XLSdze1sH+XjYqdqa/3k0GvIok1dGU49G4sK23EVWW6TfnFt6rLYsTfhYTtfZibhDrNEWxLdz5" Feb 09 21:45:36 music go-librespot[17365]: time="2026-02-09T21:45:36-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 09 21:45:36 music go-librespot[17365]: time="2026-02-09T21:45:36-05:00" level=debug msg="completed keyexchange" Feb 09 21:45:36 music go-librespot[17365]: time="2026-02-09T21:45:36-05:00" level=debug msg="completed challenge" Feb 09 21:45:36 music go-librespot[17365]: time="2026-02-09T21:45:36-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:37 music go-librespot[17365]: time="2026-02-09T21:45:37-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.255.62:443: connect: connection refused" Feb 09 21:45:37 music go-librespot[17365]: time="2026-02-09T21:45:37-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 09 21:45:37 music go-librespot[17365]: time="2026-02-09T21:45:37-05:00" level=debug msg="completed keyexchange" Feb 09 21:45:37 music go-librespot[17365]: time="2026-02-09T21:45:37-05:00" level=debug msg="completed challenge" Feb 09 21:45:37 music go-librespot[17365]: time="2026-02-09T21:45:37-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:37 music go-librespot[17365]: time="2026-02-09T21:45:37-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 09 21:45:37 music mpd[17350]: 2026-02-09T21:45:37 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 09 21:45:37 music systemd[1]: Started mpd.service - Music Player Daemon. Feb 09 21:45:37 music go-librespot[17365]: time="2026-02-09T21:45:37-05:00" level=debug msg="completed keyexchange" Feb 09 21:45:37 music go-librespot[17365]: time="2026-02-09T21:45:37-05:00" level=debug msg="completed challenge" Feb 09 21:45:37 music sudo[17319]: pam_unix(sudo:session): session closed for user root Feb 09 21:45:37 music sudo[17309]: pam_unix(sudo:session): session closed for user root Feb 09 21:45:37 music volumio[17179]: info: Completed starting Core Plugins Feb 09 21:45:37 music volumio[17179]: info: ------------------------------------------- Feb 09 21:45:37 music volumio[17179]: info: ----- MyVolumio plugins startup ---- Feb 09 21:45:37 music volumio[17179]: info: ------------------------------------------- Feb 09 21:45:37 music volumio[17179]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 09 21:45:37 music go-librespot[17365]: time="2026-02-09T21:45:37-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:37 music volumio[17179]: error: MPD error: The expression evaluated to a falsy value: Feb 09 21:45:37 music volumio[17179]: assert.ok(self.idling) Feb 09 21:45:37 music volumio[17179]: error: The expression evaluated to a falsy value: Feb 09 21:45:37 music volumio[17179]: assert.ok(self.idling) Feb 09 21:45:37 music volumio[17179]: error: updateQueue error: null Feb 09 21:45:37 music volumio[17179]: info: MPD running with PID17350 Feb 09 21:45:37 music volumio[17179]: ,establishing connection Feb 09 21:45:37 music volumio[17179]: error: updateQueue error: null Feb 09 21:45:38 music sudo[17442]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 21:45:38 music sudo[17442]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:45:38 music go-librespot[17365]: time="2026-02-09T21:45:38-05:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.241.202:443: connect: connection refused" Feb 09 21:45:38 music sudo[17442]: pam_unix(sudo:session): session closed for user root Feb 09 21:45:38 music sudo[17444]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 21:45:38 music sudo[17444]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:45:38 music sudo[17444]: pam_unix(sudo:session): session closed for user root Feb 09 21:45:38 music sudo[17447]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 09 21:45:38 music sudo[17447]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:45:38 music sudo[17447]: pam_unix(sudo:session): session closed for user root Feb 09 21:45:38 music volumio[17179]: info: Upmpdcli Daemon Started Feb 09 21:45:38 music go-librespot[17365]: time="2026-02-09T21:45:38-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 09 21:45:38 music volumio[17179]: info: go-librespot daemon successfully initialized Feb 09 21:45:38 music go-librespot[17365]: time="2026-02-09T21:45:38-05:00" level=debug msg="completed keyexchange" Feb 09 21:45:38 music go-librespot[17365]: time="2026-02-09T21:45:38-05:00" level=debug msg="completed challenge" Feb 09 21:45:39 music go-librespot[17365]: time="2026-02-09T21:45:39-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:39 music go-librespot[17365]: time="2026-02-09T21:45:39-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 09 21:45:39 music go-librespot[17365]: time="2026-02-09T21:45:39-05:00" level=debug msg="completed keyexchange" Feb 09 21:45:39 music go-librespot[17365]: time="2026-02-09T21:45:39-05:00" level=debug msg="completed challenge" Feb 09 21:45:39 music go-librespot[17365]: time="2026-02-09T21:45:39-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:40 music go-librespot[17365]: time="2026-02-09T21:45:40-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.255.62:443: connect: connection refused" Feb 09 21:45:40 music go-librespot[17365]: time="2026-02-09T21:45:40-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 09 21:45:40 music go-librespot[17365]: time="2026-02-09T21:45:40-05:00" level=debug msg="completed keyexchange" Feb 09 21:45:40 music go-librespot[17365]: time="2026-02-09T21:45:40-05:00" level=debug msg="completed challenge" Feb 09 21:45:40 music go-librespot[17365]: time="2026-02-09T21:45:40-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:40 music go-librespot[17365]: time="2026-02-09T21:45: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 09 21:45:40 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 21:45:40 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 21:45:40 music sudo[17451]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 09 21:45:40 music sudo[17451]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:45:40 music sudo[17453]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 09 21:45:40 music sudo[17453]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:45:40 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 09 21:45:40 music systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 09 21:45:40 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 09 21:45:41 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 09 21:45:41 music sudo[17451]: pam_unix(sudo:session): session closed for user root Feb 09 21:45:41 music sudo[17453]: pam_unix(sudo:session): session closed for user root Feb 09 21:45:41 music mpd_monitor.sh[17456]: MPD Monitor Service: Starting MPD Monitor Service Feb 09 21:45:41 music volumio[17179]: info: Successfully started MPD Monitor Feb 09 21:45:41 music volumio[17179]: info: Successfully started MPD Monitor Feb 09 21:45:41 music volumio[17179]: info: Initializing connection to go-librespot Websocket Feb 09 21:45:41 music volumio[17179]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 21:45:42 music volumio[17179]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 09 21:45:43 music volumio[17179]: info: CoreCommandRouter::volumioGetState Feb 09 21:45:43 music volumio[17179]: info: CorePlayQueue::getTrack 0 Feb 09 21:45:43 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 09 21:45:43 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 21:45:43 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 21:45:43 music go-librespot[17460]: go-librespot daemon starting... Feb 09 21:45:43 music go-librespot[17461]: time="2026-02-09T21:45:43-05:00" level=info msg="running go-librespot 0.6.2" Feb 09 21:45:43 music go-librespot[17461]: time="2026-02-09T21:45:43-05:00" level=debug msg="app state loaded" Feb 09 21:45:43 music go-librespot[17461]: time="2026-02-09T21:45:43-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 21:45:44 music go-librespot[17461]: time="2026-02-09T21:45:44-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 21:45:44 music go-librespot[17461]: time="2026-02-09T21:45:44-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 21:45:44 music go-librespot[17461]: time="2026-02-09T21:45:44-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 21:45:44 music go-librespot[17461]: time="2026-02-09T21:45:44-05:00" level=info msg="zeroconf server listening on port 44277" Feb 09 21:45:44 music go-librespot[17461]: time="2026-02-09T21:45:44-05:00" level=debug msg="obtained new client token: AABQO5wYmO6UOVKBw9iRVFXXO/vGvX7kZlm9LGNv3UfdSi9hqP15VPM08BVJmU8REyjxo/svUzjrV7+m9jGCARnJc4hwL6gwu7tOB9dyXbKetC05GqGV4uRfFMOTEogVk7sDzpcgprib4FgPOIMrUQ3UdnZNw+5UburRRqqlNH36vsaVxyLMBxJ896vOxxh8uWvkUarXHpC6zg1lsVoMhK6b9nIpqXdf+khwFibMQ3E/GsZRn8rq5ho=" Feb 09 21:45:44 music go-librespot[17461]: time="2026-02-09T21:45:44-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 09 21:45:44 music go-librespot[17461]: time="2026-02-09T21:45:44-05:00" level=debug msg="completed keyexchange" Feb 09 21:45:44 music go-librespot[17461]: time="2026-02-09T21:45:44-05:00" level=debug msg="completed challenge" Feb 09 21:45:44 music go-librespot[17461]: time="2026-02-09T21:45:44-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:44 music volumio[17179]: info: Initializing connection to go-librespot Websocket Feb 09 21:45:44 music go-librespot[17461]: time="2026-02-09T21:45:44-05:00" level=debug msg="new websocket client" Feb 09 21:45:44 music volumio[17179]: info: Connection to go-librespot Websocket established Feb 09 21:45:45 music go-librespot[17461]: time="2026-02-09T21:45:45-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 09 21:45:45 music go-librespot[17461]: time="2026-02-09T21:45:45-05:00" level=debug msg="completed keyexchange" Feb 09 21:45:45 music go-librespot[17461]: time="2026-02-09T21:45:45-05:00" level=debug msg="completed challenge" Feb 09 21:45:45 music go-librespot[17461]: time="2026-02-09T21:45:45-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:45 music go-librespot[17461]: time="2026-02-09T21:45:45-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 09 21:45:45 music go-librespot[17461]: time="2026-02-09T21:45:45-05:00" level=debug msg="completed keyexchange" Feb 09 21:45:45 music go-librespot[17461]: time="2026-02-09T21:45:45-05:00" level=debug msg="completed challenge" Feb 09 21:45:45 music go-librespot[17461]: time="2026-02-09T21:45:45-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:46 music go-librespot[17461]: time="2026-02-09T21:45:46-05:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 21:45:46 music go-librespot[17461]: time="2026-02-09T21:45:46-05:00" level=debug msg="completed keyexchange" Feb 09 21:45:46 music go-librespot[17461]: time="2026-02-09T21:45:46-05:00" level=debug msg="completed challenge" Feb 09 21:45:47 music volumio[17179]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 09 21:45:47 music volumio[17179]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 09 21:45:47 music volumio[17179]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 09 21:45:47 music volumio[17179]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 09 21:45:47 music volumio[17179]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 09 21:45:47 music volumio[17179]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 09 21:45:47 music volumio[17179]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 09 21:45:47 music volumio[17179]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 09 21:45:47 music volumio[17179]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 09 21:45:47 music volumio[17179]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 09 21:45:47 music volumio[17179]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 09 21:45:47 music volumio[17179]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 09 21:45:47 music volumio[17179]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 09 21:45:47 music volumio[17179]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 09 21:45:47 music volumio[17179]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 09 21:45:47 music volumio[17179]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 09 21:45:47 music volumio[17179]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 09 21:45:47 music volumio[17179]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 09 21:45:47 music volumio[17179]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 09 21:45:47 music volumio[17179]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 09 21:45:47 music volumio[17179]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 09 21:45:47 music volumio[17179]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 09 21:45:47 music volumio[17179]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 09 21:45:47 music volumio[17179]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 09 21:45:47 music volumio[17179]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 09 21:45:47 music volumio[17179]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 09 21:45:47 music volumio[17179]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 09 21:45:47 music volumio[17179]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 09 21:45:47 music volumio[17179]: info: Adding plugin bluetooth to MyMusic Plugins Feb 09 21:45:47 music volumio[17179]: info: Adding plugin multiroom to MyMusic Plugins Feb 09 21:45:47 music volumio[17179]: info: Adding plugin metavolumio to MyMusic Plugins Feb 09 21:45:47 music volumio[17179]: info: Adding plugin cd_controller to MyMusic Plugins Feb 09 21:45:47 music volumio[17179]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 09 21:45:47 music volumio[17179]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 09 21:45:47 music volumio[17179]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 09 21:45:47 music volumio[17179]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 09 21:45:47 music go-librespot[17461]: time="2026-02-09T21:45:47-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:47 music go-librespot[17461]: time="2026-02-09T21:45:47-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 09 21:45:47 music go-librespot[17461]: time="2026-02-09T21:45:47-05:00" level=debug msg="completed keyexchange" Feb 09 21:45:47 music go-librespot[17461]: time="2026-02-09T21:45:47-05:00" level=debug msg="completed challenge" Feb 09 21:45:47 music go-librespot[17461]: time="2026-02-09T21:45:47-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:48 music volumio[17179]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 09 21:45:48 music volumio[17179]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 09 21:45:48 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:45:48 music volumio[17179]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 21:45:48 music volumio[17179]: info: Starting MyVolumio Remote Streaming Endpoints Feb 09 21:45:48 music volumio[17179]: info: MyVolumio login type: Token Feb 09 21:45:48 music volumio[17179]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 09 21:45:48 music volumio[17179]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 09 21:45:48 music go-librespot[17461]: time="2026-02-09T21:45:48-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 09 21:45:48 music go-librespot[17461]: time="2026-02-09T21:45:48-05:00" level=debug msg="completed keyexchange" Feb 09 21:45:48 music go-librespot[17461]: time="2026-02-09T21:45:48-05:00" level=debug msg="completed challenge" Feb 09 21:45:48 music go-librespot[17461]: time="2026-02-09T21:45:48-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:48 music go-librespot[17461]: time="2026-02-09T21:45:48-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 21:45:48 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 21:45:48 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 21:45:49 music volumio[17179]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 09 21:45:49 music volumio[17179]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 09 21:45:49 music volumio[17179]: info: Streaming services startup Feb 09 21:45:49 music volumio[17179]: info: Starting Streaming Daemon Feb 09 21:45:49 music sudo[17485]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 09 21:45:49 music sudo[17485]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 21:45:49 music volumio[17179]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 09 21:45:49 music sudo[17485]: pam_unix(sudo:session): session closed for user root Feb 09 21:45:49 music volumio[17179]: info: Getting Spotify volume Feb 09 21:45:49 music volumio[17179]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 21:45:49 music volumio[17179]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 21:45:49 music volumio[17179]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 09 21:45:49 music volumio[17179]: errno: -111, Feb 09 21:45:49 music volumio[17179]: code: 'ECONNREFUSED', Feb 09 21:45:49 music volumio[17179]: syscall: 'connect', Feb 09 21:45:49 music volumio[17179]: address: '127.0.0.1', Feb 09 21:45:49 music volumio[17179]: port: 9879, Feb 09 21:45:49 music volumio[17179]: response: undefined Feb 09 21:45:49 music volumio[17179]: } Feb 09 21:45:49 music volumio[17179]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 21:45:49 music sudo[17505]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-09 21:44' Feb 09 21:45:49 music sudo[17505]: 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"