Mar 24 18:35:00 volumio go-librespot[20470]: time="2026-03-24T18:35:00Z" level=debug msg="completed keyexchange" Mar 24 18:35:00 volumio go-librespot[20470]: time="2026-03-24T18:35:00Z" level=debug msg="completed challenge" Mar 24 18:35:00 volumio go-librespot[20470]: time="2026-03-24T18:35:00Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:00 volumio volumio[20249]: info: go-librespot daemon successfully initialized Mar 24 18:35:00 volumio go-librespot[20470]: time="2026-03-24T18:35:00Z" level=debug msg="connected to ap-guc3.spotify.com:4070" Mar 24 18:35:00 volumio go-librespot[20470]: time="2026-03-24T18:35:00Z" level=debug msg="completed keyexchange" Mar 24 18:35:00 volumio go-librespot[20470]: time="2026-03-24T18:35:00Z" level=debug msg="completed challenge" Mar 24 18:35:00 volumio go-librespot[20470]: time="2026-03-24T18:35:00Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:01 volumio go-librespot[20470]: time="2026-03-24T18:35:01Z" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 24 18:35:01 volumio go-librespot[20470]: time="2026-03-24T18:35:01Z" level=debug msg="completed keyexchange" Mar 24 18:35:01 volumio go-librespot[20470]: time="2026-03-24T18:35:01Z" level=debug msg="completed challenge" Mar 24 18:35:01 volumio go-librespot[20470]: time="2026-03-24T18:35:01Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:02 volumio volumio[20249]: info: Discovery: this is already registered, 072f109f-54a2-4344-b8c4-538b45da7e51 Mar 24 18:35:02 volumio volumio[20249]: info: Discovery: Found device Volumio Mar 24 18:35:02 volumio volumio[20249]: info: CoreCommandRouter::volumioGetState Mar 24 18:35:02 volumio volumio[20249]: info: CorePlayQueue::getTrack 0 Mar 24 18:35:02 volumio go-librespot[20470]: time="2026-03-24T18:35:02Z" level=debug msg="connected to ap-gae2.spotify.com:80" Mar 24 18:35:02 volumio go-librespot[20470]: time="2026-03-24T18:35:02Z" level=debug msg="completed keyexchange" Mar 24 18:35:02 volumio go-librespot[20470]: time="2026-03-24T18:35:02Z" level=debug msg="completed challenge" Mar 24 18:35:02 volumio go-librespot[20470]: time="2026-03-24T18:35:02Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:02 volumio go-librespot[20470]: time="2026-03-24T18:35:02Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 18:35:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 18:35:03 volumio volumio[20249]: info: Initializing connection to go-librespot Websocket Mar 24 18:35:03 volumio volumio[20249]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 18:35:05 volumio sudo[20522]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 24 18:35:05 volumio sudo[20522]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:05 volumio sudo[20524]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 24 18:35:05 volumio sudo[20524]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:05 volumio sudo[20522]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:05 volumio sudo[20524]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:05 volumio sudo[20528]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 24 18:35:05 volumio sudo[20528]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:05 volumio sudo[20528]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:05 volumio volumio[20249]: info: Upmpdcli Daemon Started Mar 24 18:35:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 24 18:35:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 18:35:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 18:35:05 volumio go-librespot[20530]: go-librespot daemon starting... Mar 24 18:35:05 volumio go-librespot[20531]: time="2026-03-24T18:35:05Z" level=info msg="running go-librespot 0.6.2" Mar 24 18:35:05 volumio go-librespot[20531]: time="2026-03-24T18:35:05Z" level=debug msg="app state loaded" Mar 24 18:35:05 volumio go-librespot[20531]: time="2026-03-24T18:35:05Z" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 18:35:06 volumio go-librespot[20531]: time="2026-03-24T18:35:06Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 24 18:35:06 volumio go-librespot[20531]: time="2026-03-24T18:35:06Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 24 18:35:06 volumio go-librespot[20531]: time="2026-03-24T18:35:06Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 24 18:35:06 volumio go-librespot[20531]: time="2026-03-24T18:35:06Z" level=info msg="zeroconf server listening on port 34517" Mar 24 18:35:06 volumio go-librespot[20531]: time="2026-03-24T18:35:06Z" level=debug msg="obtained new client token: AADNqoCTb9oPy5XLW+YpQSaDktEu6t2Y0Oan2zTENaT/2ZYEAaKomwb28sD4ZCZfBiYskaB1HjQKCZ42quFMUPqbN+5pYyA54tGEUu3YZAGJVhqR8PUze+snXtGcmLnRwf4gS46wHo8RaddJFvDJe0aYlDBxjOfM6f0yptU9gLb11xEAkCzFyOq6dX11GuwoycrJ3sSZmrLWquNMbh+ajm1ZfQ2t8zs18eflM/OivhIAXp8jw4hCJvs=" Mar 24 18:35:06 volumio go-librespot[20531]: time="2026-03-24T18:35:06Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Mar 24 18:35:06 volumio go-librespot[20531]: time="2026-03-24T18:35:06Z" level=debug msg="completed keyexchange" Mar 24 18:35:06 volumio go-librespot[20531]: time="2026-03-24T18:35:06Z" level=debug msg="completed challenge" Mar 24 18:35:06 volumio go-librespot[20531]: time="2026-03-24T18:35:06Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:06 volumio volumio[20249]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 24 18:35:06 volumio volumio[20249]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 24 18:35:06 volumio volumio[20249]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 24 18:35:06 volumio volumio[20249]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 24 18:35:06 volumio volumio[20249]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 24 18:35:06 volumio volumio[20249]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 24 18:35:06 volumio volumio[20249]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 24 18:35:06 volumio volumio[20249]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 24 18:35:06 volumio volumio[20249]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 24 18:35:06 volumio volumio[20249]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 24 18:35:06 volumio volumio[20249]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 24 18:35:06 volumio volumio[20249]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 24 18:35:06 volumio volumio[20249]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 24 18:35:06 volumio volumio[20249]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 24 18:35:06 volumio volumio[20249]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 24 18:35:06 volumio volumio[20249]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 24 18:35:06 volumio volumio[20249]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 24 18:35:06 volumio volumio[20249]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 24 18:35:06 volumio volumio[20249]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 24 18:35:06 volumio volumio[20249]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 24 18:35:06 volumio volumio[20249]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 24 18:35:06 volumio volumio[20249]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 24 18:35:06 volumio volumio[20249]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 24 18:35:06 volumio volumio[20249]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 24 18:35:06 volumio volumio[20249]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 24 18:35:06 volumio volumio[20249]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 24 18:35:06 volumio volumio[20249]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 24 18:35:06 volumio volumio[20249]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 24 18:35:06 volumio volumio[20249]: info: Adding plugin bluetooth to MyMusic Plugins Mar 24 18:35:06 volumio volumio[20249]: info: Adding plugin multiroom to MyMusic Plugins Mar 24 18:35:06 volumio volumio[20249]: info: Adding plugin metavolumio to MyMusic Plugins Mar 24 18:35:06 volumio volumio[20249]: info: Adding plugin cd_controller to MyMusic Plugins Mar 24 18:35:06 volumio volumio[20249]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 24 18:35:06 volumio volumio[20249]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 24 18:35:06 volumio volumio[20249]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 24 18:35:06 volumio volumio[20249]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 24 18:35:06 volumio go-librespot[20531]: time="2026-03-24T18:35:06Z" level=debug msg="connected to ap-gew1.spotify.com:443" Mar 24 18:35:06 volumio volumio[20249]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 24 18:35:06 volumio volumio[20249]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 24 18:35:06 volumio volumio[20249]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:06 volumio volumio[20249]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:06 volumio volumio[20249]: info: Starting MyVolumio Remote Streaming Endpoints Mar 24 18:35:06 volumio volumio[20249]: info: MyVolumio login type: Token Mar 24 18:35:06 volumio go-librespot[20531]: time="2026-03-24T18:35:06Z" level=debug msg="completed keyexchange" Mar 24 18:35:06 volumio go-librespot[20531]: time="2026-03-24T18:35:06Z" level=debug msg="completed challenge" Mar 24 18:35:06 volumio volumio[20249]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 24 18:35:06 volumio volumio[20249]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 24 18:35:06 volumio go-librespot[20531]: time="2026-03-24T18:35:06Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:07 volumio volumio[20249]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 24 18:35:07 volumio volumio[20249]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 24 18:35:07 volumio volumio[20249]: info: Streaming services startup Mar 24 18:35:07 volumio volumio[20249]: info: Starting Streaming Daemon Mar 24 18:35:07 volumio sudo[20541]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 24 18:35:07 volumio sudo[20541]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:07 volumio volumio[20249]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 24 18:35:07 volumio sudo[20541]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:07 volumio volumio[20249]: info: Initializing connection to go-librespot Websocket Mar 24 18:35:07 volumio volumio[20249]: error: Cannot start Volumio Streaming Daemon Mar 24 18:35:07 volumio volumio[20249]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 24 18:35:07 volumio volumio[20249]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 24 18:35:07 volumio go-librespot[20531]: time="2026-03-24T18:35:07Z" level=debug msg="new websocket client" Mar 24 18:35:07 volumio volumio[20249]: info: Connection to go-librespot Websocket established Mar 24 18:35:07 volumio go-librespot[20531]: time="2026-03-24T18:35:07Z" level=debug msg="connected to ap-gew1.spotify.com:80" Mar 24 18:35:07 volumio go-librespot[20531]: time="2026-03-24T18:35:07Z" level=debug msg="completed keyexchange" Mar 24 18:35:07 volumio go-librespot[20531]: time="2026-03-24T18:35:07Z" level=debug msg="completed challenge" Mar 24 18:35:07 volumio go-librespot[20531]: time="2026-03-24T18:35:07Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:07 volumio volumio[20249]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 24 18:35:07 volumio volumio[20249]: info: MyVolumio token set successfully Mar 24 18:35:07 volumio volumio[20249]: info: MYVOLUMIO: Adding device Mar 24 18:35:07 volumio volumio[20249]: info: MYVOLUMIO: Evaluating Server Mar 24 18:35:08 volumio go-librespot[20531]: time="2026-03-24T18:35:08Z" level=debug msg="connected to ap-guc3.spotify.com:4070" Mar 24 18:35:08 volumio volumio[20249]: info: MyVolumio status changed Mar 24 18:35:08 volumio volumio[20249]: info: Streaming services startup Mar 24 18:35:08 volumio volumio[20249]: info: Starting Streaming Daemon Mar 24 18:35:08 volumio volumio[20249]: info: Removing browser output: myVolumio user plan is not superstar Mar 24 18:35:08 volumio volumio[20249]: info: Removing audio output: Mar 24 18:35:08 volumio volumio[20249]: info: Stoppping Tunnel 1 Mar 24 18:35:08 volumio sudo[20568]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 24 18:35:08 volumio sudo[20568]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:08 volumio sudo[20570]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Mar 24 18:35:08 volumio sudo[20570]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:08 volumio sudo[20568]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:08 volumio volumio[20249]: error: Cannot start Volumio Streaming Daemon Mar 24 18:35:08 volumio volumio[20249]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 24 18:35:08 volumio volumio[20249]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 24 18:35:08 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 18:35:08 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 18:35:08 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 18:35:08 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 18:35:08 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 18:35:08 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 18:35:08 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 18:35:08 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 18:35:08 volumio sudo[20570]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:08 volumio volumio[20249]: info: Remote SSH Stopped Mar 24 18:35:08 volumio go-librespot[20531]: time="2026-03-24T18:35:08Z" level=debug msg="completed keyexchange" Mar 24 18:35:08 volumio go-librespot[20531]: time="2026-03-24T18:35:08Z" level=debug msg="completed challenge" Mar 24 18:35:08 volumio go-librespot[20531]: time="2026-03-24T18:35:08Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:08 volumio volumio[20249]: info: Setting Geolocation for MyVolumio to eu12 Mar 24 18:35:08 volumio volumio[20249]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:08 volumio volumio[20249]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:08 volumio volumio[20249]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:08 volumio volumio[20249]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Mar 24 18:35:08 volumio go-librespot[20531]: time="2026-03-24T18:35:08Z" level=debug msg="connected to ap-gue1.spotify.com:443" Mar 24 18:35:09 volumio go-librespot[20531]: time="2026-03-24T18:35:09Z" level=debug msg="completed keyexchange" Mar 24 18:35:09 volumio go-librespot[20531]: time="2026-03-24T18:35:09Z" level=debug msg="completed challenge" Mar 24 18:35:09 volumio go-librespot[20531]: time="2026-03-24T18:35:09Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:09 volumio volumio[20249]: info: Updating MyVolumio device info Mar 24 18:35:09 volumio volumio[20249]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:09 volumio volumio[20249]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:09 volumio volumio[20249]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:09 volumio go-librespot[20531]: time="2026-03-24T18:35:09Z" level=debug msg="connected to ap-gew4.spotify.com:80" Mar 24 18:35:09 volumio go-librespot[20531]: time="2026-03-24T18:35:09Z" level=debug msg="completed keyexchange" Mar 24 18:35:09 volumio go-librespot[20531]: time="2026-03-24T18:35:09Z" level=debug msg="completed challenge" Mar 24 18:35:09 volumio go-librespot[20531]: time="2026-03-24T18:35:09Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:09 volumio go-librespot[20531]: time="2026-03-24T18:35:09Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:09 volumio volumio[20249]: info: Connection to go-librespot Websocket closed Mar 24 18:35:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 18:35:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 18:35:10 volumio volumio[20249]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Mar 24 18:35:10 volumio volumio[20249]: info: Getting Spotify volume Mar 24 18:35:10 volumio volumio[20249]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 18:35:10 volumio volumio[20249]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 18:35:10 volumio volumio[20249]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 24 18:35:10 volumio volumio[20249]: errno: -111, Mar 24 18:35:10 volumio volumio[20249]: code: 'ECONNREFUSED', Mar 24 18:35:10 volumio volumio[20249]: syscall: 'connect', Mar 24 18:35:10 volumio volumio[20249]: address: '127.0.0.1', Mar 24 18:35:10 volumio volumio[20249]: port: 9879, Mar 24 18:35:10 volumio volumio[20249]: response: undefined Mar 24 18:35:10 volumio volumio[20249]: } Mar 24 18:35:10 volumio volumio[20249]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 18:35:10 volumio sudo[20587]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-24 18:34' Mar 24 18:35:10 volumio sudo[20587]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:10 volumio sudo[20587]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:10 volumio volumio-remote-updater[945]: [2026-03-24 18:35:10] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 24 18:35:10 volumio volumio-remote-updater[945]: [2026-03-24 18:35:10] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 24 18:35:10 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 24 18:35:10 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 24 18:35:10 volumio systemd[1]: volumio.service: Consumed 9.019s CPU time. Mar 24 18:35:10 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 24 18:35:10 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Mar 24 18:35:11 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 78821. Mar 24 18:35:11 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 24 18:35:11 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 24 18:35:11 volumio systemd[1]: volumio.service: Consumed 9.019s CPU time. Mar 24 18:35:11 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Mar 24 18:35:11 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Mar 24 18:35:11 volumio volumio[20603]: info: ------------------------------------------- Mar 24 18:35:11 volumio volumio[20603]: info: ----- Volumio3 ---- Mar 24 18:35:11 volumio volumio[20603]: info: ------------------------------------------- Mar 24 18:35:11 volumio volumio[20603]: info: ----- System startup ---- Mar 24 18:35:11 volumio volumio[20603]: info: ------------------------------------------- Mar 24 18:35:11 volumio volumio[20603]: info: MYVOLUMIO Environment detected Mar 24 18:35:11 volumio volumio[20603]: info: Plugin folders cleanup Mar 24 18:35:11 volumio volumio[20603]: info: Scanning into folder /volumio/app/plugins/ Mar 24 18:35:11 volumio volumio[20603]: info: Scanning category audio_interface Mar 24 18:35:11 volumio volumio[20603]: info: Scanning category miscellanea Mar 24 18:35:11 volumio volumio[20603]: info: Scanning category music_service Mar 24 18:35:11 volumio volumio[20603]: info: Scanning category plugins.json Mar 24 18:35:11 volumio volumio[20603]: info: Scanning category system_controller Mar 24 18:35:11 volumio volumio[20603]: info: Scanning category user_interface Mar 24 18:35:11 volumio volumio[20603]: info: Scanning into folder /data/plugins/ Mar 24 18:35:11 volumio volumio[20603]: info: Scanning category music_service Mar 24 18:35:11 volumio volumio[20603]: info: Plugin folders cleanup completed Mar 24 18:35:11 volumio volumio[20603]: info: ------------------------------------------- Mar 24 18:35:11 volumio volumio[20603]: info: ----- Core plugins startup ---- Mar 24 18:35:11 volumio volumio[20603]: info: ------------------------------------------- Mar 24 18:35:11 volumio volumio[20603]: info: Loading plugins from folder /volumio/app/plugins/ Mar 24 18:35:11 volumio volumio[20603]: info: Adding plugin upnp to MyMusic Plugins Mar 24 18:35:11 volumio volumio[20603]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 24 18:35:11 volumio volumio[20603]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 24 18:35:11 volumio volumio[20603]: info: Loading plugins from folder /data/plugins/ Mar 24 18:35:11 volumio volumio[20603]: info: Adding plugin rtlsdr_radio to MyMusic Plugins Mar 24 18:35:11 volumio volumio[20603]: info: Loading plugin "system"... Mar 24 18:35:11 volumio volumio[20603]: info: Loading plugin "appearance"... Mar 24 18:35:12 volumio volumio[20603]: info: Loading plugin "network"... Mar 24 18:35:12 volumio volumio[20603]: info: Refreshing Cached IP Addresses Mar 24 18:35:12 volumio sudo[20631]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 24 18:35:12 volumio sudo[20631]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:12 volumio sudo[20633]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 24 18:35:12 volumio sudo[20633]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:12 volumio sudo[20633]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:12 volumio sudo[20631]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:12 volumio volumio[20603]: info: Loading plugin "services"... Mar 24 18:35:12 volumio volumio[20603]: info: Loading plugin "alsa_controller"... Mar 24 18:35:12 volumio sudo[20642]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 24 18:35:12 volumio sudo[20642]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:12 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 18:35:12 volumio volumio[20603]: info: Loading plugin "wizard"... Mar 24 18:35:12 volumio volumio[20603]: info: Loading plugin "networkfs"... Mar 24 18:35:12 volumio volumio[20603]: info: Starting Udev Watcher for removable devices Mar 24 18:35:12 volumio volumio[20603]: info: Mounting Device 0ACB-A1DE Mar 24 18:35:12 volumio sudo[20670]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/0ACB-A1DE -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Mar 24 18:35:12 volumio sudo[20670]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:12 volumio sudo[20670]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:12 volumio volumio[20603]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Mar 24 18:35:12 volumio volumio[20603]: dmesg(1) may have more information after failed mount system call. Mar 24 18:35:12 volumio volumio[20603]: error: Failed to mount 0ACB-A1DE: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/0ACB-A1DE" -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Mar 24 18:35:12 volumio volumio[20603]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Mar 24 18:35:12 volumio volumio[20603]: dmesg(1) may have more information after failed mount system call. Mar 24 18:35:12 volumio volumio[20603]: info: Ignoring mount for partition: boot Mar 24 18:35:12 volumio volumio[20603]: info: Ignoring mount for partition: volumio Mar 24 18:35:12 volumio volumio[20603]: info: Ignoring mount for partition: volumio_data Mar 24 18:35:12 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 24 18:35:12 volumio volumio[20603]: info: Loading plugin "volumio_command_line_client"... Mar 24 18:35:12 volumio volumio[20603]: info: Loading plugin "upnp"... Mar 24 18:35:12 volumio volumio[20603]: info: [1774377312376] Starting Upmpd Daemon Mar 24 18:35:12 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 24 18:35:12 volumio volumio[20603]: info: Loading plugin "my_music"... Mar 24 18:35:12 volumio volumio[20603]: info: Loading plugin "mpd"... Mar 24 18:35:12 volumio volumio[20603]: info: Loading plugin "upnp_browser"... Mar 24 18:35:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 24 18:35:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 18:35:12 volumio volumio[20603]: info: Starting UPNP Browser Mar 24 18:35:12 volumio volumio[20603]: info: Loading plugin "alarm-clock"... Mar 24 18:35:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 18:35:12 volumio go-librespot[20672]: go-librespot daemon starting... Mar 24 18:35:12 volumio go-librespot[20673]: time="2026-03-24T18:35:12Z" level=info msg="running go-librespot 0.6.2" Mar 24 18:35:12 volumio go-librespot[20673]: time="2026-03-24T18:35:12Z" level=debug msg="app state loaded" Mar 24 18:35:12 volumio go-librespot[20673]: time="2026-03-24T18:35:12Z" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 18:35:12 volumio volumio[20603]: info: Loading plugin "airplay_emulation"... Mar 24 18:35:12 volumio volumio[20603]: info: Starting Shairport Sync Mar 24 18:35:12 volumio volumio[20603]: info: Loading plugin "last_100"... Mar 24 18:35:12 volumio volumio[20603]: info: Loading plugin "webradio"... Mar 24 18:35:13 volumio volumio[20603]: info: Loading plugin "i2s_dacs"... Mar 24 18:35:13 volumio volumio[20603]: info: Loading plugin "volumiodiscovery"... Mar 24 18:35:13 volumio volumio[20603]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 24 18:35:13 volumio volumio[20603]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 18:35:13 volumio volumio[20603]: *** WARNING *** For more information see Mar 24 18:35:13 volumio volumio[20603]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 24 18:35:13 volumio volumio[20603]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 18:35:13 volumio volumio[20603]: *** WARNING *** For more information see Mar 24 18:35:13 volumio node[20603]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 24 18:35:13 volumio node[20603]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 18:35:13 volumio node[20603]: *** WARNING *** For more information see Mar 24 18:35:13 volumio node[20603]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 24 18:35:13 volumio node[20603]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 18:35:13 volumio node[20603]: *** WARNING *** For more information see Mar 24 18:35:13 volumio volumio[20603]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 24 18:35:13 volumio volumio[20603]: info: Discovery: Started advertising with name: Volumio Mar 24 18:35:13 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 24 18:35:13 volumio volumio[20603]: info: Loading plugin "spop"... Mar 24 18:35:13 volumio go-librespot[20673]: time="2026-03-24T18:35:13Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 18:35:13 volumio go-librespot[20673]: time="2026-03-24T18:35:13Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 24 18:35:13 volumio go-librespot[20673]: time="2026-03-24T18:35:13Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 24 18:35:13 volumio go-librespot[20673]: time="2026-03-24T18:35:13Z" level=info msg="zeroconf server listening on port 42985" Mar 24 18:35:13 volumio volumio[20603]: info: Loading plugin "ytmusic"... Mar 24 18:35:13 volumio volumio[20603]: info: Loading plugin "outputs"... Mar 24 18:35:13 volumio volumio[20603]: info: Loading plugin "albumart"... Mar 24 18:35:13 volumio volumio[20603]: info: Plugin example_plugin is not enabled Mar 24 18:35:13 volumio volumio[20603]: info: Loading plugin "inputs"... Mar 24 18:35:13 volumio volumio[20603]: info: Loading plugin "updater_comm"... Mar 24 18:35:13 volumio go-librespot[20673]: time="2026-03-24T18:35:13Z" level=debug msg="obtained new client token: AAAPB4if3rr+n5N45p4pAYm3yqW4jHcYFdNgro4CYL8fGWiIEuJ5F26qyQU/ZGjR1sgltZAkujbxp/2EO3aUax+QvRG607kYzCFv/gCm+g1Pt3mFP61hB/YMwtl71QXc3robg9iGN5TlBaGk8AftRdh8a+VWWbmf8LxHho2iyWKRjhQWbanfb0QVFhuybV6sSgbAu1+yL8rj9TB1am+PLLnFBJKkUJ73YfE7sAPh2q4YhOM6ry+GeM46tQ==" Mar 24 18:35:13 volumio volumio[20603]: info: Plugin mpdemulation is not enabled Mar 24 18:35:13 volumio volumio[20603]: info: Loading plugin "rest_api"... Mar 24 18:35:13 volumio volumio[20603]: info: Loading plugin "websocket"... Mar 24 18:35:13 volumio volumio[20603]: info: Starting Socket.io Server version 1.7.4 Mar 24 18:35:13 volumio volumio[20603]: info: Loading plugin "podcast"... Mar 24 18:35:13 volumio volumio[20603]: info: ControllerPodcast::constructor Mar 24 18:35:13 volumio volumio[20603]: info: Loading plugin "rtlsdr_radio"... Mar 24 18:35:13 volumio volumio[20684]: Forking 3 albumart workers Mar 24 18:35:13 volumio go-librespot[20673]: time="2026-03-24T18:35:13Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Mar 24 18:35:13 volumio go-librespot[20673]: time="2026-03-24T18:35:13Z" level=debug msg="completed keyexchange" Mar 24 18:35:13 volumio go-librespot[20673]: time="2026-03-24T18:35:13Z" level=debug msg="completed challenge" Mar 24 18:35:13 volumio volumio[20603]: info: Loading i18n strings for locale en Mar 24 18:35:13 volumio volumio[20603]: Updating browse sources language Mar 24 18:35:13 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 18:35:13 volumio go-librespot[20673]: time="2026-03-24T18:35:13Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:13 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 18:35:13 volumio volumio[20603]: info: CoreCommandRouter::initPlayerControls Mar 24 18:35:13 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:13 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:13 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:13 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:13 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:13 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:13 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:13 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:13 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 18:35:13 volumio volumio[20603]: Express server listening on port 3000 Mar 24 18:35:13 volumio volumio[20603]: [Metrics] WebUI: 2s 341.44ms Mar 24 18:35:13 volumio volumio[20603]: info: CoreStateMachine::resetVolumioState Mar 24 18:35:13 volumio volumio[20603]: info: CoreStateMachine::getcurrentVolume Mar 24 18:35:13 volumio volumio[20603]: info: CoreCommandRouter::volumioRetrievevolume Mar 24 18:35:13 volumio volumio[20603]: info: Volumio Network Manager: Network status updated: 2 Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:14 volumio volumio[20603]: info: Reloading queue from file Mar 24 18:35:14 volumio volumio[20603]: info: CoreStateMachine::setRepeat null single undefined Mar 24 18:35:14 volumio volumio[20603]: info: CoreStateMachine::pushState Mar 24 18:35:14 volumio volumio[20603]: info: CorePlayQueue::getTrack 0 Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::volumioPushState Mar 24 18:35:14 volumio volumio[20603]: info: CoreStateMachine::setRandom true Mar 24 18:35:14 volumio volumio[20603]: info: CoreStateMachine::pushState Mar 24 18:35:14 volumio volumio[20603]: info: CorePlayQueue::getTrack 0 Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::volumioPushState Mar 24 18:35:14 volumio volumio[20603]: info: VolumeController:: Volume=36 Mute =true Mar 24 18:35:14 volumio volumio[20603]: info: CoreStateMachine::pushState Mar 24 18:35:14 volumio volumio[20603]: info: CorePlayQueue::getTrack 0 Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::volumioPushState Mar 24 18:35:14 volumio volumio[20603]: info: CoreStateMachine::updateTrackBlock Mar 24 18:35:14 volumio volumio[20603]: info: CorePlayQueue::getTrackBlock Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::volumioRetrievevolume Mar 24 18:35:14 volumio volumio[20603]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Mar 24 18:35:14 volumio volumio[20603]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04170 Mar 24 18:35:14 volumio volumio[20603]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Mar 24 18:35:14 volumio volumio[20603]: info: Setting Device type: Raspberry PI Mar 24 18:35:14 volumio volumio[20603]: info: Completed loading Core Plugins Mar 24 18:35:14 volumio volumio[20603]: info: Preparing to generate the ALSA configuration file Mar 24 18:35:14 volumio volumio[20603]: info: Asound.conf file unchanged, so no further update is needed Mar 24 18:35:14 volumio volumio[20603]: info: Output device has changed, restarting MPD Mar 24 18:35:14 volumio volumio[20603]: info: Output device has changed, restarting Shairport Sync Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:14 volumio sudo[20740]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 24 18:35:14 volumio sudo[20740]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:14 volumio sudo[20740]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:14 volumio volumio[20603]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 24 18:35:14 volumio volumio[20603]: info: ___________ START PLUGINS ___________ Mar 24 18:35:14 volumio sudo[20743]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 24 18:35:14 volumio sudo[20743]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:14 volumio volumio[20603]: info: ControllerMpd::onStart: Initializing MPD Mar 24 18:35:14 volumio volumio[20603]: info: Creating MPD Configuration file Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 18:35:14 volumio volumio[20696]: Starting albumart workers Mar 24 18:35:14 volumio volumio[20603]: info: [1774377314143] CoreMusicLibrary::Adding element Media Servers Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 18:35:14 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 24 18:35:14 volumio sudo[20752]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 24 18:35:14 volumio sudo[20752]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:14 volumio volumio[20695]: Starting albumart workers Mar 24 18:35:14 volumio volumio[20603]: info: UPNP Browser: Client initialized successfully Mar 24 18:35:14 volumio sudo[20751]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 24 18:35:14 volumio sudo[20751]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:14 volumio sudo[20751]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:14 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 24 18:35:14 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:14 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:14 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 24 18:35:14 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 24 18:35:14 volumio volumio[20603]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 24 18:35:14 volumio volumio[20694]: Starting albumart workers Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:14 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 24 18:35:14 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 24 18:35:14 volumio volumio[20603]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 18:35:14 volumio volumio[20603]: info: [1774377314214] CoreMusicLibrary::Adding element Last_100 Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 18:35:14 volumio volumio[20603]: info: [1774377314216] CoreMusicLibrary::Adding element Webradio Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 18:35:14 volumio volumio[20603]: info: Initializing BBC Radios Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:14 volumio volumio[20603]: info: Creating Spotify config file Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:14 volumio sudo[20764]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 24 18:35:14 volumio sudo[20764]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 24 18:35:14 volumio sudo[20764]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:14 volumio go-librespot[20673]: time="2026-03-24T18:35:14Z" level=debug msg="connected to ap-gew1.spotify.com:443" Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 18:35:14 volumio volumio[20603]: info: [1774377314467] CoreMusicLibrary::Adding element YouTube Music Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 18:35:14 volumio volumio[20603]: Cannot find translation for source YouTube Music Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 18:35:14 volumio volumio[20603]: info: [1774377314471] CoreMusicLibrary::Adding element Podcast Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 18:35:14 volumio volumio[20603]: Cannot find translation for source YouTube Music Mar 24 18:35:14 volumio volumio[20603]: Cannot find translation for source Podcast Mar 24 18:35:14 volumio volumio[20603]: info: [RTL-SDR Radio] Starting plugin Mar 24 18:35:14 volumio volumio[20603]: info: [RTL-SDR Radio] Loaded i18n strings for language: en Mar 24 18:35:14 volumio volumio[20603]: info: Volumio Calling Home Mar 24 18:35:14 volumio volumio[20603]: info: [RTL-SDR Radio] snd-aloop already loaded Mar 24 18:35:14 volumio volumio[20603]: info: [RTL-SDR Radio] No stations database found, creating v2 Mar 24 18:35:14 volumio volumio[20603]: info: [RTL-SDR Radio] Database loaded at: 2026-03-24T18:35:14.528Z Mar 24 18:35:14 volumio volumio[20603]: info: [RTL-SDR Radio] Loading blocklist from: /data/plugins/music_service/rtlsdr_radio/blocklist.json Mar 24 18:35:14 volumio volumio[20603]: info: [RTL-SDR Radio] Got 21 phrases from file Mar 24 18:35:14 volumio volumio[20603]: info: [RTL-SDR Radio] Updated metadata blocklist Mar 24 18:35:14 volumio volumio[20603]: info: [RTL-SDR Radio] Metadata module now has 21 phrases Mar 24 18:35:14 volumio volumio[20603]: info: [RTL-SDR Radio] Management server started on port 3456 Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 18:35:14 volumio volumio[20603]: info: [1774377314561] CoreMusicLibrary::Adding element FM/DAB Radio Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 18:35:14 volumio volumio[20603]: Cannot find translation for source YouTube Music Mar 24 18:35:14 volumio volumio[20603]: Cannot find translation for source Podcast Mar 24 18:35:14 volumio volumio[20603]: Cannot find translation for source FM/DAB Radio Mar 24 18:35:14 volumio volumio[20603]: info: [RTL-SDR Radio] Plugin started successfully Mar 24 18:35:14 volumio volumio[20603]: info: MPD Permissions set Mar 24 18:35:14 volumio volumio[20603]: info: MPD Permissions set Mar 24 18:35:14 volumio volumio[20603]: info: VolumeController:: Volume=36 Mute =true Mar 24 18:35:14 volumio volumio[20603]: info: CoreStateMachine::pushState Mar 24 18:35:14 volumio volumio[20603]: info: CorePlayQueue::getTrack 0 Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::volumioPushState Mar 24 18:35:14 volumio volumio[20603]: info: Spotify config file written Mar 24 18:35:14 volumio go-librespot[20673]: time="2026-03-24T18:35:14Z" level=debug msg="completed keyexchange" Mar 24 18:35:14 volumio go-librespot[20673]: time="2026-03-24T18:35:14Z" level=debug msg="completed challenge" Mar 24 18:35:14 volumio sudo[20808]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 24 18:35:14 volumio sudo[20808]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:14 volumio volumio[20603]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:14 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 24 18:35:14 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 24 18:35:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:14 volumio volumio[20603]: info: No need to fix Spotify hosts Mar 24 18:35:14 volumio volumio[20603]: info: Starting Shairport Sync Mar 24 18:35:14 volumio volumio[20603]: info: Starting Shairport Sync Mar 24 18:35:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 18:35:14 volumio go-librespot[20820]: go-librespot daemon starting... Mar 24 18:35:14 volumio volumio[20603]: info: Starting Shairport Sync Mar 24 18:35:14 volumio sudo[20808]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:14 volumio go-librespot[20824]: time="2026-03-24T18:35:14Z" level=info msg="running go-librespot 0.6.2" Mar 24 18:35:14 volumio go-librespot[20824]: time="2026-03-24T18:35:14Z" level=debug msg="app state loaded" Mar 24 18:35:14 volumio go-librespot[20824]: time="2026-03-24T18:35:14Z" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 18:35:14 volumio sudo[20832]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 18:35:14 volumio sudo[20832]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:14 volumio sudo[20822]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 18:35:14 volumio sudo[20822]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:14 volumio sudo[20825]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 18:35:14 volumio sudo[20825]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:14 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 24 18:35:14 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Mar 24 18:35:14 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 18:35:14 volumio systemd[1]: shairport-sync.service: Consumed 1.556s CPU time. Mar 24 18:35:14 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 18:35:14 volumio sudo[20825]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:14 volumio sudo[20832]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:14 volumio volumio[20603]: info: Shairport-Sync Started Mar 24 18:35:14 volumio sudo[20822]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:14 volumio volumio[20603]: Error adding Membership: Error: addMembership EINVAL Mar 24 18:35:14 volumio volumio[20603]: info: Shairport-Sync Started Mar 24 18:35:14 volumio volumio[20603]: info: Shairport-Sync Started Mar 24 18:35:14 volumio volumio[20603]: info: Volumio called home Mar 24 18:35:14 volumio volumio[20603]: info: Discovery: adding 072f109f-54a2-4344-b8c4-538b45da7e51 Mar 24 18:35:14 volumio volumio[20603]: info: Discovery: Found device Volumio Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::volumioGetState Mar 24 18:35:14 volumio volumio[20603]: info: CorePlayQueue::getTrack 0 Mar 24 18:35:14 volumio volumio[20603]: info: Discovery: this is already registered, 072f109f-54a2-4344-b8c4-538b45da7e51 Mar 24 18:35:14 volumio volumio[20603]: info: Discovery: Found device Volumio Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::volumioGetState Mar 24 18:35:14 volumio volumio[20603]: info: CorePlayQueue::getTrack 0 Mar 24 18:35:14 volumio volumio[20603]: info: CoreCommandRouter::volumioGetState Mar 24 18:35:14 volumio volumio[20603]: info: CorePlayQueue::getTrack 0 Mar 24 18:35:14 volumio go-librespot[20824]: time="2026-03-24T18:35:14Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 18:35:14 volumio go-librespot[20824]: time="2026-03-24T18:35:14Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 24 18:35:14 volumio go-librespot[20824]: time="2026-03-24T18:35:14Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 24 18:35:14 volumio go-librespot[20824]: time="2026-03-24T18:35:14Z" level=info msg="zeroconf server listening on port 32973" Mar 24 18:35:15 volumio mpd[20779]: 2026-03-24T18:35:15 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 24 18:35:15 volumio systemd[1]: Started mpd.service - Music Player Daemon. Mar 24 18:35:15 volumio sudo[20743]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:15 volumio sudo[20752]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:15 volumio volumio[20603]: info: Completed starting Core Plugins Mar 24 18:35:15 volumio volumio[20603]: info: ------------------------------------------- Mar 24 18:35:15 volumio volumio[20603]: info: ----- MyVolumio plugins startup ---- Mar 24 18:35:15 volumio volumio[20603]: info: ------------------------------------------- Mar 24 18:35:15 volumio volumio[20603]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 24 18:35:15 volumio volumio[20603]: error: MPD error: The expression evaluated to a falsy value: Mar 24 18:35:15 volumio volumio[20603]: assert.ok(self.idling) Mar 24 18:35:15 volumio volumio[20603]: error: The expression evaluated to a falsy value: Mar 24 18:35:15 volumio volumio[20603]: assert.ok(self.idling) Mar 24 18:35:15 volumio volumio[20603]: info: MPD running with PID20779 Mar 24 18:35:15 volumio volumio[20603]: ,establishing connection Mar 24 18:35:15 volumio volumio[20603]: error: updateQueue error: null Mar 24 18:35:15 volumio volumio[20603]: error: updateQueue error: null Mar 24 18:35:15 volumio volumio[20603]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 24 18:35:15 volumio go-librespot[20824]: time="2026-03-24T18:35:15Z" level=debug msg="obtained new client token: AADVEuZdvGRZwrwN7EFNS7PMWY2gozhTPcngCjpV05PedZeSQr00oPgpx4ETgu7Q+oiNINAOczbltU3RGxAvIb+hNDNjcRMMFEGwnttg/0SBp/x0DQ6drTggqG+H9Dq66sYTXVmOUQN7pWRBgMdXLJvWV2jjq2ZGx8zCy9jiPDluSVm8DEGTgWQabiG+rurN20d+dK3eRb75ctReRAj9ueCEZ17J0JvJqxfEFjRAmHXbkNZmZZ+B51w=" Mar 24 18:35:15 volumio go-librespot[20824]: time="2026-03-24T18:35:15Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Mar 24 18:35:15 volumio go-librespot[20824]: time="2026-03-24T18:35:15Z" level=debug msg="completed keyexchange" Mar 24 18:35:15 volumio go-librespot[20824]: time="2026-03-24T18:35:15Z" level=debug msg="completed challenge" Mar 24 18:35:15 volumio go-librespot[20824]: time="2026-03-24T18:35:15Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:15 volumio volumio-remote-updater[945]: [2026-03-24 18:35:15] [connect] Successful connection Mar 24 18:35:15 volumio volumio-remote-updater[945]: [2026-03-24 18:35:15] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774377315 101 Mar 24 18:35:15 volumio volumio[20603]: 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: 2 Mar 24 18:35:16 volumio sudo[20642]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:16 volumio go-librespot[20824]: time="2026-03-24T18:35:16Z" level=debug msg="connected to ap-gew1.spotify.com:443" Mar 24 18:35:16 volumio go-librespot[20824]: time="2026-03-24T18:35:16Z" level=debug msg="completed keyexchange" Mar 24 18:35:16 volumio go-librespot[20824]: time="2026-03-24T18:35:16Z" level=debug msg="completed challenge" Mar 24 18:35:16 volumio go-librespot[20824]: time="2026-03-24T18:35:16Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:16 volumio go-librespot[20824]: time="2026-03-24T18:35:16Z" level=debug msg="connected to ap-gew1.spotify.com:80" Mar 24 18:35:16 volumio go-librespot[20824]: time="2026-03-24T18:35:16Z" level=debug msg="completed keyexchange" Mar 24 18:35:16 volumio go-librespot[20824]: time="2026-03-24T18:35:16Z" level=debug msg="completed challenge" Mar 24 18:35:16 volumio go-librespot[20824]: time="2026-03-24T18:35:16Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:17 volumio go-librespot[20824]: time="2026-03-24T18:35:17Z" level=debug msg="connected to ap-gue1.spotify.com:4070" Mar 24 18:35:17 volumio go-librespot[20824]: time="2026-03-24T18:35:17Z" level=debug msg="completed keyexchange" Mar 24 18:35:17 volumio go-librespot[20824]: time="2026-03-24T18:35:17Z" level=debug msg="completed challenge" Mar 24 18:35:17 volumio go-librespot[20824]: time="2026-03-24T18:35:17Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:17 volumio volumio[20603]: info: go-librespot daemon successfully initialized Mar 24 18:35:18 volumio go-librespot[20824]: time="2026-03-24T18:35:18Z" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 24 18:35:18 volumio go-librespot[20824]: time="2026-03-24T18:35:18Z" level=debug msg="completed keyexchange" Mar 24 18:35:18 volumio go-librespot[20824]: time="2026-03-24T18:35:18Z" level=debug msg="completed challenge" Mar 24 18:35:18 volumio go-librespot[20824]: time="2026-03-24T18:35:18Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:18 volumio go-librespot[20824]: time="2026-03-24T18:35:18Z" level=debug msg="connected to ap-gae2.spotify.com:80" Mar 24 18:35:19 volumio go-librespot[20824]: time="2026-03-24T18:35:19Z" level=debug msg="completed keyexchange" Mar 24 18:35:19 volumio go-librespot[20824]: time="2026-03-24T18:35:19Z" level=debug msg="completed challenge" Mar 24 18:35:19 volumio go-librespot[20824]: time="2026-03-24T18:35:19Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:19 volumio go-librespot[20824]: time="2026-03-24T18:35:19Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 18:35:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 18:35:20 volumio volumio[20603]: info: Initializing connection to go-librespot Websocket Mar 24 18:35:20 volumio volumio[20603]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 18:35:22 volumio sudo[20875]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 24 18:35:22 volumio sudo[20875]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:22 volumio sudo[20877]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 24 18:35:22 volumio sudo[20875]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:22 volumio sudo[20877]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:22 volumio sudo[20877]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:22 volumio sudo[20881]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 24 18:35:22 volumio sudo[20881]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:22 volumio sudo[20881]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:22 volumio volumio[20603]: info: Upmpdcli Daemon Started Mar 24 18:35:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 24 18:35:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 18:35:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 18:35:22 volumio go-librespot[20883]: go-librespot daemon starting... Mar 24 18:35:22 volumio go-librespot[20884]: time="2026-03-24T18:35:22Z" level=info msg="running go-librespot 0.6.2" Mar 24 18:35:22 volumio go-librespot[20884]: time="2026-03-24T18:35:22Z" level=debug msg="app state loaded" Mar 24 18:35:22 volumio go-librespot[20884]: time="2026-03-24T18:35:22Z" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 18:35:22 volumio go-librespot[20884]: time="2026-03-24T18:35:22Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 18:35:22 volumio go-librespot[20884]: time="2026-03-24T18:35:22Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 24 18:35:22 volumio go-librespot[20884]: time="2026-03-24T18:35:22Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 24 18:35:22 volumio go-librespot[20884]: time="2026-03-24T18:35:22Z" level=info msg="zeroconf server listening on port 42381" Mar 24 18:35:22 volumio go-librespot[20884]: time="2026-03-24T18:35:22Z" level=debug msg="obtained new client token: AAC+0i6HSEbNyeB4G2Hne9csX2omosUv0530598StJ7nQLaurjggZtLNc8pVRPg/XwzYD8rILKE6TWlW1OTLLcrvCBWeNo8rzaFWA9WwYgC3Omp9ePcBLrz2FnN6mEfVR+HjkuDWYfuS4wYiLLFxldHPucV8ealbxW0vDP2YBBtiqWMph85pcYea2XlpvK4TeBQDCcaiYJawdp6qnMR5BWC72ja5C5kUKE34kM/eqZ8gmLLQwhoRyP4qDg==" Mar 24 18:35:22 volumio go-librespot[20884]: time="2026-03-24T18:35:22Z" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused" Mar 24 18:35:22 volumio go-librespot[20884]: time="2026-03-24T18:35:22Z" level=debug msg="connected to ap-gew1.spotify.com:443" Mar 24 18:35:22 volumio go-librespot[20884]: time="2026-03-24T18:35:22Z" level=debug msg="completed keyexchange" Mar 24 18:35:22 volumio go-librespot[20884]: time="2026-03-24T18:35:22Z" level=debug msg="completed challenge" Mar 24 18:35:22 volumio go-librespot[20884]: time="2026-03-24T18:35:22Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:23 volumio volumio[20603]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 24 18:35:23 volumio volumio[20603]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 24 18:35:23 volumio volumio[20603]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 24 18:35:23 volumio volumio[20603]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 24 18:35:23 volumio volumio[20603]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 24 18:35:23 volumio volumio[20603]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 24 18:35:23 volumio volumio[20603]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 24 18:35:23 volumio volumio[20603]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 24 18:35:23 volumio volumio[20603]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 24 18:35:23 volumio volumio[20603]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 24 18:35:23 volumio volumio[20603]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 24 18:35:23 volumio volumio[20603]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 24 18:35:23 volumio volumio[20603]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 24 18:35:23 volumio volumio[20603]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 24 18:35:23 volumio volumio[20603]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 24 18:35:23 volumio volumio[20603]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 24 18:35:23 volumio volumio[20603]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 24 18:35:23 volumio volumio[20603]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 24 18:35:23 volumio volumio[20603]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 24 18:35:23 volumio volumio[20603]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 24 18:35:23 volumio volumio[20603]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 24 18:35:23 volumio volumio[20603]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 24 18:35:23 volumio volumio[20603]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 24 18:35:23 volumio volumio[20603]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 24 18:35:23 volumio volumio[20603]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 24 18:35:23 volumio volumio[20603]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 24 18:35:23 volumio volumio[20603]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 24 18:35:23 volumio volumio[20603]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 24 18:35:23 volumio volumio[20603]: info: Adding plugin bluetooth to MyMusic Plugins Mar 24 18:35:23 volumio volumio[20603]: info: Adding plugin multiroom to MyMusic Plugins Mar 24 18:35:23 volumio volumio[20603]: info: Adding plugin metavolumio to MyMusic Plugins Mar 24 18:35:23 volumio volumio[20603]: info: Adding plugin cd_controller to MyMusic Plugins Mar 24 18:35:23 volumio volumio[20603]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 24 18:35:23 volumio volumio[20603]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 24 18:35:23 volumio volumio[20603]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 24 18:35:23 volumio volumio[20603]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 24 18:35:23 volumio go-librespot[20884]: time="2026-03-24T18:35:23Z" level=debug msg="connected to ap-gew1.spotify.com:80" Mar 24 18:35:23 volumio go-librespot[20884]: time="2026-03-24T18:35:23Z" level=debug msg="completed keyexchange" Mar 24 18:35:23 volumio go-librespot[20884]: time="2026-03-24T18:35:23Z" level=debug msg="completed challenge" Mar 24 18:35:23 volumio go-librespot[20884]: time="2026-03-24T18:35:23Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:23 volumio volumio[20603]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 24 18:35:23 volumio volumio[20603]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 24 18:35:23 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:23 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:23 volumio volumio[20603]: info: Starting MyVolumio Remote Streaming Endpoints Mar 24 18:35:23 volumio volumio[20603]: info: MyVolumio login type: Token Mar 24 18:35:23 volumio volumio[20603]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 24 18:35:23 volumio volumio[20603]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 24 18:35:23 volumio volumio[20603]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 24 18:35:23 volumio volumio[20603]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 24 18:35:23 volumio volumio[20603]: info: Streaming services startup Mar 24 18:35:23 volumio volumio[20603]: info: Starting Streaming Daemon Mar 24 18:35:23 volumio sudo[20894]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 24 18:35:23 volumio sudo[20894]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:23 volumio volumio[20603]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 24 18:35:23 volumio sudo[20894]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:23 volumio volumio[20603]: info: Initializing connection to go-librespot Websocket Mar 24 18:35:23 volumio volumio[20603]: error: Cannot start Volumio Streaming Daemon Mar 24 18:35:24 volumio volumio[20603]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 24 18:35:24 volumio volumio[20603]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 24 18:35:24 volumio go-librespot[20884]: time="2026-03-24T18:35:24Z" level=debug msg="new websocket client" Mar 24 18:35:24 volumio volumio[20603]: info: Connection to go-librespot Websocket established Mar 24 18:35:24 volumio go-librespot[20884]: time="2026-03-24T18:35:24Z" level=debug msg="connected to ap-guc3.spotify.com:4070" Mar 24 18:35:24 volumio go-librespot[20884]: time="2026-03-24T18:35:24Z" level=debug msg="completed keyexchange" Mar 24 18:35:24 volumio go-librespot[20884]: time="2026-03-24T18:35:24Z" level=debug msg="completed challenge" Mar 24 18:35:24 volumio volumio[20603]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 24 18:35:24 volumio go-librespot[20884]: time="2026-03-24T18:35:24Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:24 volumio volumio[20603]: info: MyVolumio token set successfully Mar 24 18:35:24 volumio volumio[20603]: info: MYVOLUMIO: Adding device Mar 24 18:35:24 volumio volumio[20603]: info: MYVOLUMIO: Evaluating Server Mar 24 18:35:24 volumio volumio[20603]: info: MyVolumio status changed Mar 24 18:35:24 volumio volumio[20603]: info: Streaming services startup Mar 24 18:35:24 volumio volumio[20603]: info: Starting Streaming Daemon Mar 24 18:35:24 volumio volumio[20603]: info: Removing browser output: myVolumio user plan is not superstar Mar 24 18:35:24 volumio volumio[20603]: info: Removing audio output: Mar 24 18:35:24 volumio volumio[20603]: info: Stoppping Tunnel 1 Mar 24 18:35:24 volumio sudo[20921]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 24 18:35:24 volumio sudo[20921]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:24 volumio sudo[20923]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Mar 24 18:35:24 volumio sudo[20923]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:24 volumio sudo[20921]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:24 volumio volumio[20603]: error: Cannot start Volumio Streaming Daemon Mar 24 18:35:24 volumio volumio[20603]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 24 18:35:24 volumio volumio[20603]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 24 18:35:24 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 18:35:24 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 18:35:24 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 18:35:24 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 18:35:24 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 18:35:24 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 18:35:24 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 18:35:24 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 18:35:24 volumio sudo[20923]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:24 volumio volumio[20603]: info: Remote SSH Stopped Mar 24 18:35:25 volumio go-librespot[20884]: time="2026-03-24T18:35:25Z" 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" Mar 24 18:35:25 volumio volumio[20603]: info: Setting Geolocation for MyVolumio to eu3 Mar 24 18:35:25 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:25 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:25 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:25 volumio go-librespot[20884]: time="2026-03-24T18:35:25Z" level=debug msg="connected to ap-gae2.spotify.com:80" Mar 24 18:35:25 volumio go-librespot[20884]: time="2026-03-24T18:35:25Z" level=debug msg="completed keyexchange" Mar 24 18:35:25 volumio go-librespot[20884]: time="2026-03-24T18:35:25Z" level=debug msg="completed challenge" Mar 24 18:35:25 volumio volumio[20603]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Mar 24 18:35:25 volumio go-librespot[20884]: time="2026-03-24T18:35:25Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:26 volumio volumio[20603]: info: Updating MyVolumio device info Mar 24 18:35:26 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:26 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:26 volumio volumio[20603]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:26 volumio go-librespot[20884]: time="2026-03-24T18:35:26Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Mar 24 18:35:26 volumio go-librespot[20884]: time="2026-03-24T18:35:26Z" level=debug msg="completed keyexchange" Mar 24 18:35:26 volumio go-librespot[20884]: time="2026-03-24T18:35:26Z" level=debug msg="completed challenge" Mar 24 18:35:26 volumio go-librespot[20884]: time="2026-03-24T18:35:26Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:26 volumio volumio[20603]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Mar 24 18:35:26 volumio go-librespot[20884]: time="2026-03-24T18:35:26Z" level=debug msg="connected to ap-gew1.spotify.com:443" Mar 24 18:35:26 volumio go-librespot[20884]: time="2026-03-24T18:35:26Z" level=debug msg="completed keyexchange" Mar 24 18:35:26 volumio go-librespot[20884]: time="2026-03-24T18:35:26Z" level=debug msg="completed challenge" Mar 24 18:35:26 volumio go-librespot[20884]: time="2026-03-24T18:35:26Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:26 volumio go-librespot[20884]: time="2026-03-24T18:35:26Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 18:35:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 18:35:26 volumio volumio[20603]: info: Connection to go-librespot Websocket closed Mar 24 18:35:27 volumio volumio[20603]: info: Getting Spotify volume Mar 24 18:35:27 volumio volumio[20603]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 18:35:27 volumio volumio[20603]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 18:35:27 volumio volumio[20603]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 24 18:35:27 volumio volumio[20603]: errno: -111, Mar 24 18:35:27 volumio volumio[20603]: code: 'ECONNREFUSED', Mar 24 18:35:27 volumio volumio[20603]: syscall: 'connect', Mar 24 18:35:27 volumio volumio[20603]: address: '127.0.0.1', Mar 24 18:35:27 volumio volumio[20603]: port: 9879, Mar 24 18:35:27 volumio volumio[20603]: response: undefined Mar 24 18:35:27 volumio volumio[20603]: } Mar 24 18:35:27 volumio volumio[20603]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 18:35:27 volumio sudo[20940]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-24 18:34' Mar 24 18:35:27 volumio sudo[20940]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:27 volumio sudo[20940]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:27 volumio volumio-remote-updater[945]: [2026-03-24 18:35:27] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 24 18:35:27 volumio volumio-remote-updater[945]: [2026-03-24 18:35:27] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 24 18:35:27 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 24 18:35:27 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 24 18:35:27 volumio systemd[1]: volumio.service: Consumed 8.982s CPU time. Mar 24 18:35:27 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 24 18:35:27 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Mar 24 18:35:27 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 78822. Mar 24 18:35:27 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 24 18:35:27 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 24 18:35:27 volumio systemd[1]: volumio.service: Consumed 8.982s CPU time. Mar 24 18:35:27 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Mar 24 18:35:27 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Mar 24 18:35:28 volumio volumio[20953]: info: ------------------------------------------- Mar 24 18:35:28 volumio volumio[20953]: info: ----- Volumio3 ---- Mar 24 18:35:28 volumio volumio[20953]: info: ------------------------------------------- Mar 24 18:35:28 volumio volumio[20953]: info: ----- System startup ---- Mar 24 18:35:28 volumio volumio[20953]: info: ------------------------------------------- Mar 24 18:35:28 volumio volumio[20953]: info: MYVOLUMIO Environment detected Mar 24 18:35:28 volumio volumio[20953]: info: Plugin folders cleanup Mar 24 18:35:28 volumio volumio[20953]: info: Scanning into folder /volumio/app/plugins/ Mar 24 18:35:28 volumio volumio[20953]: info: Scanning category audio_interface Mar 24 18:35:28 volumio volumio[20953]: info: Scanning category miscellanea Mar 24 18:35:28 volumio volumio[20953]: info: Scanning category music_service Mar 24 18:35:28 volumio volumio[20953]: info: Scanning category plugins.json Mar 24 18:35:28 volumio volumio[20953]: info: Scanning category system_controller Mar 24 18:35:28 volumio volumio[20953]: info: Scanning category user_interface Mar 24 18:35:28 volumio volumio[20953]: info: Scanning into folder /data/plugins/ Mar 24 18:35:28 volumio volumio[20953]: info: Scanning category music_service Mar 24 18:35:28 volumio volumio[20953]: info: Plugin folders cleanup completed Mar 24 18:35:28 volumio volumio[20953]: info: ------------------------------------------- Mar 24 18:35:28 volumio volumio[20953]: info: ----- Core plugins startup ---- Mar 24 18:35:28 volumio volumio[20953]: info: ------------------------------------------- Mar 24 18:35:28 volumio volumio[20953]: info: Loading plugins from folder /volumio/app/plugins/ Mar 24 18:35:28 volumio volumio[20953]: info: Adding plugin upnp to MyMusic Plugins Mar 24 18:35:28 volumio volumio[20953]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 24 18:35:28 volumio volumio[20953]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 24 18:35:28 volumio volumio[20953]: info: Loading plugins from folder /data/plugins/ Mar 24 18:35:28 volumio volumio[20953]: info: Adding plugin rtlsdr_radio to MyMusic Plugins Mar 24 18:35:28 volumio volumio[20953]: info: Loading plugin "system"... Mar 24 18:35:28 volumio volumio[20953]: info: Loading plugin "appearance"... Mar 24 18:35:28 volumio volumio[20953]: info: Loading plugin "network"... Mar 24 18:35:28 volumio volumio[20953]: info: Refreshing Cached IP Addresses Mar 24 18:35:28 volumio sudo[20981]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 24 18:35:28 volumio sudo[20981]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:28 volumio sudo[20983]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 24 18:35:28 volumio sudo[20983]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:28 volumio sudo[20981]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:28 volumio sudo[20983]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:28 volumio volumio[20953]: info: Loading plugin "services"... Mar 24 18:35:28 volumio volumio[20953]: info: Loading plugin "alsa_controller"... Mar 24 18:35:28 volumio sudo[20992]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 24 18:35:28 volumio sudo[20992]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:28 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 18:35:28 volumio volumio[20953]: info: Loading plugin "wizard"... Mar 24 18:35:28 volumio volumio[20953]: info: Loading plugin "networkfs"... Mar 24 18:35:28 volumio volumio[20953]: info: Starting Udev Watcher for removable devices Mar 24 18:35:28 volumio volumio[20953]: info: Mounting Device 0ACB-A1DE Mar 24 18:35:28 volumio sudo[21020]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/0ACB-A1DE -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Mar 24 18:35:28 volumio sudo[21020]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:28 volumio sudo[21020]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:28 volumio volumio[20953]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Mar 24 18:35:28 volumio volumio[20953]: dmesg(1) may have more information after failed mount system call. Mar 24 18:35:28 volumio volumio[20953]: error: Failed to mount 0ACB-A1DE: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/0ACB-A1DE" -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Mar 24 18:35:28 volumio volumio[20953]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Mar 24 18:35:28 volumio volumio[20953]: dmesg(1) may have more information after failed mount system call. Mar 24 18:35:28 volumio volumio[20953]: info: Ignoring mount for partition: boot Mar 24 18:35:28 volumio volumio[20953]: info: Ignoring mount for partition: volumio Mar 24 18:35:28 volumio volumio[20953]: info: Ignoring mount for partition: volumio_data Mar 24 18:35:28 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 24 18:35:28 volumio volumio[20953]: info: Loading plugin "volumio_command_line_client"... Mar 24 18:35:28 volumio volumio[20953]: info: Loading plugin "upnp"... Mar 24 18:35:28 volumio volumio[20953]: info: [1774377328868] Starting Upmpd Daemon Mar 24 18:35:28 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 24 18:35:28 volumio volumio[20953]: info: Loading plugin "my_music"... Mar 24 18:35:28 volumio volumio[20953]: info: Loading plugin "mpd"... Mar 24 18:35:28 volumio volumio[20953]: info: Loading plugin "upnp_browser"... Mar 24 18:35:29 volumio volumio[20953]: info: Starting UPNP Browser Mar 24 18:35:29 volumio volumio[20953]: info: Loading plugin "alarm-clock"... Mar 24 18:35:29 volumio volumio[20953]: info: Loading plugin "airplay_emulation"... Mar 24 18:35:29 volumio volumio[20953]: info: Starting Shairport Sync Mar 24 18:35:29 volumio volumio[20953]: info: Loading plugin "last_100"... Mar 24 18:35:29 volumio volumio[20953]: info: Loading plugin "webradio"... Mar 24 18:35:29 volumio volumio[20953]: info: Loading plugin "i2s_dacs"... Mar 24 18:35:29 volumio volumio[20953]: info: Loading plugin "volumiodiscovery"... Mar 24 18:35:29 volumio volumio[20953]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 24 18:35:29 volumio volumio[20953]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 18:35:29 volumio volumio[20953]: *** WARNING *** For more information see Mar 24 18:35:29 volumio volumio[20953]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 24 18:35:29 volumio volumio[20953]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 18:35:29 volumio volumio[20953]: *** WARNING *** For more information see Mar 24 18:35:29 volumio node[20953]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 24 18:35:29 volumio node[20953]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 18:35:29 volumio node[20953]: *** WARNING *** For more information see Mar 24 18:35:29 volumio node[20953]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 24 18:35:29 volumio node[20953]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 18:35:29 volumio node[20953]: *** WARNING *** For more information see Mar 24 18:35:29 volumio volumio[20953]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 24 18:35:29 volumio volumio[20953]: info: Discovery: Started advertising with name: Volumio Mar 24 18:35:29 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 24 18:35:29 volumio volumio[20953]: info: Loading plugin "spop"... Mar 24 18:35:29 volumio volumio[20953]: info: Loading plugin "ytmusic"... Mar 24 18:35:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 24 18:35:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 18:35:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 18:35:29 volumio go-librespot[21024]: go-librespot daemon starting... Mar 24 18:35:29 volumio go-librespot[21025]: time="2026-03-24T18:35:29Z" level=info msg="running go-librespot 0.6.2" Mar 24 18:35:29 volumio go-librespot[21025]: time="2026-03-24T18:35:29Z" level=debug msg="app state loaded" Mar 24 18:35:29 volumio go-librespot[21025]: time="2026-03-24T18:35:29Z" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 18:35:30 volumio volumio[20953]: info: Loading plugin "outputs"... Mar 24 18:35:30 volumio volumio[20953]: info: Loading plugin "albumart"... Mar 24 18:35:30 volumio volumio[20953]: info: Plugin example_plugin is not enabled Mar 24 18:35:30 volumio volumio[20953]: info: Loading plugin "inputs"... Mar 24 18:35:30 volumio volumio[20953]: info: Loading plugin "updater_comm"... Mar 24 18:35:30 volumio volumio[20953]: info: Plugin mpdemulation is not enabled Mar 24 18:35:30 volumio volumio[20953]: info: Loading plugin "rest_api"... Mar 24 18:35:30 volumio volumio[20953]: info: Loading plugin "websocket"... Mar 24 18:35:30 volumio volumio[20953]: info: Starting Socket.io Server version 1.7.4 Mar 24 18:35:30 volumio volumio[20953]: info: Loading plugin "podcast"... Mar 24 18:35:30 volumio volumio[20953]: info: ControllerPodcast::constructor Mar 24 18:35:30 volumio volumio[20953]: info: Loading plugin "rtlsdr_radio"... Mar 24 18:35:30 volumio volumio[21031]: Forking 3 albumart workers Mar 24 18:35:30 volumio go-librespot[21025]: time="2026-03-24T18:35:30Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 18:35:30 volumio go-librespot[21025]: time="2026-03-24T18:35:30Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 24 18:35:30 volumio go-librespot[21025]: time="2026-03-24T18:35:30Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 24 18:35:30 volumio go-librespot[21025]: time="2026-03-24T18:35:30Z" level=info msg="zeroconf server listening on port 41327" Mar 24 18:35:30 volumio volumio[20953]: info: Loading i18n strings for locale en Mar 24 18:35:30 volumio volumio[20953]: Updating browse sources language Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::initPlayerControls Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 18:35:30 volumio volumio[20953]: Express server listening on port 3000 Mar 24 18:35:30 volumio volumio[20953]: [Metrics] WebUI: 2s 312.64ms Mar 24 18:35:30 volumio volumio[20953]: info: CoreStateMachine::resetVolumioState Mar 24 18:35:30 volumio volumio[20953]: info: CoreStateMachine::getcurrentVolume Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::volumioRetrievevolume Mar 24 18:35:30 volumio volumio[20953]: info: Volumio Network Manager: Network status updated: 2 Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:30 volumio volumio[20953]: info: Reloading queue from file Mar 24 18:35:30 volumio volumio[20953]: info: CoreStateMachine::setRepeat null single undefined Mar 24 18:35:30 volumio volumio[20953]: info: CoreStateMachine::pushState Mar 24 18:35:30 volumio volumio[20953]: info: CorePlayQueue::getTrack 0 Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::volumioPushState Mar 24 18:35:30 volumio volumio[20953]: info: CoreStateMachine::setRandom true Mar 24 18:35:30 volumio volumio[20953]: info: CoreStateMachine::pushState Mar 24 18:35:30 volumio volumio[20953]: info: CorePlayQueue::getTrack 0 Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::volumioPushState Mar 24 18:35:30 volumio volumio[20953]: info: VolumeController:: Volume=36 Mute =true Mar 24 18:35:30 volumio volumio[20953]: info: CoreStateMachine::pushState Mar 24 18:35:30 volumio volumio[20953]: info: CorePlayQueue::getTrack 0 Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::volumioPushState Mar 24 18:35:30 volumio volumio[20953]: info: CoreStateMachine::updateTrackBlock Mar 24 18:35:30 volumio volumio[20953]: info: CorePlayQueue::getTrackBlock Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::volumioRetrievevolume Mar 24 18:35:30 volumio volumio[20953]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Mar 24 18:35:30 volumio volumio[20953]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04170 Mar 24 18:35:30 volumio volumio[20953]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Mar 24 18:35:30 volumio volumio[20953]: info: Setting Device type: Raspberry PI Mar 24 18:35:30 volumio volumio[20953]: info: Completed loading Core Plugins Mar 24 18:35:30 volumio volumio[20953]: info: Preparing to generate the ALSA configuration file Mar 24 18:35:30 volumio volumio[20953]: info: Asound.conf file unchanged, so no further update is needed Mar 24 18:35:30 volumio volumio[20953]: info: Output device has changed, restarting MPD Mar 24 18:35:30 volumio volumio[20953]: info: Output device has changed, restarting Shairport Sync Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:30 volumio sudo[21090]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 24 18:35:30 volumio sudo[21090]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:30 volumio sudo[21090]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:30 volumio sudo[21092]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 24 18:35:30 volumio volumio[20953]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 24 18:35:30 volumio sudo[21092]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:30 volumio volumio[20953]: info: ___________ START PLUGINS ___________ Mar 24 18:35:30 volumio volumio[20953]: info: ControllerMpd::onStart: Initializing MPD Mar 24 18:35:30 volumio volumio[20953]: info: Creating MPD Configuration file Mar 24 18:35:30 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 18:35:30 volumio volumio[20953]: info: [1774377330604] CoreMusicLibrary::Adding element Media Servers Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 18:35:30 volumio volumio[20953]: info: UPNP Browser: Client initialized successfully Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:30 volumio sudo[21100]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 24 18:35:30 volumio sudo[21100]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:30 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 24 18:35:30 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 24 18:35:30 volumio sudo[21102]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 24 18:35:30 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 24 18:35:30 volumio sudo[21100]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:30 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 24 18:35:30 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 24 18:35:30 volumio sudo[21102]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:30 volumio volumio[21043]: Starting albumart workers Mar 24 18:35:30 volumio volumio[20953]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:30 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 24 18:35:30 volumio volumio[21042]: Starting albumart workers Mar 24 18:35:30 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 24 18:35:30 volumio volumio[20953]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 18:35:30 volumio volumio[20953]: info: [1774377330667] CoreMusicLibrary::Adding element Last_100 Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 18:35:30 volumio volumio[20953]: info: [1774377330674] CoreMusicLibrary::Adding element Webradio Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 18:35:30 volumio volumio[20953]: info: Initializing BBC Radios Mar 24 18:35:30 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 24 18:35:30 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 24 18:35:30 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 24 18:35:30 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 24 18:35:30 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 24 18:35:30 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 24 18:35:30 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 24 18:35:30 volumio volumio[21044]: Starting albumart workers Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:30 volumio volumio[20953]: info: Creating Spotify config file Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:30 volumio sudo[21119]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 24 18:35:30 volumio sudo[21119]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 24 18:35:30 volumio sudo[21119]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 18:35:30 volumio volumio[20953]: info: [1774377330917] CoreMusicLibrary::Adding element YouTube Music Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 18:35:30 volumio volumio[20953]: Cannot find translation for source YouTube Music Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 18:35:30 volumio volumio[20953]: info: [1774377330932] CoreMusicLibrary::Adding element Podcast Mar 24 18:35:30 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 18:35:30 volumio volumio[20953]: Cannot find translation for source YouTube Music Mar 24 18:35:30 volumio volumio[20953]: Cannot find translation for source Podcast Mar 24 18:35:30 volumio volumio[20953]: info: [RTL-SDR Radio] Starting plugin Mar 24 18:35:30 volumio volumio[20953]: info: [RTL-SDR Radio] Loaded i18n strings for language: en Mar 24 18:35:30 volumio volumio[20953]: info: Volumio Calling Home Mar 24 18:35:30 volumio go-librespot[21025]: time="2026-03-24T18:35:30Z" level=debug msg="obtained new client token: AADuKWgEk9rV3SWIRePINEGZ1M/QKateUJ+/e3RfEKJHpnlBtQR8QqRErVLf/CcNFAi+SbzKV6dhzHFvL/JwfQR12FJLIE/yJMgw77AZjRcz23XKmJp/ETIvffMI87b8tL4832h7i17rFor8vzN4ATFIRnXXo2mSm/XzMwqXDeKKMQdz9qYOpdadaQ4R4RBUUNldwNL/EFu+3fNu8emne+l5A2eL7KgXilom9fENa/FjfkIyf2YB6ZQQMQ==" Mar 24 18:35:30 volumio volumio[20953]: info: [RTL-SDR Radio] snd-aloop already loaded Mar 24 18:35:30 volumio volumio[20953]: info: [RTL-SDR Radio] No stations database found, creating v2 Mar 24 18:35:30 volumio volumio[20953]: info: [RTL-SDR Radio] Database loaded at: 2026-03-24T18:35:30.996Z Mar 24 18:35:30 volumio volumio[20953]: info: [RTL-SDR Radio] Loading blocklist from: /data/plugins/music_service/rtlsdr_radio/blocklist.json Mar 24 18:35:30 volumio volumio[20953]: info: [RTL-SDR Radio] Got 21 phrases from file Mar 24 18:35:30 volumio volumio[20953]: info: [RTL-SDR Radio] Updated metadata blocklist Mar 24 18:35:30 volumio volumio[20953]: info: [RTL-SDR Radio] Metadata module now has 21 phrases Mar 24 18:35:31 volumio volumio[20953]: info: [RTL-SDR Radio] Management server started on port 3456 Mar 24 18:35:31 volumio volumio[20953]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 18:35:31 volumio volumio[20953]: info: [1774377331039] CoreMusicLibrary::Adding element FM/DAB Radio Mar 24 18:35:31 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 18:35:31 volumio volumio[20953]: Cannot find translation for source YouTube Music Mar 24 18:35:31 volumio volumio[20953]: Cannot find translation for source Podcast Mar 24 18:35:31 volumio volumio[20953]: Cannot find translation for source FM/DAB Radio Mar 24 18:35:31 volumio volumio[20953]: info: [RTL-SDR Radio] Plugin started successfully Mar 24 18:35:31 volumio volumio[20953]: info: Discovery: adding 072f109f-54a2-4344-b8c4-538b45da7e51 Mar 24 18:35:31 volumio volumio[20953]: info: Discovery: Found device Volumio Mar 24 18:35:31 volumio volumio[20953]: info: CoreCommandRouter::volumioGetState Mar 24 18:35:31 volumio volumio[20953]: info: CorePlayQueue::getTrack 0 Mar 24 18:35:31 volumio volumio[20953]: info: Discovery: this is already registered, 072f109f-54a2-4344-b8c4-538b45da7e51 Mar 24 18:35:31 volumio volumio[20953]: info: Discovery: Found device Volumio Mar 24 18:35:31 volumio volumio[20953]: info: CoreCommandRouter::volumioGetState Mar 24 18:35:31 volumio volumio[20953]: info: CorePlayQueue::getTrack 0 Mar 24 18:35:31 volumio volumio[20953]: info: MPD Permissions set Mar 24 18:35:31 volumio volumio[20953]: info: MPD Permissions set Mar 24 18:35:31 volumio volumio[20953]: info: VolumeController:: Volume=36 Mute =true Mar 24 18:35:31 volumio volumio[20953]: info: CoreStateMachine::pushState Mar 24 18:35:31 volumio volumio[20953]: info: CorePlayQueue::getTrack 0 Mar 24 18:35:31 volumio volumio[20953]: info: CoreCommandRouter::volumioPushState Mar 24 18:35:31 volumio volumio[20953]: info: Spotify config file written Mar 24 18:35:31 volumio sudo[21159]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 24 18:35:31 volumio sudo[21159]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:31 volumio volumio[20953]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Mar 24 18:35:31 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:31 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:31 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:31 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:31 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:31 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:31 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:31 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:31 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 24 18:35:31 volumio systemd[1]: go-librespot-daemon.service: Killing process 21030 (go-librespot) with signal SIGKILL. Mar 24 18:35:31 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:31 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:31 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:31 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 24 18:35:31 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:31 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:31 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:31 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:31 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:31 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:31 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 18:35:31 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:31 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:31 volumio volumio[20953]: info: No need to fix Spotify hosts Mar 24 18:35:31 volumio volumio[20953]: info: Starting Shairport Sync Mar 24 18:35:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 18:35:31 volumio go-librespot[21168]: go-librespot daemon starting... Mar 24 18:35:31 volumio sudo[21159]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:31 volumio volumio[20953]: info: Starting Shairport Sync Mar 24 18:35:31 volumio go-librespot[21173]: time="2026-03-24T18:35:31Z" level=info msg="running go-librespot 0.6.2" Mar 24 18:35:31 volumio go-librespot[21173]: time="2026-03-24T18:35:31Z" level=debug msg="app state loaded" Mar 24 18:35:31 volumio go-librespot[21173]: time="2026-03-24T18:35:31Z" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 18:35:31 volumio volumio[20953]: info: Starting Shairport Sync Mar 24 18:35:31 volumio sudo[21178]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 18:35:31 volumio sudo[21178]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:31 volumio sudo[21181]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 18:35:31 volumio sudo[21181]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:31 volumio sudo[21184]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 18:35:31 volumio sudo[21184]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:31 volumio volumio[20953]: info: CoreCommandRouter::volumioGetState Mar 24 18:35:31 volumio volumio[20953]: info: CorePlayQueue::getTrack 0 Mar 24 18:35:31 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 24 18:35:31 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Mar 24 18:35:31 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 18:35:31 volumio systemd[1]: shairport-sync.service: Consumed 1.548s CPU time. Mar 24 18:35:31 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 18:35:31 volumio sudo[21184]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:31 volumio sudo[21181]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:31 volumio sudo[21178]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:31 volumio volumio[20953]: info: Shairport-Sync Started Mar 24 18:35:31 volumio volumio[20953]: Error adding Membership: Error: addMembership EINVAL Mar 24 18:35:31 volumio volumio[20953]: info: Shairport-Sync Started Mar 24 18:35:31 volumio volumio[20953]: info: Shairport-Sync Started Mar 24 18:35:31 volumio volumio[20953]: info: Volumio called home Mar 24 18:35:31 volumio mpd[21131]: 2026-03-24T18:35:31 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 24 18:35:31 volumio systemd[1]: Started mpd.service - Music Player Daemon. Mar 24 18:35:31 volumio sudo[21102]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:31 volumio sudo[21092]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:31 volumio volumio[20953]: info: Completed starting Core Plugins Mar 24 18:35:31 volumio volumio[20953]: info: ------------------------------------------- Mar 24 18:35:31 volumio volumio[20953]: info: ----- MyVolumio plugins startup ---- Mar 24 18:35:31 volumio volumio[20953]: info: ------------------------------------------- Mar 24 18:35:31 volumio volumio[20953]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 24 18:35:31 volumio volumio[20953]: error: MPD error: The expression evaluated to a falsy value: Mar 24 18:35:31 volumio volumio[20953]: assert.ok(self.idling) Mar 24 18:35:31 volumio volumio[20953]: error: The expression evaluated to a falsy value: Mar 24 18:35:31 volumio volumio[20953]: assert.ok(self.idling) Mar 24 18:35:31 volumio volumio[20953]: info: MPD running with PID21131 Mar 24 18:35:31 volumio volumio[20953]: ,establishing connection Mar 24 18:35:31 volumio volumio[20953]: error: updateQueue error: null Mar 24 18:35:31 volumio volumio[20953]: error: updateQueue error: null Mar 24 18:35:31 volumio volumio[20953]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 24 18:35:31 volumio go-librespot[21173]: time="2026-03-24T18:35:31Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 18:35:31 volumio go-librespot[21173]: time="2026-03-24T18:35:31Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 24 18:35:31 volumio go-librespot[21173]: time="2026-03-24T18:35:31Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 24 18:35:31 volumio go-librespot[21173]: time="2026-03-24T18:35:31Z" level=info msg="zeroconf server listening on port 41709" Mar 24 18:35:32 volumio go-librespot[21173]: time="2026-03-24T18:35:32Z" level=debug msg="obtained new client token: AAC/ucSuZpLrwFt4xdgC+n9Ufy7jEHHYYld1L1rdAfIA8iCpZODxTFff0r/mmqgHaSrA/ea9oXeJ9nUdM1JGRmYu1YsWNtp0khF6p2mqfaJIGLHoJSC6IzDtTWsCUI/m7tUCIG22p3XLHj37rr7cDjJyNRJZe8lTV4MjKeE1bRTUAqg0O9dmZLaP92NNnwacGW12Z21v/6nIUuhZM3J7xkv95OcutYEYgu3guoqxFGx8Y/pcy0Qznus=" Mar 24 18:35:32 volumio go-librespot[21173]: time="2026-03-24T18:35:32Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Mar 24 18:35:32 volumio go-librespot[21173]: time="2026-03-24T18:35:32Z" level=debug msg="completed keyexchange" Mar 24 18:35:32 volumio go-librespot[21173]: time="2026-03-24T18:35:32Z" level=debug msg="completed challenge" Mar 24 18:35:32 volumio go-librespot[21173]: time="2026-03-24T18:35:32Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:32 volumio volumio-remote-updater[945]: [2026-03-24 18:35:32] [connect] Successful connection Mar 24 18:35:32 volumio volumio-remote-updater[945]: [2026-03-24 18:35:32] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774377332 101 Mar 24 18:35:32 volumio volumio[20953]: 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: 2 Mar 24 18:35:32 volumio sudo[20992]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:32 volumio go-librespot[21173]: time="2026-03-24T18:35:32Z" level=debug msg="connected to ap-gew1.spotify.com:443" Mar 24 18:35:32 volumio go-librespot[21173]: time="2026-03-24T18:35:32Z" level=debug msg="completed keyexchange" Mar 24 18:35:32 volumio go-librespot[21173]: time="2026-03-24T18:35:32Z" level=debug msg="completed challenge" Mar 24 18:35:32 volumio go-librespot[21173]: time="2026-03-24T18:35:32Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:33 volumio go-librespot[21173]: time="2026-03-24T18:35:33Z" level=debug msg="connected to ap-gew1.spotify.com:80" Mar 24 18:35:33 volumio go-librespot[21173]: time="2026-03-24T18:35:33Z" level=debug msg="completed keyexchange" Mar 24 18:35:33 volumio go-librespot[21173]: time="2026-03-24T18:35:33Z" level=debug msg="completed challenge" Mar 24 18:35:33 volumio go-librespot[21173]: time="2026-03-24T18:35:33Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:34 volumio go-librespot[21173]: time="2026-03-24T18:35:34Z" level=debug msg="connected to ap-guc3.spotify.com:4070" Mar 24 18:35:34 volumio volumio[20953]: info: go-librespot daemon successfully initialized Mar 24 18:35:34 volumio go-librespot[21173]: time="2026-03-24T18:35:34Z" level=debug msg="completed keyexchange" Mar 24 18:35:34 volumio go-librespot[21173]: time="2026-03-24T18:35:34Z" level=debug msg="completed challenge" Mar 24 18:35:34 volumio go-librespot[21173]: time="2026-03-24T18:35:34Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:34 volumio go-librespot[21173]: time="2026-03-24T18:35:34Z" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 24 18:35:34 volumio go-librespot[21173]: time="2026-03-24T18:35:34Z" level=debug msg="completed keyexchange" Mar 24 18:35:34 volumio go-librespot[21173]: time="2026-03-24T18:35:34Z" level=debug msg="completed challenge" Mar 24 18:35:34 volumio go-librespot[21173]: time="2026-03-24T18:35:34Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:35 volumio go-librespot[21173]: time="2026-03-24T18:35:35Z" level=debug msg="connected to ap-gae2.spotify.com:80" Mar 24 18:35:35 volumio go-librespot[21173]: time="2026-03-24T18:35:35Z" level=debug msg="completed keyexchange" Mar 24 18:35:35 volumio go-librespot[21173]: time="2026-03-24T18:35:35Z" level=debug msg="completed challenge" Mar 24 18:35:36 volumio go-librespot[21173]: time="2026-03-24T18:35:36Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:36 volumio go-librespot[21173]: time="2026-03-24T18:35:36Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 18:35:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 18:35:37 volumio volumio[20953]: info: Initializing connection to go-librespot Websocket Mar 24 18:35:37 volumio volumio[20953]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 18:35:38 volumio sudo[21226]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 24 18:35:38 volumio sudo[21226]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:38 volumio sudo[21228]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 24 18:35:38 volumio sudo[21226]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:38 volumio sudo[21228]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:38 volumio sudo[21228]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:38 volumio sudo[21231]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 24 18:35:38 volumio sudo[21231]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:38 volumio sudo[21231]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:38 volumio volumio[20953]: info: Upmpdcli Daemon Started Mar 24 18:35:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 24 18:35:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 18:35:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 18:35:39 volumio go-librespot[21234]: go-librespot daemon starting... Mar 24 18:35:39 volumio go-librespot[21235]: time="2026-03-24T18:35:39Z" level=info msg="running go-librespot 0.6.2" Mar 24 18:35:39 volumio go-librespot[21235]: time="2026-03-24T18:35:39Z" level=debug msg="app state loaded" Mar 24 18:35:39 volumio go-librespot[21235]: time="2026-03-24T18:35:39Z" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 18:35:39 volumio go-librespot[21235]: time="2026-03-24T18:35:39Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 24 18:35:39 volumio go-librespot[21235]: time="2026-03-24T18:35:39Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 24 18:35:39 volumio go-librespot[21235]: time="2026-03-24T18:35:39Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 24 18:35:39 volumio go-librespot[21235]: time="2026-03-24T18:35:39Z" level=info msg="zeroconf server listening on port 42745" Mar 24 18:35:39 volumio go-librespot[21235]: time="2026-03-24T18:35:39Z" level=debug msg="obtained new client token: AAAkdJ2T5UfYVY5eHmeDdATRi23L17chXHD2nPGtFwnwk0QJWX7c80ry9vw8HqTwtNEnZfSvqJoUV/jxevD/onptFVPKMQ2qlQolLuesQzNy3Tvs4sxoS8Pdt6KQl2OHcOnJ6nx6J3GVRCYPMp1Qj8NcTKk65y5vAzp9jSAq+3uLXgZA5y7Jx2hfOwrKALN9gjn/y4+B8nOesnAGn935t5O1NlYmdllP29uqK0A+xEFP4K4qAXVhkZisZQ==" Mar 24 18:35:39 volumio go-librespot[21235]: time="2026-03-24T18:35:39Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Mar 24 18:35:39 volumio go-librespot[21235]: time="2026-03-24T18:35:39Z" level=debug msg="completed keyexchange" Mar 24 18:35:39 volumio go-librespot[21235]: time="2026-03-24T18:35:39Z" level=debug msg="completed challenge" Mar 24 18:35:39 volumio go-librespot[21235]: time="2026-03-24T18:35:39Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:39 volumio volumio[20953]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 24 18:35:39 volumio volumio[20953]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 24 18:35:39 volumio volumio[20953]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 24 18:35:39 volumio volumio[20953]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 24 18:35:39 volumio volumio[20953]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 24 18:35:39 volumio volumio[20953]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 24 18:35:39 volumio volumio[20953]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 24 18:35:39 volumio volumio[20953]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 24 18:35:39 volumio volumio[20953]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 24 18:35:39 volumio volumio[20953]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 24 18:35:39 volumio volumio[20953]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 24 18:35:39 volumio volumio[20953]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 24 18:35:39 volumio volumio[20953]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 24 18:35:39 volumio volumio[20953]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 24 18:35:39 volumio volumio[20953]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 24 18:35:39 volumio volumio[20953]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 24 18:35:39 volumio volumio[20953]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 24 18:35:39 volumio volumio[20953]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 24 18:35:39 volumio volumio[20953]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 24 18:35:39 volumio volumio[20953]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 24 18:35:39 volumio volumio[20953]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 24 18:35:39 volumio volumio[20953]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 24 18:35:39 volumio volumio[20953]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 24 18:35:39 volumio volumio[20953]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 24 18:35:39 volumio volumio[20953]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 24 18:35:39 volumio volumio[20953]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 24 18:35:39 volumio volumio[20953]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 24 18:35:39 volumio volumio[20953]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 24 18:35:39 volumio volumio[20953]: info: Adding plugin bluetooth to MyMusic Plugins Mar 24 18:35:39 volumio volumio[20953]: info: Adding plugin multiroom to MyMusic Plugins Mar 24 18:35:39 volumio volumio[20953]: info: Adding plugin metavolumio to MyMusic Plugins Mar 24 18:35:39 volumio volumio[20953]: info: Adding plugin cd_controller to MyMusic Plugins Mar 24 18:35:39 volumio volumio[20953]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 24 18:35:39 volumio volumio[20953]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 24 18:35:39 volumio volumio[20953]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 24 18:35:39 volumio volumio[20953]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 24 18:35:40 volumio volumio[20953]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 24 18:35:40 volumio volumio[20953]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 24 18:35:40 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:40 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:40 volumio volumio[20953]: info: Starting MyVolumio Remote Streaming Endpoints Mar 24 18:35:40 volumio volumio[20953]: info: MyVolumio login type: Token Mar 24 18:35:40 volumio volumio[20953]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 24 18:35:40 volumio volumio[20953]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 24 18:35:40 volumio go-librespot[21235]: time="2026-03-24T18:35:40Z" level=debug msg="connected to ap-gew1.spotify.com:443" Mar 24 18:35:40 volumio go-librespot[21235]: time="2026-03-24T18:35:40Z" level=debug msg="completed keyexchange" Mar 24 18:35:40 volumio go-librespot[21235]: time="2026-03-24T18:35:40Z" level=debug msg="completed challenge" Mar 24 18:35:40 volumio go-librespot[21235]: time="2026-03-24T18:35:40Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:40 volumio volumio[20953]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 24 18:35:40 volumio volumio[20953]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 24 18:35:40 volumio volumio[20953]: info: Streaming services startup Mar 24 18:35:40 volumio volumio[20953]: info: Starting Streaming Daemon Mar 24 18:35:40 volumio sudo[21245]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 24 18:35:40 volumio sudo[21245]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:40 volumio volumio[20953]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 24 18:35:40 volumio sudo[21245]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:40 volumio volumio[20953]: info: Initializing connection to go-librespot Websocket Mar 24 18:35:40 volumio volumio[20953]: error: Cannot start Volumio Streaming Daemon Mar 24 18:35:40 volumio volumio[20953]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 24 18:35:40 volumio volumio[20953]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 24 18:35:40 volumio go-librespot[21235]: time="2026-03-24T18:35:40Z" level=debug msg="new websocket client" Mar 24 18:35:40 volumio volumio[20953]: info: Connection to go-librespot Websocket established Mar 24 18:35:40 volumio go-librespot[21235]: time="2026-03-24T18:35:40Z" level=debug msg="connected to ap-gew1.spotify.com:80" Mar 24 18:35:40 volumio go-librespot[21235]: time="2026-03-24T18:35:40Z" level=debug msg="completed keyexchange" Mar 24 18:35:40 volumio go-librespot[21235]: time="2026-03-24T18:35:40Z" level=debug msg="completed challenge" Mar 24 18:35:40 volumio go-librespot[21235]: time="2026-03-24T18:35:40Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:41 volumio go-librespot[21235]: time="2026-03-24T18:35:41Z" level=debug msg="connected to ap-guc3.spotify.com:4070" Mar 24 18:35:41 volumio go-librespot[21235]: time="2026-03-24T18:35:41Z" level=debug msg="completed keyexchange" Mar 24 18:35:41 volumio go-librespot[21235]: time="2026-03-24T18:35:41Z" level=debug msg="completed challenge" Mar 24 18:35:41 volumio go-librespot[21235]: time="2026-03-24T18:35:41Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:42 volumio go-librespot[21235]: time="2026-03-24T18:35:42Z" level=debug msg="connected to ap-gue1.spotify.com:443" Mar 24 18:35:42 volumio go-librespot[21235]: time="2026-03-24T18:35:42Z" level=debug msg="completed keyexchange" Mar 24 18:35:42 volumio go-librespot[21235]: time="2026-03-24T18:35:42Z" level=debug msg="completed challenge" Mar 24 18:35:42 volumio go-librespot[21235]: time="2026-03-24T18:35:42Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:42 volumio volumio[20953]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 24 18:35:42 volumio volumio[20953]: info: MyVolumio token set successfully Mar 24 18:35:42 volumio volumio[20953]: info: MYVOLUMIO: Adding device Mar 24 18:35:42 volumio volumio[20953]: info: MYVOLUMIO: Evaluating Server Mar 24 18:35:43 volumio volumio[20953]: info: MyVolumio status changed Mar 24 18:35:43 volumio volumio[20953]: info: Streaming services startup Mar 24 18:35:43 volumio volumio[20953]: info: Starting Streaming Daemon Mar 24 18:35:43 volumio volumio[20953]: info: Removing browser output: myVolumio user plan is not superstar Mar 24 18:35:43 volumio volumio[20953]: info: Removing audio output: Mar 24 18:35:43 volumio volumio[20953]: info: Stoppping Tunnel 1 Mar 24 18:35:43 volumio sudo[21273]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 24 18:35:43 volumio sudo[21273]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:43 volumio sudo[21275]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Mar 24 18:35:43 volumio sudo[21275]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:43 volumio sudo[21273]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:43 volumio volumio[20953]: error: Cannot start Volumio Streaming Daemon Mar 24 18:35:43 volumio volumio[20953]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 24 18:35:43 volumio volumio[20953]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 24 18:35:43 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 18:35:43 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 18:35:43 volumio go-librespot[21235]: time="2026-03-24T18:35:43Z" level=debug msg="connected to ap-gew4.spotify.com:80" Mar 24 18:35:43 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 18:35:43 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 18:35:43 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 18:35:43 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 18:35:43 volumio sudo[21275]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:43 volumio volumio[20953]: info: Remote SSH Stopped Mar 24 18:35:43 volumio go-librespot[21235]: time="2026-03-24T18:35:43Z" level=debug msg="completed keyexchange" Mar 24 18:35:43 volumio go-librespot[21235]: time="2026-03-24T18:35:43Z" level=debug msg="completed challenge" Mar 24 18:35:43 volumio go-librespot[21235]: time="2026-03-24T18:35:43Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:43 volumio go-librespot[21235]: time="2026-03-24T18:35:43Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:43 volumio volumio[20953]: info: Connection to go-librespot Websocket closed Mar 24 18:35:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 18:35:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 18:35:43 volumio volumio[20953]: info: Setting Geolocation for MyVolumio to eu3 Mar 24 18:35:43 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:43 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:43 volumio volumio[20953]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:43 volumio volumio[20953]: info: Getting Spotify volume Mar 24 18:35:43 volumio volumio[20953]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 18:35:43 volumio volumio[20953]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 18:35:43 volumio volumio[20953]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 24 18:35:43 volumio volumio[20953]: errno: -111, Mar 24 18:35:43 volumio volumio[20953]: code: 'ECONNREFUSED', Mar 24 18:35:43 volumio volumio[20953]: syscall: 'connect', Mar 24 18:35:43 volumio volumio[20953]: address: '127.0.0.1', Mar 24 18:35:43 volumio volumio[20953]: port: 9879, Mar 24 18:35:43 volumio volumio[20953]: response: undefined Mar 24 18:35:43 volumio volumio[20953]: } Mar 24 18:35:43 volumio volumio[20953]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 18:35:43 volumio sudo[21292]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-24 18:34' Mar 24 18:35:43 volumio sudo[21292]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:43 volumio sudo[21292]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:43 volumio volumio-remote-updater[945]: [2026-03-24 18:35:43] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 24 18:35:43 volumio volumio-remote-updater[945]: [2026-03-24 18:35:43] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 24 18:35:43 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 24 18:35:43 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 24 18:35:43 volumio systemd[1]: volumio.service: Consumed 9.019s CPU time. Mar 24 18:35:43 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 24 18:35:43 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Mar 24 18:35:44 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 78823. Mar 24 18:35:44 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 24 18:35:44 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 24 18:35:44 volumio systemd[1]: volumio.service: Consumed 9.019s CPU time. Mar 24 18:35:44 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Mar 24 18:35:44 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Mar 24 18:35:44 volumio volumio[21304]: info: ------------------------------------------- Mar 24 18:35:44 volumio volumio[21304]: info: ----- Volumio3 ---- Mar 24 18:35:44 volumio volumio[21304]: info: ------------------------------------------- Mar 24 18:35:44 volumio volumio[21304]: info: ----- System startup ---- Mar 24 18:35:44 volumio volumio[21304]: info: ------------------------------------------- Mar 24 18:35:44 volumio volumio[21304]: info: MYVOLUMIO Environment detected Mar 24 18:35:44 volumio volumio[21304]: info: Plugin folders cleanup Mar 24 18:35:44 volumio volumio[21304]: info: Scanning into folder /volumio/app/plugins/ Mar 24 18:35:44 volumio volumio[21304]: info: Scanning category audio_interface Mar 24 18:35:44 volumio volumio[21304]: info: Scanning category miscellanea Mar 24 18:35:44 volumio volumio[21304]: info: Scanning category music_service Mar 24 18:35:44 volumio volumio[21304]: info: Scanning category plugins.json Mar 24 18:35:44 volumio volumio[21304]: info: Scanning category system_controller Mar 24 18:35:44 volumio volumio[21304]: info: Scanning category user_interface Mar 24 18:35:44 volumio volumio[21304]: info: Scanning into folder /data/plugins/ Mar 24 18:35:44 volumio volumio[21304]: info: Scanning category music_service Mar 24 18:35:44 volumio volumio[21304]: info: Plugin folders cleanup completed Mar 24 18:35:44 volumio volumio[21304]: info: ------------------------------------------- Mar 24 18:35:44 volumio volumio[21304]: info: ----- Core plugins startup ---- Mar 24 18:35:44 volumio volumio[21304]: info: ------------------------------------------- Mar 24 18:35:44 volumio volumio[21304]: info: Loading plugins from folder /volumio/app/plugins/ Mar 24 18:35:44 volumio volumio[21304]: info: Adding plugin upnp to MyMusic Plugins Mar 24 18:35:44 volumio volumio[21304]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 24 18:35:44 volumio volumio[21304]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 24 18:35:44 volumio volumio[21304]: info: Loading plugins from folder /data/plugins/ Mar 24 18:35:44 volumio volumio[21304]: info: Adding plugin rtlsdr_radio to MyMusic Plugins Mar 24 18:35:44 volumio volumio[21304]: info: Loading plugin "system"... Mar 24 18:35:44 volumio volumio[21304]: info: Loading plugin "appearance"... Mar 24 18:35:45 volumio volumio[21304]: info: Loading plugin "network"... Mar 24 18:35:45 volumio volumio[21304]: info: Refreshing Cached IP Addresses Mar 24 18:35:45 volumio sudo[21332]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 24 18:35:45 volumio sudo[21332]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:45 volumio sudo[21334]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 24 18:35:45 volumio sudo[21334]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:45 volumio sudo[21332]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:45 volumio sudo[21334]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:45 volumio volumio[21304]: info: Loading plugin "services"... Mar 24 18:35:45 volumio volumio[21304]: info: Loading plugin "alsa_controller"... Mar 24 18:35:45 volumio sudo[21344]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 24 18:35:45 volumio sudo[21344]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:45 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 18:35:45 volumio volumio[21304]: info: Loading plugin "wizard"... Mar 24 18:35:45 volumio volumio[21304]: info: Loading plugin "networkfs"... Mar 24 18:35:45 volumio volumio[21304]: info: Starting Udev Watcher for removable devices Mar 24 18:35:45 volumio volumio[21304]: info: Mounting Device 0ACB-A1DE Mar 24 18:35:45 volumio sudo[21371]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/0ACB-A1DE -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Mar 24 18:35:45 volumio sudo[21371]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:45 volumio sudo[21371]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:45 volumio volumio[21304]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Mar 24 18:35:45 volumio volumio[21304]: dmesg(1) may have more information after failed mount system call. Mar 24 18:35:45 volumio volumio[21304]: error: Failed to mount 0ACB-A1DE: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/0ACB-A1DE" -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Mar 24 18:35:45 volumio volumio[21304]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Mar 24 18:35:45 volumio volumio[21304]: dmesg(1) may have more information after failed mount system call. Mar 24 18:35:45 volumio volumio[21304]: info: Ignoring mount for partition: boot Mar 24 18:35:45 volumio volumio[21304]: info: Ignoring mount for partition: volumio Mar 24 18:35:45 volumio volumio[21304]: info: Ignoring mount for partition: volumio_data Mar 24 18:35:45 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 24 18:35:45 volumio volumio[21304]: info: Loading plugin "volumio_command_line_client"... Mar 24 18:35:45 volumio volumio[21304]: info: Loading plugin "upnp"... Mar 24 18:35:45 volumio volumio[21304]: info: [1774377345344] Starting Upmpd Daemon Mar 24 18:35:45 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 24 18:35:45 volumio volumio[21304]: info: Loading plugin "my_music"... Mar 24 18:35:45 volumio volumio[21304]: info: Loading plugin "mpd"... Mar 24 18:35:45 volumio volumio[21304]: info: Loading plugin "upnp_browser"... Mar 24 18:35:45 volumio volumio[21304]: info: Starting UPNP Browser Mar 24 18:35:45 volumio volumio[21304]: info: Loading plugin "alarm-clock"... Mar 24 18:35:45 volumio volumio[21304]: info: Loading plugin "airplay_emulation"... Mar 24 18:35:45 volumio volumio[21304]: info: Starting Shairport Sync Mar 24 18:35:45 volumio volumio[21304]: info: Loading plugin "last_100"... Mar 24 18:35:45 volumio volumio[21304]: info: Loading plugin "webradio"... Mar 24 18:35:45 volumio volumio[21304]: info: Loading plugin "i2s_dacs"... Mar 24 18:35:45 volumio volumio[21304]: info: Loading plugin "volumiodiscovery"... Mar 24 18:35:45 volumio volumio[21304]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 24 18:35:45 volumio volumio[21304]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 18:35:45 volumio volumio[21304]: *** WARNING *** For more information see Mar 24 18:35:45 volumio volumio[21304]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 24 18:35:45 volumio volumio[21304]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 18:35:45 volumio volumio[21304]: *** WARNING *** For more information see Mar 24 18:35:45 volumio node[21304]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 24 18:35:45 volumio node[21304]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 18:35:45 volumio node[21304]: *** WARNING *** For more information see Mar 24 18:35:45 volumio node[21304]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 24 18:35:45 volumio node[21304]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 18:35:45 volumio node[21304]: *** WARNING *** For more information see Mar 24 18:35:45 volumio volumio[21304]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 24 18:35:45 volumio volumio[21304]: info: Discovery: Started advertising with name: Volumio Mar 24 18:35:45 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 24 18:35:45 volumio volumio[21304]: info: Loading plugin "spop"... Mar 24 18:35:46 volumio volumio[21304]: info: Loading plugin "ytmusic"... Mar 24 18:35:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 24 18:35:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 18:35:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 18:35:46 volumio go-librespot[21375]: go-librespot daemon starting... Mar 24 18:35:46 volumio go-librespot[21376]: time="2026-03-24T18:35:46Z" level=info msg="running go-librespot 0.6.2" Mar 24 18:35:46 volumio go-librespot[21376]: time="2026-03-24T18:35:46Z" level=debug msg="app state loaded" Mar 24 18:35:46 volumio go-librespot[21376]: time="2026-03-24T18:35:46Z" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 18:35:46 volumio volumio[21304]: info: Loading plugin "outputs"... Mar 24 18:35:46 volumio volumio[21304]: info: Loading plugin "albumart"... Mar 24 18:35:46 volumio volumio[21304]: info: Plugin example_plugin is not enabled Mar 24 18:35:46 volumio volumio[21304]: info: Loading plugin "inputs"... Mar 24 18:35:46 volumio volumio[21304]: info: Loading plugin "updater_comm"... Mar 24 18:35:46 volumio volumio[21304]: info: Plugin mpdemulation is not enabled Mar 24 18:35:46 volumio volumio[21304]: info: Loading plugin "rest_api"... Mar 24 18:35:46 volumio volumio[21304]: info: Loading plugin "websocket"... Mar 24 18:35:46 volumio volumio[21304]: info: Starting Socket.io Server version 1.7.4 Mar 24 18:35:46 volumio volumio[21304]: info: Loading plugin "podcast"... Mar 24 18:35:46 volumio volumio[21304]: info: ControllerPodcast::constructor Mar 24 18:35:46 volumio volumio[21304]: info: Loading plugin "rtlsdr_radio"... Mar 24 18:35:46 volumio volumio[21382]: Forking 3 albumart workers Mar 24 18:35:46 volumio volumio[21304]: info: Loading i18n strings for locale en Mar 24 18:35:46 volumio volumio[21304]: Updating browse sources language Mar 24 18:35:46 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 18:35:46 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 18:35:46 volumio volumio[21304]: info: CoreCommandRouter::initPlayerControls Mar 24 18:35:46 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:46 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:46 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:46 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:46 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:46 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:46 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:46 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:46 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 18:35:46 volumio volumio[21304]: Express server listening on port 3000 Mar 24 18:35:46 volumio volumio[21304]: [Metrics] WebUI: 2s 277.88ms Mar 24 18:35:46 volumio volumio[21304]: info: CoreStateMachine::resetVolumioState Mar 24 18:35:46 volumio volumio[21304]: info: CoreStateMachine::getcurrentVolume Mar 24 18:35:46 volumio volumio[21304]: info: CoreCommandRouter::volumioRetrievevolume Mar 24 18:35:46 volumio volumio[21304]: info: Volumio Network Manager: Network status updated: 2 Mar 24 18:35:46 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:46 volumio volumio[21304]: info: Reloading queue from file Mar 24 18:35:46 volumio volumio[21304]: info: VolumeController:: Volume=36 Mute =true Mar 24 18:35:46 volumio volumio[21304]: info: CoreStateMachine::pushState Mar 24 18:35:46 volumio volumio[21304]: info: CorePlayQueue::getTrack 0 Mar 24 18:35:46 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 18:35:46 volumio volumio[21304]: info: CoreCommandRouter::volumioPushState Mar 24 18:35:46 volumio volumio[21304]: info: CoreStateMachine::updateTrackBlock Mar 24 18:35:46 volumio volumio[21304]: info: CorePlayQueue::getTrackBlock Mar 24 18:35:46 volumio volumio[21304]: info: CoreCommandRouter::volumioRetrievevolume Mar 24 18:35:46 volumio volumio[21304]: info: CoreStateMachine::setRepeat null single undefined Mar 24 18:35:46 volumio volumio[21304]: info: CoreStateMachine::pushState Mar 24 18:35:46 volumio volumio[21304]: info: CorePlayQueue::getTrack 0 Mar 24 18:35:46 volumio volumio[21304]: info: CoreCommandRouter::volumioPushState Mar 24 18:35:46 volumio volumio[21304]: info: CoreStateMachine::setRandom true Mar 24 18:35:46 volumio volumio[21304]: info: CoreStateMachine::pushState Mar 24 18:35:46 volumio volumio[21304]: info: CorePlayQueue::getTrack 0 Mar 24 18:35:46 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 18:35:46 volumio volumio[21304]: info: CoreCommandRouter::volumioPushState Mar 24 18:35:46 volumio volumio[21304]: info: Setting Device type: Raspberry PI Mar 24 18:35:46 volumio volumio[21304]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Mar 24 18:35:46 volumio volumio[21304]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04170 Mar 24 18:35:46 volumio volumio[21304]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Mar 24 18:35:46 volumio volumio[21304]: info: Completed loading Core Plugins Mar 24 18:35:46 volumio volumio[21304]: info: Preparing to generate the ALSA configuration file Mar 24 18:35:47 volumio volumio[21304]: info: Asound.conf file unchanged, so no further update is needed Mar 24 18:35:47 volumio volumio[21304]: info: Output device has changed, restarting MPD Mar 24 18:35:47 volumio volumio[21304]: info: Output device has changed, restarting Shairport Sync Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:47 volumio volumio[21304]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 24 18:35:47 volumio sudo[21441]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 24 18:35:47 volumio sudo[21439]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 24 18:35:47 volumio sudo[21439]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:47 volumio volumio[21304]: info: ___________ START PLUGINS ___________ Mar 24 18:35:47 volumio sudo[21441]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:47 volumio sudo[21439]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:47 volumio volumio[21304]: info: ControllerMpd::onStart: Initializing MPD Mar 24 18:35:47 volumio volumio[21304]: info: Creating MPD Configuration file Mar 24 18:35:47 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 24 18:35:47 volumio go-librespot[21376]: time="2026-03-24T18:35:47Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 24 18:35:47 volumio go-librespot[21376]: time="2026-03-24T18:35:47Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 24 18:35:47 volumio go-librespot[21376]: time="2026-03-24T18:35:47Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 24 18:35:47 volumio sudo[21449]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 24 18:35:47 volumio sudo[21449]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:47 volumio go-librespot[21376]: time="2026-03-24T18:35:47Z" level=info msg="zeroconf server listening on port 45915" Mar 24 18:35:47 volumio sudo[21449]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:47 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 24 18:35:47 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 24 18:35:47 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 18:35:47 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 24 18:35:47 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 18:35:47 volumio volumio[21304]: info: [1774377347102] CoreMusicLibrary::Adding element Media Servers Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 18:35:47 volumio sudo[21453]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 24 18:35:47 volumio sudo[21453]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:47 volumio volumio[21392]: Starting albumart workers Mar 24 18:35:47 volumio volumio[21304]: info: UPNP Browser: Client initialized successfully Mar 24 18:35:47 volumio volumio[21393]: Starting albumart workers Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:47 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 24 18:35:47 volumio volumio[21394]: Starting albumart workers Mar 24 18:35:47 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 24 18:35:47 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 24 18:35:47 volumio volumio[21304]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:47 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 24 18:35:47 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 24 18:35:47 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 24 18:35:47 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 24 18:35:47 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 24 18:35:47 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 24 18:35:47 volumio volumio[21304]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 18:35:47 volumio volumio[21304]: info: [1774377347170] CoreMusicLibrary::Adding element Last_100 Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 18:35:47 volumio volumio[21304]: info: [1774377347174] CoreMusicLibrary::Adding element Webradio Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 18:35:47 volumio volumio[21304]: info: Initializing BBC Radios Mar 24 18:35:47 volumio sudo[21465]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 24 18:35:47 volumio sudo[21465]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 24 18:35:47 volumio sudo[21465]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:47 volumio volumio[21304]: info: Creating Spotify config file Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:47 volumio go-librespot[21376]: time="2026-03-24T18:35:47Z" level=debug msg="obtained new client token: AACbv//Jmoctyx8uTIx2rCFlY+t1t3wqEH8YidvOZLduGBWScd5vk9VC12YvdiMEWfKNef10tupEKaDl4WjC4fWBP9RVuS6ecQECzW0S/8GbxEfCfu5a8Uf+WS3BnO0T9SKlbFXJrQEWy6ycgFHOE0h2jJ24EjpFbAveibZw9AtqBggyOzpuA3xRKoAxUdVCFi3ImfAu5/e+kR8xhB1HSH0G+ix+9VAjvxMP1XYk8iA3ToL63tSN1zE=" Mar 24 18:35:47 volumio go-librespot[21376]: time="2026-03-24T18:35:47Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 18:35:47 volumio volumio[21304]: info: [1774377347446] CoreMusicLibrary::Adding element YouTube Music Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 18:35:47 volumio volumio[21304]: Cannot find translation for source YouTube Music Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 18:35:47 volumio volumio[21304]: info: [1774377347450] CoreMusicLibrary::Adding element Podcast Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 18:35:47 volumio volumio[21304]: Cannot find translation for source YouTube Music Mar 24 18:35:47 volumio volumio[21304]: Cannot find translation for source Podcast Mar 24 18:35:47 volumio volumio[21304]: info: [RTL-SDR Radio] Starting plugin Mar 24 18:35:47 volumio volumio[21304]: info: [RTL-SDR Radio] Loaded i18n strings for language: en Mar 24 18:35:47 volumio volumio[21304]: info: Volumio Calling Home Mar 24 18:35:47 volumio volumio[21304]: info: [RTL-SDR Radio] snd-aloop already loaded Mar 24 18:35:47 volumio volumio[21304]: info: [RTL-SDR Radio] No stations database found, creating v2 Mar 24 18:35:47 volumio volumio[21304]: info: [RTL-SDR Radio] Database loaded at: 2026-03-24T18:35:47.495Z Mar 24 18:35:47 volumio volumio[21304]: info: [RTL-SDR Radio] Loading blocklist from: /data/plugins/music_service/rtlsdr_radio/blocklist.json Mar 24 18:35:47 volumio volumio[21304]: info: [RTL-SDR Radio] Got 21 phrases from file Mar 24 18:35:47 volumio volumio[21304]: info: [RTL-SDR Radio] Updated metadata blocklist Mar 24 18:35:47 volumio volumio[21304]: info: [RTL-SDR Radio] Metadata module now has 21 phrases Mar 24 18:35:47 volumio volumio[21304]: info: [RTL-SDR Radio] Management server started on port 3456 Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 18:35:47 volumio volumio[21304]: info: [1774377347528] CoreMusicLibrary::Adding element FM/DAB Radio Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 18:35:47 volumio volumio[21304]: Cannot find translation for source YouTube Music Mar 24 18:35:47 volumio volumio[21304]: Cannot find translation for source Podcast Mar 24 18:35:47 volumio volumio[21304]: Cannot find translation for source FM/DAB Radio Mar 24 18:35:47 volumio volumio[21304]: info: [RTL-SDR Radio] Plugin started successfully Mar 24 18:35:47 volumio volumio[21304]: info: VolumeController:: Volume=36 Mute =true Mar 24 18:35:47 volumio volumio[21304]: info: CoreStateMachine::pushState Mar 24 18:35:47 volumio volumio[21304]: info: CorePlayQueue::getTrack 0 Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::volumioPushState Mar 24 18:35:47 volumio volumio[21304]: info: MPD Permissions set Mar 24 18:35:47 volumio volumio[21304]: info: MPD Permissions set Mar 24 18:35:47 volumio volumio[21304]: info: Spotify config file written Mar 24 18:35:47 volumio sudo[21509]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 24 18:35:47 volumio sudo[21509]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:47 volumio volumio[21304]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:47 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:47 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:35:47 volumio volumio[21304]: info: No need to fix Spotify hosts Mar 24 18:35:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 18:35:47 volumio go-librespot[21518]: go-librespot daemon starting... Mar 24 18:35:47 volumio sudo[21509]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:47 volumio volumio[21304]: info: Starting Shairport Sync Mar 24 18:35:47 volumio volumio[21304]: info: Starting Shairport Sync Mar 24 18:35:47 volumio volumio[21304]: info: Starting Shairport Sync Mar 24 18:35:47 volumio go-librespot[21522]: time="2026-03-24T18:35:47Z" level=info msg="running go-librespot 0.6.2" Mar 24 18:35:47 volumio go-librespot[21522]: time="2026-03-24T18:35:47Z" level=debug msg="app state loaded" Mar 24 18:35:47 volumio go-librespot[21522]: time="2026-03-24T18:35:47Z" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 18:35:47 volumio sudo[21530]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 18:35:47 volumio sudo[21530]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:47 volumio sudo[21533]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 18:35:47 volumio sudo[21533]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:47 volumio sudo[21534]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 18:35:47 volumio sudo[21534]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:47 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 24 18:35:47 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Mar 24 18:35:47 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 18:35:47 volumio systemd[1]: shairport-sync.service: Consumed 1.548s CPU time. Mar 24 18:35:47 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 18:35:47 volumio sudo[21530]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:47 volumio sudo[21534]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:47 volumio sudo[21533]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:47 volumio volumio[21304]: info: Shairport-Sync Started Mar 24 18:35:47 volumio volumio[21304]: Error adding Membership: Error: addMembership EINVAL Mar 24 18:35:47 volumio volumio[21304]: info: Shairport-Sync Started Mar 24 18:35:47 volumio volumio[21304]: info: Shairport-Sync Started Mar 24 18:35:47 volumio volumio[21304]: info: Discovery: adding 072f109f-54a2-4344-b8c4-538b45da7e51 Mar 24 18:35:47 volumio volumio[21304]: info: Discovery: Found device Volumio Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::volumioGetState Mar 24 18:35:47 volumio volumio[21304]: info: CorePlayQueue::getTrack 0 Mar 24 18:35:47 volumio volumio[21304]: info: Volumio called home Mar 24 18:35:47 volumio volumio[21304]: info: Discovery: this is already registered, 072f109f-54a2-4344-b8c4-538b45da7e51 Mar 24 18:35:47 volumio volumio[21304]: info: Discovery: Found device Volumio Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::volumioGetState Mar 24 18:35:47 volumio volumio[21304]: info: CorePlayQueue::getTrack 0 Mar 24 18:35:47 volumio volumio[21304]: info: CoreCommandRouter::volumioGetState Mar 24 18:35:47 volumio volumio[21304]: info: CorePlayQueue::getTrack 0 Mar 24 18:35:47 volumio mpd[21482]: 2026-03-24T18:35:47 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 24 18:35:47 volumio systemd[1]: Started mpd.service - Music Player Daemon. Mar 24 18:35:47 volumio sudo[21453]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:47 volumio sudo[21441]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:47 volumio volumio[21304]: info: Completed starting Core Plugins Mar 24 18:35:47 volumio volumio[21304]: info: ------------------------------------------- Mar 24 18:35:47 volumio volumio[21304]: info: ----- MyVolumio plugins startup ---- Mar 24 18:35:47 volumio volumio[21304]: info: ------------------------------------------- Mar 24 18:35:47 volumio volumio[21304]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 24 18:35:48 volumio volumio[21304]: error: MPD error: The expression evaluated to a falsy value: Mar 24 18:35:48 volumio volumio[21304]: assert.ok(self.idling) Mar 24 18:35:48 volumio volumio[21304]: error: The expression evaluated to a falsy value: Mar 24 18:35:48 volumio volumio[21304]: assert.ok(self.idling) Mar 24 18:35:48 volumio volumio[21304]: info: MPD running with PID21482 Mar 24 18:35:48 volumio volumio[21304]: ,establishing connection Mar 24 18:35:48 volumio volumio[21304]: error: updateQueue error: null Mar 24 18:35:48 volumio volumio[21304]: error: updateQueue error: null Mar 24 18:35:48 volumio volumio[21304]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 24 18:35:48 volumio go-librespot[21522]: time="2026-03-24T18:35:48Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 24 18:35:48 volumio go-librespot[21522]: time="2026-03-24T18:35:48Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 24 18:35:48 volumio go-librespot[21522]: time="2026-03-24T18:35:48Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 24 18:35:48 volumio go-librespot[21522]: time="2026-03-24T18:35:48Z" level=info msg="zeroconf server listening on port 43901" Mar 24 18:35:48 volumio volumio-remote-updater[945]: [2026-03-24 18:35:48] [connect] Successful connection Mar 24 18:35:48 volumio volumio-remote-updater[945]: [2026-03-24 18:35:48] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774377348 101 Mar 24 18:35:48 volumio volumio[21304]: 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: 2 Mar 24 18:35:49 volumio sudo[21344]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:50 volumio volumio[21304]: info: go-librespot daemon successfully initialized Mar 24 18:35:53 volumio go-librespot[21522]: time="2026-03-24T18:35:53Z" level=debug msg="obtained new client token: AADG81E241dgXOJCvHcsP/MK9u/2IIijIt82HEDsSMX4w0vEHEhsbpbIABwcAVxLgKkaWUWnyt17Jpx9js5fif2QbirRhGExj9SfX+vl1C5NF5LR9goCWzc0rLdRM/sofxbrn6e6cK1L4IHqbu+Tkrt6S+KnzICH+erSE/oWosbRlo6KxYl5rTsexdeFolCN6F1VOWa9QPZSLo6kLSzj6OGnEg15AH9clEXuiLQsF28/oyw3MnqtDMc=" Mar 24 18:35:53 volumio go-librespot[21522]: time="2026-03-24T18:35:53Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Mar 24 18:35:53 volumio go-librespot[21522]: time="2026-03-24T18:35:53Z" level=debug msg="completed keyexchange" Mar 24 18:35:53 volumio go-librespot[21522]: time="2026-03-24T18:35:53Z" level=debug msg="completed challenge" Mar 24 18:35:53 volumio go-librespot[21522]: time="2026-03-24T18:35:53Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:53 volumio volumio[21304]: info: Initializing connection to go-librespot Websocket Mar 24 18:35:53 volumio go-librespot[21522]: time="2026-03-24T18:35:53Z" level=debug msg="new websocket client" Mar 24 18:35:53 volumio volumio[21304]: info: Connection to go-librespot Websocket established Mar 24 18:35:53 volumio go-librespot[21522]: time="2026-03-24T18:35:53Z" level=debug msg="connected to ap-gew1.spotify.com:443" Mar 24 18:35:53 volumio go-librespot[21522]: time="2026-03-24T18:35:53Z" level=debug msg="completed keyexchange" Mar 24 18:35:53 volumio go-librespot[21522]: time="2026-03-24T18:35:53Z" level=debug msg="completed challenge" Mar 24 18:35:53 volumio go-librespot[21522]: time="2026-03-24T18:35:53Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:54 volumio go-librespot[21522]: time="2026-03-24T18:35:54Z" level=debug msg="connected to ap-gew1.spotify.com:80" Mar 24 18:35:54 volumio go-librespot[21522]: time="2026-03-24T18:35:54Z" level=debug msg="completed keyexchange" Mar 24 18:35:54 volumio go-librespot[21522]: time="2026-03-24T18:35:54Z" level=debug msg="completed challenge" Mar 24 18:35:54 volumio go-librespot[21522]: time="2026-03-24T18:35:54Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:55 volumio go-librespot[21522]: time="2026-03-24T18:35:55Z" level=debug msg="connected to ap-guc3.spotify.com:4070" Mar 24 18:35:55 volumio go-librespot[21522]: time="2026-03-24T18:35:55Z" level=debug msg="completed keyexchange" Mar 24 18:35:55 volumio go-librespot[21522]: time="2026-03-24T18:35:55Z" level=debug msg="completed challenge" Mar 24 18:35:55 volumio go-librespot[21522]: time="2026-03-24T18:35:55Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:55 volumio sudo[21576]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 24 18:35:55 volumio sudo[21576]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:55 volumio sudo[21576]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:55 volumio sudo[21578]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 24 18:35:55 volumio sudo[21578]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:55 volumio sudo[21578]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:55 volumio sudo[21581]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 24 18:35:55 volumio sudo[21581]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:55 volumio sudo[21581]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:55 volumio volumio[21304]: info: Upmpdcli Daemon Started Mar 24 18:35:55 volumio go-librespot[21522]: time="2026-03-24T18:35:55Z" level=debug msg="connected to ap-gue1.spotify.com:443" Mar 24 18:35:56 volumio go-librespot[21522]: time="2026-03-24T18:35:56Z" level=debug msg="completed keyexchange" Mar 24 18:35:56 volumio go-librespot[21522]: time="2026-03-24T18:35:56Z" level=debug msg="completed challenge" Mar 24 18:35:56 volumio go-librespot[21522]: time="2026-03-24T18:35:56Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:56 volumio volumio[21304]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 24 18:35:56 volumio volumio[21304]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 24 18:35:56 volumio volumio[21304]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 24 18:35:56 volumio volumio[21304]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 24 18:35:56 volumio volumio[21304]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 24 18:35:56 volumio volumio[21304]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 24 18:35:56 volumio volumio[21304]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 24 18:35:56 volumio volumio[21304]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 24 18:35:56 volumio volumio[21304]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 24 18:35:56 volumio volumio[21304]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 24 18:35:56 volumio volumio[21304]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 24 18:35:56 volumio volumio[21304]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 24 18:35:56 volumio volumio[21304]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 24 18:35:56 volumio volumio[21304]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 24 18:35:56 volumio volumio[21304]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 24 18:35:56 volumio volumio[21304]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 24 18:35:56 volumio volumio[21304]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 24 18:35:56 volumio volumio[21304]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 24 18:35:56 volumio volumio[21304]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 24 18:35:56 volumio volumio[21304]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 24 18:35:56 volumio volumio[21304]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 24 18:35:56 volumio volumio[21304]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 24 18:35:56 volumio volumio[21304]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 24 18:35:56 volumio volumio[21304]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 24 18:35:56 volumio volumio[21304]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 24 18:35:56 volumio volumio[21304]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 24 18:35:56 volumio volumio[21304]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 24 18:35:56 volumio volumio[21304]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 24 18:35:56 volumio volumio[21304]: info: Adding plugin bluetooth to MyMusic Plugins Mar 24 18:35:56 volumio volumio[21304]: info: Adding plugin multiroom to MyMusic Plugins Mar 24 18:35:56 volumio volumio[21304]: info: Adding plugin metavolumio to MyMusic Plugins Mar 24 18:35:56 volumio volumio[21304]: info: Adding plugin cd_controller to MyMusic Plugins Mar 24 18:35:56 volumio volumio[21304]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 24 18:35:56 volumio volumio[21304]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 24 18:35:56 volumio volumio[21304]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 24 18:35:56 volumio volumio[21304]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 24 18:35:56 volumio volumio[21304]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 24 18:35:56 volumio volumio[21304]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 24 18:35:56 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:56 volumio volumio[21304]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:35:56 volumio volumio[21304]: info: Starting MyVolumio Remote Streaming Endpoints Mar 24 18:35:56 volumio volumio[21304]: info: MyVolumio login type: Token Mar 24 18:35:56 volumio volumio[21304]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 24 18:35:56 volumio volumio[21304]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 24 18:35:56 volumio go-librespot[21522]: time="2026-03-24T18:35:56Z" 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" Mar 24 18:35:56 volumio go-librespot[21522]: time="2026-03-24T18:35:56Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Mar 24 18:35:56 volumio go-librespot[21522]: time="2026-03-24T18:35:56Z" level=debug msg="completed keyexchange" Mar 24 18:35:56 volumio go-librespot[21522]: time="2026-03-24T18:35:56Z" level=debug msg="completed challenge" Mar 24 18:35:56 volumio go-librespot[21522]: time="2026-03-24T18:35:56Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:56 volumio go-librespot[21522]: time="2026-03-24T18:35:56Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:35:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 18:35:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 18:35:56 volumio volumio[21304]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 24 18:35:56 volumio volumio[21304]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 24 18:35:56 volumio volumio[21304]: info: Streaming services startup Mar 24 18:35:56 volumio volumio[21304]: info: Starting Streaming Daemon Mar 24 18:35:56 volumio sudo[21585]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 24 18:35:56 volumio sudo[21585]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:56 volumio volumio[21304]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 24 18:35:56 volumio sudo[21585]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:56 volumio volumio[21304]: info: Getting Spotify volume Mar 24 18:35:56 volumio volumio[21304]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 18:35:56 volumio volumio[21304]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 18:35:56 volumio volumio[21304]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 24 18:35:56 volumio volumio[21304]: errno: -111, Mar 24 18:35:56 volumio volumio[21304]: code: 'ECONNREFUSED', Mar 24 18:35:56 volumio volumio[21304]: syscall: 'connect', Mar 24 18:35:56 volumio volumio[21304]: address: '127.0.0.1', Mar 24 18:35:56 volumio volumio[21304]: port: 9879, Mar 24 18:35:56 volumio volumio[21304]: response: undefined Mar 24 18:35:56 volumio volumio[21304]: } Mar 24 18:35:56 volumio volumio[21304]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 18:35:57 volumio sudo[21607]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-24 18:34' Mar 24 18:35:57 volumio sudo[21607]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:57 volumio sudo[21607]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:57 volumio volumio-remote-updater[945]: [2026-03-24 18:35:57] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 24 18:35:57 volumio volumio-remote-updater[945]: [2026-03-24 18:35:57] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 24 18:35:57 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 24 18:35:57 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 24 18:35:57 volumio systemd[1]: volumio.service: Consumed 8.603s CPU time. Mar 24 18:35:57 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 24 18:35:57 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Mar 24 18:35:57 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 78824. Mar 24 18:35:57 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 24 18:35:57 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 24 18:35:57 volumio systemd[1]: volumio.service: Consumed 8.603s CPU time. Mar 24 18:35:57 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Mar 24 18:35:57 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Mar 24 18:35:57 volumio volumio[21620]: info: ------------------------------------------- Mar 24 18:35:57 volumio volumio[21620]: info: ----- Volumio3 ---- Mar 24 18:35:57 volumio volumio[21620]: info: ------------------------------------------- Mar 24 18:35:57 volumio volumio[21620]: info: ----- System startup ---- Mar 24 18:35:57 volumio volumio[21620]: info: ------------------------------------------- Mar 24 18:35:58 volumio volumio[21620]: info: MYVOLUMIO Environment detected Mar 24 18:35:58 volumio volumio[21620]: info: Plugin folders cleanup Mar 24 18:35:58 volumio volumio[21620]: info: Scanning into folder /volumio/app/plugins/ Mar 24 18:35:58 volumio volumio[21620]: info: Scanning category audio_interface Mar 24 18:35:58 volumio volumio[21620]: info: Scanning category miscellanea Mar 24 18:35:58 volumio volumio[21620]: info: Scanning category music_service Mar 24 18:35:58 volumio volumio[21620]: info: Scanning category plugins.json Mar 24 18:35:58 volumio volumio[21620]: info: Scanning category system_controller Mar 24 18:35:58 volumio volumio[21620]: info: Scanning category user_interface Mar 24 18:35:58 volumio volumio[21620]: info: Scanning into folder /data/plugins/ Mar 24 18:35:58 volumio volumio[21620]: info: Scanning category music_service Mar 24 18:35:58 volumio volumio[21620]: info: Plugin folders cleanup completed Mar 24 18:35:58 volumio volumio[21620]: info: ------------------------------------------- Mar 24 18:35:58 volumio volumio[21620]: info: ----- Core plugins startup ---- Mar 24 18:35:58 volumio volumio[21620]: info: ------------------------------------------- Mar 24 18:35:58 volumio volumio[21620]: info: Loading plugins from folder /volumio/app/plugins/ Mar 24 18:35:58 volumio volumio[21620]: info: Adding plugin upnp to MyMusic Plugins Mar 24 18:35:58 volumio volumio[21620]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 24 18:35:58 volumio volumio[21620]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 24 18:35:58 volumio volumio[21620]: info: Loading plugins from folder /data/plugins/ Mar 24 18:35:58 volumio volumio[21620]: info: Adding plugin rtlsdr_radio to MyMusic Plugins Mar 24 18:35:58 volumio volumio[21620]: info: Loading plugin "system"... Mar 24 18:35:58 volumio volumio[21620]: info: Loading plugin "appearance"... Mar 24 18:35:58 volumio volumio[21620]: info: Loading plugin "network"... Mar 24 18:35:58 volumio volumio[21620]: info: Refreshing Cached IP Addresses Mar 24 18:35:58 volumio sudo[21648]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 24 18:35:58 volumio sudo[21648]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:58 volumio sudo[21650]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 24 18:35:58 volumio sudo[21650]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:58 volumio sudo[21648]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:58 volumio sudo[21650]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:58 volumio volumio[21620]: info: Loading plugin "services"... Mar 24 18:35:58 volumio volumio[21620]: info: Loading plugin "alsa_controller"... Mar 24 18:35:58 volumio sudo[21657]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 24 18:35:58 volumio sudo[21657]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:58 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 18:35:58 volumio volumio[21620]: info: Loading plugin "wizard"... Mar 24 18:35:58 volumio volumio[21620]: info: Loading plugin "networkfs"... Mar 24 18:35:58 volumio volumio[21620]: info: Starting Udev Watcher for removable devices Mar 24 18:35:58 volumio volumio[21620]: info: Mounting Device 0ACB-A1DE Mar 24 18:35:58 volumio sudo[21687]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/0ACB-A1DE -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Mar 24 18:35:58 volumio sudo[21687]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:35:58 volumio sudo[21687]: pam_unix(sudo:session): session closed for user root Mar 24 18:35:58 volumio volumio[21620]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Mar 24 18:35:58 volumio volumio[21620]: dmesg(1) may have more information after failed mount system call. Mar 24 18:35:58 volumio volumio[21620]: error: Failed to mount 0ACB-A1DE: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/0ACB-A1DE" -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Mar 24 18:35:58 volumio volumio[21620]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Mar 24 18:35:58 volumio volumio[21620]: dmesg(1) may have more information after failed mount system call. Mar 24 18:35:58 volumio volumio[21620]: info: Ignoring mount for partition: boot Mar 24 18:35:58 volumio volumio[21620]: info: Ignoring mount for partition: volumio Mar 24 18:35:58 volumio volumio[21620]: info: Ignoring mount for partition: volumio_data Mar 24 18:35:58 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 24 18:35:58 volumio volumio[21620]: info: Loading plugin "volumio_command_line_client"... Mar 24 18:35:58 volumio volumio[21620]: info: Loading plugin "upnp"... Mar 24 18:35:58 volumio volumio[21620]: info: [1774377358603] Starting Upmpd Daemon Mar 24 18:35:58 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 24 18:35:58 volumio volumio[21620]: info: Loading plugin "my_music"... Mar 24 18:35:58 volumio volumio[21620]: info: Loading plugin "mpd"... Mar 24 18:35:58 volumio volumio[21620]: info: Loading plugin "upnp_browser"... Mar 24 18:35:59 volumio volumio[21620]: info: Starting UPNP Browser Mar 24 18:35:59 volumio volumio[21620]: info: Loading plugin "alarm-clock"... Mar 24 18:35:59 volumio volumio[21620]: info: Loading plugin "airplay_emulation"... Mar 24 18:35:59 volumio volumio[21620]: info: Starting Shairport Sync Mar 24 18:35:59 volumio volumio[21620]: info: Loading plugin "last_100"... Mar 24 18:35:59 volumio volumio[21620]: info: Loading plugin "webradio"... Mar 24 18:35:59 volumio volumio[21620]: info: Loading plugin "i2s_dacs"... Mar 24 18:35:59 volumio volumio[21620]: info: Loading plugin "volumiodiscovery"... Mar 24 18:35:59 volumio volumio[21620]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 24 18:35:59 volumio volumio[21620]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 18:35:59 volumio volumio[21620]: *** WARNING *** For more information see Mar 24 18:35:59 volumio volumio[21620]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 24 18:35:59 volumio volumio[21620]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 18:35:59 volumio volumio[21620]: *** WARNING *** For more information see Mar 24 18:35:59 volumio node[21620]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 24 18:35:59 volumio node[21620]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 18:35:59 volumio node[21620]: *** WARNING *** For more information see Mar 24 18:35:59 volumio node[21620]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 24 18:35:59 volumio node[21620]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 18:35:59 volumio node[21620]: *** WARNING *** For more information see Mar 24 18:35:59 volumio volumio[21620]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 24 18:35:59 volumio volumio[21620]: info: Discovery: Started advertising with name: Volumio Mar 24 18:35:59 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 24 18:35:59 volumio volumio[21620]: info: Loading plugin "spop"... Mar 24 18:35:59 volumio volumio[21620]: info: Loading plugin "ytmusic"... Mar 24 18:35:59 volumio volumio[21620]: info: Loading plugin "outputs"... Mar 24 18:35:59 volumio volumio[21620]: info: Loading plugin "albumart"... Mar 24 18:35:59 volumio volumio[21620]: info: Plugin example_plugin is not enabled Mar 24 18:35:59 volumio volumio[21620]: info: Loading plugin "inputs"... Mar 24 18:35:59 volumio volumio[21620]: info: Loading plugin "updater_comm"... Mar 24 18:35:59 volumio volumio[21620]: info: Plugin mpdemulation is not enabled Mar 24 18:35:59 volumio volumio[21620]: info: Loading plugin "rest_api"... Mar 24 18:35:59 volumio volumio[21620]: info: Loading plugin "websocket"... Mar 24 18:35:59 volumio volumio[21620]: info: Starting Socket.io Server version 1.7.4 Mar 24 18:35:59 volumio volumio[21620]: info: Loading plugin "podcast"... Mar 24 18:35:59 volumio volumio[21620]: info: ControllerPodcast::constructor Mar 24 18:35:59 volumio volumio[21620]: info: Loading plugin "rtlsdr_radio"... Mar 24 18:35:59 volumio volumio[21691]: Forking 3 albumart workers Mar 24 18:35:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 24 18:35:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 18:35:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 18:35:59 volumio go-librespot[21701]: go-librespot daemon starting... Mar 24 18:35:59 volumio go-librespot[21721]: time="2026-03-24T18:35:59Z" level=info msg="running go-librespot 0.6.2" Mar 24 18:35:59 volumio go-librespot[21721]: time="2026-03-24T18:35:59Z" level=debug msg="app state loaded" Mar 24 18:35:59 volumio go-librespot[21721]: time="2026-03-24T18:35:59Z" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 18:36:00 volumio volumio[21620]: info: Loading i18n strings for locale en Mar 24 18:36:00 volumio volumio[21620]: Updating browse sources language Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::initPlayerControls Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 18:36:00 volumio volumio[21620]: Express server listening on port 3000 Mar 24 18:36:00 volumio volumio[21620]: [Metrics] WebUI: 2s 299.37ms Mar 24 18:36:00 volumio volumio[21620]: info: CoreStateMachine::resetVolumioState Mar 24 18:36:00 volumio volumio[21620]: info: CoreStateMachine::getcurrentVolume Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::volumioRetrievevolume Mar 24 18:36:00 volumio volumio[21620]: info: Volumio Network Manager: Network status updated: 2 Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:36:00 volumio volumio[21620]: info: Reloading queue from file Mar 24 18:36:00 volumio volumio[21620]: info: VolumeController:: Volume=36 Mute =true Mar 24 18:36:00 volumio volumio[21620]: info: CoreStateMachine::pushState Mar 24 18:36:00 volumio volumio[21620]: info: CorePlayQueue::getTrack 0 Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::volumioPushState Mar 24 18:36:00 volumio volumio[21620]: info: CoreStateMachine::updateTrackBlock Mar 24 18:36:00 volumio volumio[21620]: info: CorePlayQueue::getTrackBlock Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::volumioRetrievevolume Mar 24 18:36:00 volumio volumio[21620]: info: CoreStateMachine::setRepeat null single undefined Mar 24 18:36:00 volumio volumio[21620]: info: CoreStateMachine::pushState Mar 24 18:36:00 volumio volumio[21620]: info: CorePlayQueue::getTrack 0 Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::volumioPushState Mar 24 18:36:00 volumio volumio[21620]: info: CoreStateMachine::setRandom true Mar 24 18:36:00 volumio volumio[21620]: info: CoreStateMachine::pushState Mar 24 18:36:00 volumio volumio[21620]: info: CorePlayQueue::getTrack 0 Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::volumioPushState Mar 24 18:36:00 volumio volumio[21620]: info: Setting Device type: Raspberry PI Mar 24 18:36:00 volumio volumio[21620]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Mar 24 18:36:00 volumio volumio[21620]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04170 Mar 24 18:36:00 volumio volumio[21620]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Mar 24 18:36:00 volumio volumio[21620]: info: Completed loading Core Plugins Mar 24 18:36:00 volumio volumio[21620]: info: Preparing to generate the ALSA configuration file Mar 24 18:36:00 volumio volumio[21702]: Starting albumart workers Mar 24 18:36:00 volumio volumio[21620]: info: Asound.conf file unchanged, so no further update is needed Mar 24 18:36:00 volumio volumio[21620]: info: Output device has changed, restarting MPD Mar 24 18:36:00 volumio volumio[21620]: info: Output device has changed, restarting Shairport Sync Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:36:00 volumio sudo[21757]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 24 18:36:00 volumio sudo[21758]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 24 18:36:00 volumio sudo[21757]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:36:00 volumio sudo[21758]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:36:00 volumio sudo[21757]: pam_unix(sudo:session): session closed for user root Mar 24 18:36:00 volumio volumio[21703]: Starting albumart workers Mar 24 18:36:00 volumio volumio[21620]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 24 18:36:00 volumio volumio[21620]: info: ___________ START PLUGINS ___________ Mar 24 18:36:00 volumio volumio[21620]: info: ControllerMpd::onStart: Initializing MPD Mar 24 18:36:00 volumio volumio[21620]: info: Creating MPD Configuration file Mar 24 18:36:00 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 18:36:00 volumio volumio[21620]: info: [1774377360354] CoreMusicLibrary::Adding element Media Servers Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 18:36:00 volumio sudo[21766]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 24 18:36:00 volumio volumio[21620]: info: UPNP Browser: Client initialized successfully Mar 24 18:36:00 volumio sudo[21766]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:36:00 volumio sudo[21766]: pam_unix(sudo:session): session closed for user root Mar 24 18:36:00 volumio sudo[21768]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 24 18:36:00 volumio sudo[21768]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:36:00 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 24 18:36:00 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 24 18:36:00 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 24 18:36:00 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 24 18:36:00 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 24 18:36:00 volumio volumio[21620]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:36:00 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 24 18:36:00 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 24 18:36:00 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 24 18:36:00 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 24 18:36:00 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 24 18:36:00 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 24 18:36:00 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 24 18:36:00 volumio volumio[21620]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 18:36:00 volumio volumio[21620]: info: [1774377360437] CoreMusicLibrary::Adding element Last_100 Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 18:36:00 volumio volumio[21620]: info: [1774377360438] CoreMusicLibrary::Adding element Webradio Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 18:36:00 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 24 18:36:00 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 24 18:36:00 volumio volumio[21620]: info: Initializing BBC Radios Mar 24 18:36:00 volumio go-librespot[21721]: time="2026-03-24T18:36:00Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 24 18:36:00 volumio go-librespot[21721]: time="2026-03-24T18:36:00Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 24 18:36:00 volumio go-librespot[21721]: time="2026-03-24T18:36:00Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 24 18:36:00 volumio volumio[21704]: Starting albumart workers Mar 24 18:36:00 volumio go-librespot[21721]: time="2026-03-24T18:36:00Z" level=info msg="zeroconf server listening on port 38665" Mar 24 18:36:00 volumio sudo[21782]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 24 18:36:00 volumio sudo[21782]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 24 18:36:00 volumio sudo[21782]: pam_unix(sudo:session): session closed for user root Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:36:00 volumio volumio[21620]: info: Creating Spotify config file Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 18:36:00 volumio volumio[21620]: info: [1774377360707] CoreMusicLibrary::Adding element YouTube Music Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 18:36:00 volumio volumio[21620]: Cannot find translation for source YouTube Music Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 18:36:00 volumio volumio[21620]: info: [1774377360714] CoreMusicLibrary::Adding element Podcast Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 18:36:00 volumio volumio[21620]: Cannot find translation for source YouTube Music Mar 24 18:36:00 volumio volumio[21620]: Cannot find translation for source Podcast Mar 24 18:36:00 volumio volumio[21620]: info: [RTL-SDR Radio] Starting plugin Mar 24 18:36:00 volumio volumio[21620]: info: [RTL-SDR Radio] Loaded i18n strings for language: en Mar 24 18:36:00 volumio volumio[21620]: info: Volumio Calling Home Mar 24 18:36:00 volumio volumio[21620]: info: [RTL-SDR Radio] snd-aloop already loaded Mar 24 18:36:00 volumio volumio[21620]: info: [RTL-SDR Radio] No stations database found, creating v2 Mar 24 18:36:00 volumio volumio[21620]: info: [RTL-SDR Radio] Database loaded at: 2026-03-24T18:36:00.756Z Mar 24 18:36:00 volumio volumio[21620]: info: [RTL-SDR Radio] Loading blocklist from: /data/plugins/music_service/rtlsdr_radio/blocklist.json Mar 24 18:36:00 volumio volumio[21620]: info: [RTL-SDR Radio] Got 21 phrases from file Mar 24 18:36:00 volumio volumio[21620]: info: [RTL-SDR Radio] Updated metadata blocklist Mar 24 18:36:00 volumio volumio[21620]: info: [RTL-SDR Radio] Metadata module now has 21 phrases Mar 24 18:36:00 volumio volumio[21620]: info: [RTL-SDR Radio] Management server started on port 3456 Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 18:36:00 volumio volumio[21620]: info: [1774377360788] CoreMusicLibrary::Adding element FM/DAB Radio Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 18:36:00 volumio volumio[21620]: Cannot find translation for source YouTube Music Mar 24 18:36:00 volumio volumio[21620]: Cannot find translation for source Podcast Mar 24 18:36:00 volumio volumio[21620]: Cannot find translation for source FM/DAB Radio Mar 24 18:36:00 volumio volumio[21620]: info: [RTL-SDR Radio] Plugin started successfully Mar 24 18:36:00 volumio volumio[21620]: info: Discovery: adding 072f109f-54a2-4344-b8c4-538b45da7e51 Mar 24 18:36:00 volumio volumio[21620]: info: Discovery: Found device Volumio Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::volumioGetState Mar 24 18:36:00 volumio volumio[21620]: info: CorePlayQueue::getTrack 0 Mar 24 18:36:00 volumio volumio[21620]: info: Discovery: this is already registered, 072f109f-54a2-4344-b8c4-538b45da7e51 Mar 24 18:36:00 volumio volumio[21620]: info: Discovery: Found device Volumio Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::volumioGetState Mar 24 18:36:00 volumio volumio[21620]: info: CorePlayQueue::getTrack 0 Mar 24 18:36:00 volumio volumio[21620]: info: MPD Permissions set Mar 24 18:36:00 volumio volumio[21620]: info: MPD Permissions set Mar 24 18:36:00 volumio volumio[21620]: info: VolumeController:: Volume=36 Mute =true Mar 24 18:36:00 volumio volumio[21620]: info: CoreStateMachine::pushState Mar 24 18:36:00 volumio volumio[21620]: info: CorePlayQueue::getTrack 0 Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::volumioPushState Mar 24 18:36:00 volumio volumio[21620]: info: Spotify config file written Mar 24 18:36:00 volumio sudo[21826]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 24 18:36:00 volumio sudo[21826]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:36:00 volumio volumio[21620]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:36:00 volumio go-librespot[21721]: time="2026-03-24T18:36:00Z" level=debug msg="obtained new client token: AAB27fEVf4Pm/By46EaKMiU/MXb2y0QtyL+lZl3i+v+KUq0B7UahhIk9JJZvXUukZ5kb1glOS4XRfErCy3np5ZDJE3YeAMNBVcsKg7M0T/6sC6v0JOQNFxQok9SeAjt7uegvHhEQkR2OQ9x1jqQ74SwTcvDju3nZMVJl3MIxaWrUsLlgKBHwPWXqtfsK03hF7WteBhSzeUmPtvBQ1ner+LFtjuXj40L+SDH1TRYbU0EAaSwV/l4tJPMl5A==" Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:36:00 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 24 18:36:00 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 24 18:36:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 18:36:00 volumio volumio[21620]: info: No need to fix Spotify hosts Mar 24 18:36:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 18:36:00 volumio go-librespot[21833]: go-librespot daemon starting... Mar 24 18:36:00 volumio sudo[21826]: pam_unix(sudo:session): session closed for user root Mar 24 18:36:00 volumio go-librespot[21839]: time="2026-03-24T18:36:00Z" level=info msg="running go-librespot 0.6.2" Mar 24 18:36:00 volumio go-librespot[21839]: time="2026-03-24T18:36:00Z" level=debug msg="app state loaded" Mar 24 18:36:00 volumio go-librespot[21839]: time="2026-03-24T18:36:00Z" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 18:36:00 volumio volumio[21620]: info: Starting Shairport Sync Mar 24 18:36:00 volumio volumio[21620]: info: Starting Shairport Sync Mar 24 18:36:00 volumio volumio[21620]: info: Starting Shairport Sync Mar 24 18:36:00 volumio sudo[21846]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 18:36:00 volumio sudo[21846]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:36:00 volumio sudo[21848]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 18:36:00 volumio sudo[21848]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:36:00 volumio sudo[21851]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 18:36:00 volumio sudo[21851]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:36:00 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 24 18:36:00 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Mar 24 18:36:00 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 18:36:00 volumio systemd[1]: shairport-sync.service: Consumed 1.544s CPU time. Mar 24 18:36:00 volumio volumio[21620]: info: CoreCommandRouter::volumioGetState Mar 24 18:36:00 volumio volumio[21620]: info: CorePlayQueue::getTrack 0 Mar 24 18:36:00 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 18:36:00 volumio sudo[21846]: pam_unix(sudo:session): session closed for user root Mar 24 18:36:00 volumio volumio[21620]: info: Shairport-Sync Started Mar 24 18:36:00 volumio volumio[21620]: Error adding Membership: Error: addMembership EINVAL Mar 24 18:36:00 volumio sudo[21848]: pam_unix(sudo:session): session closed for user root Mar 24 18:36:00 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 24 18:36:00 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Mar 24 18:36:00 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 18:36:00 volumio volumio[21620]: info: Shairport-Sync Started Mar 24 18:36:00 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 18:36:00 volumio sudo[21851]: pam_unix(sudo:session): session closed for user root Mar 24 18:36:00 volumio volumio[21620]: info: Shairport-Sync Started Mar 24 18:36:01 volumio volumio[21620]: info: Volumio called home Mar 24 18:36:01 volumio mpd[21795]: 2026-03-24T18:36:01 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 24 18:36:01 volumio systemd[1]: Started mpd.service - Music Player Daemon. Mar 24 18:36:01 volumio sudo[21768]: pam_unix(sudo:session): session closed for user root Mar 24 18:36:01 volumio sudo[21758]: pam_unix(sudo:session): session closed for user root Mar 24 18:36:01 volumio volumio[21620]: info: Completed starting Core Plugins Mar 24 18:36:01 volumio volumio[21620]: info: ------------------------------------------- Mar 24 18:36:01 volumio volumio[21620]: info: ----- MyVolumio plugins startup ---- Mar 24 18:36:01 volumio volumio[21620]: info: ------------------------------------------- Mar 24 18:36:01 volumio volumio[21620]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 24 18:36:01 volumio volumio[21620]: error: MPD error: The expression evaluated to a falsy value: Mar 24 18:36:01 volumio volumio[21620]: assert.ok(self.idling) Mar 24 18:36:01 volumio volumio[21620]: error: The expression evaluated to a falsy value: Mar 24 18:36:01 volumio volumio[21620]: assert.ok(self.idling) Mar 24 18:36:01 volumio volumio[21620]: info: MPD running with PID21795 Mar 24 18:36:01 volumio volumio[21620]: ,establishing connection Mar 24 18:36:01 volumio volumio[21620]: error: updateQueue error: null Mar 24 18:36:01 volumio volumio[21620]: error: updateQueue error: null Mar 24 18:36:01 volumio volumio[21620]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 24 18:36:01 volumio go-librespot[21839]: time="2026-03-24T18:36:01Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 18:36:01 volumio go-librespot[21839]: time="2026-03-24T18:36:01Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 24 18:36:01 volumio go-librespot[21839]: time="2026-03-24T18:36:01Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 24 18:36:01 volumio go-librespot[21839]: time="2026-03-24T18:36:01Z" level=info msg="zeroconf server listening on port 33465" Mar 24 18:36:02 volumio go-librespot[21839]: time="2026-03-24T18:36:02Z" level=debug msg="obtained new client token: AAC/GlYBWZ9gi3G5DDYdjwSTf9pM8iwxhO6xpcWP9QtRIJCdG7ZQoZuw07V6+hXu9ZYV4GlZZ70Gojh35ZhS0eYSxu5a6GSnuqDcaw1KPOM4XoR9kulnBwXUfHkVgFt7zrKY5w3lpeT3nhjbD9bXwNrlJWkR/NNwVlaoEo227b9wFEGOuxzaHkozACJpSPWjwQM41iwnYH/SGVrejPz0I7wqOYNrR8Mvb+lQoPvxuLr0m0Yn5eW9WDRwCA==" Mar 24 18:36:02 volumio go-librespot[21839]: time="2026-03-24T18:36:02Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Mar 24 18:36:02 volumio go-librespot[21839]: time="2026-03-24T18:36:02Z" level=debug msg="completed keyexchange" Mar 24 18:36:02 volumio go-librespot[21839]: time="2026-03-24T18:36:02Z" level=debug msg="completed challenge" Mar 24 18:36:02 volumio volumio-remote-updater[945]: [2026-03-24 18:36:02] [connect] Successful connection Mar 24 18:36:02 volumio volumio-remote-updater[945]: [2026-03-24 18:36:02] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774377362 101 Mar 24 18:36:02 volumio go-librespot[21839]: time="2026-03-24T18:36:02Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:36:02 volumio volumio[21620]: 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: 2 Mar 24 18:36:02 volumio sudo[21657]: pam_unix(sudo:session): session closed for user root Mar 24 18:36:02 volumio go-librespot[21839]: time="2026-03-24T18:36:02Z" level=debug msg="connected to ap-gew1.spotify.com:443" Mar 24 18:36:02 volumio go-librespot[21839]: time="2026-03-24T18:36:02Z" level=debug msg="completed keyexchange" Mar 24 18:36:02 volumio go-librespot[21839]: time="2026-03-24T18:36:02Z" level=debug msg="completed challenge" Mar 24 18:36:02 volumio go-librespot[21839]: time="2026-03-24T18:36:02Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:36:03 volumio go-librespot[21839]: time="2026-03-24T18:36:03Z" level=warning msg="failed to connect to AP ap-gew1.spotify.com:80, retrying with a different AP" error="dial tcp 104.199.65.9:80: connect: connection refused" Mar 24 18:36:03 volumio go-librespot[21839]: time="2026-03-24T18:36:03Z" level=debug msg="connected to ap-guc3.spotify.com:4070" Mar 24 18:36:03 volumio go-librespot[21839]: time="2026-03-24T18:36:03Z" level=debug msg="completed keyexchange" Mar 24 18:36:03 volumio go-librespot[21839]: time="2026-03-24T18:36:03Z" level=debug msg="completed challenge" Mar 24 18:36:03 volumio go-librespot[21839]: time="2026-03-24T18:36:03Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:36:03 volumio volumio[21620]: info: go-librespot daemon successfully initialized Mar 24 18:36:04 volumio go-librespot[21839]: time="2026-03-24T18:36:04Z" level=warning msg="failed to connect to AP ap-gew4.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.1.133:443: connect: connection refused" Mar 24 18:36:04 volumio go-librespot[21839]: time="2026-03-24T18:36:04Z" level=debug msg="connected to ap-gae2.spotify.com:80" Mar 24 18:36:04 volumio go-librespot[21839]: time="2026-03-24T18:36:04Z" level=debug msg="completed keyexchange" Mar 24 18:36:04 volumio go-librespot[21839]: time="2026-03-24T18:36:04Z" level=debug msg="completed challenge" Mar 24 18:36:05 volumio go-librespot[21839]: time="2026-03-24T18:36:05Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:36:05 volumio go-librespot[21839]: time="2026-03-24T18:36:05Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Mar 24 18:36:05 volumio go-librespot[21839]: time="2026-03-24T18:36:05Z" level=debug msg="completed keyexchange" Mar 24 18:36:05 volumio go-librespot[21839]: time="2026-03-24T18:36:05Z" level=debug msg="completed challenge" Mar 24 18:36:05 volumio go-librespot[21839]: time="2026-03-24T18:36:05Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:36:06 volumio go-librespot[21839]: time="2026-03-24T18:36:06Z" level=debug msg="connected to ap-gew1.spotify.com:443" Mar 24 18:36:06 volumio go-librespot[21839]: time="2026-03-24T18:36:06Z" level=debug msg="completed keyexchange" Mar 24 18:36:06 volumio go-librespot[21839]: time="2026-03-24T18:36:06Z" level=debug msg="completed challenge" Mar 24 18:36:06 volumio go-librespot[21839]: time="2026-03-24T18:36:06Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:36:06 volumio go-librespot[21839]: time="2026-03-24T18:36:06Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:36:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 18:36:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 18:36:06 volumio volumio[21620]: info: Initializing connection to go-librespot Websocket Mar 24 18:36:06 volumio volumio[21620]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 18:36:08 volumio sudo[21905]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 24 18:36:08 volumio sudo[21905]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:36:08 volumio sudo[21907]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 24 18:36:08 volumio sudo[21905]: pam_unix(sudo:session): session closed for user root Mar 24 18:36:08 volumio sudo[21907]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:36:08 volumio sudo[21907]: pam_unix(sudo:session): session closed for user root Mar 24 18:36:08 volumio sudo[21911]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 24 18:36:08 volumio sudo[21911]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:36:08 volumio sudo[21911]: pam_unix(sudo:session): session closed for user root Mar 24 18:36:08 volumio volumio[21620]: info: Upmpdcli Daemon Started Mar 24 18:36:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 24 18:36:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 18:36:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 18:36:09 volumio go-librespot[21913]: go-librespot daemon starting... Mar 24 18:36:09 volumio go-librespot[21914]: time="2026-03-24T18:36:09Z" level=info msg="running go-librespot 0.6.2" Mar 24 18:36:09 volumio go-librespot[21914]: time="2026-03-24T18:36:09Z" level=debug msg="app state loaded" Mar 24 18:36:09 volumio go-librespot[21914]: time="2026-03-24T18:36:09Z" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 18:36:09 volumio go-librespot[21914]: time="2026-03-24T18:36:09Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 18:36:09 volumio go-librespot[21914]: time="2026-03-24T18:36:09Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 24 18:36:09 volumio go-librespot[21914]: time="2026-03-24T18:36:09Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 24 18:36:09 volumio go-librespot[21914]: time="2026-03-24T18:36:09Z" level=info msg="zeroconf server listening on port 39265" Mar 24 18:36:09 volumio volumio[21620]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 24 18:36:09 volumio volumio[21620]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 24 18:36:09 volumio volumio[21620]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 24 18:36:09 volumio volumio[21620]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 24 18:36:09 volumio volumio[21620]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 24 18:36:09 volumio volumio[21620]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 24 18:36:09 volumio volumio[21620]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 24 18:36:09 volumio volumio[21620]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 24 18:36:09 volumio volumio[21620]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 24 18:36:09 volumio volumio[21620]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 24 18:36:09 volumio volumio[21620]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 24 18:36:09 volumio volumio[21620]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 24 18:36:09 volumio volumio[21620]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 24 18:36:09 volumio volumio[21620]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 24 18:36:09 volumio volumio[21620]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 24 18:36:09 volumio volumio[21620]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 24 18:36:09 volumio volumio[21620]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 24 18:36:09 volumio volumio[21620]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 24 18:36:09 volumio volumio[21620]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 24 18:36:09 volumio volumio[21620]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 24 18:36:09 volumio volumio[21620]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 24 18:36:09 volumio volumio[21620]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 24 18:36:09 volumio volumio[21620]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 24 18:36:09 volumio volumio[21620]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 24 18:36:09 volumio volumio[21620]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 24 18:36:09 volumio volumio[21620]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 24 18:36:09 volumio volumio[21620]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 24 18:36:09 volumio volumio[21620]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 24 18:36:09 volumio volumio[21620]: info: Adding plugin bluetooth to MyMusic Plugins Mar 24 18:36:09 volumio volumio[21620]: info: Adding plugin multiroom to MyMusic Plugins Mar 24 18:36:09 volumio volumio[21620]: info: Adding plugin metavolumio to MyMusic Plugins Mar 24 18:36:09 volumio volumio[21620]: info: Adding plugin cd_controller to MyMusic Plugins Mar 24 18:36:09 volumio volumio[21620]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 24 18:36:09 volumio volumio[21620]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 24 18:36:09 volumio volumio[21620]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 24 18:36:09 volumio volumio[21620]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 24 18:36:09 volumio go-librespot[21914]: time="2026-03-24T18:36:09Z" level=debug msg="obtained new client token: AACsPNfwq9zBlrF1ETyQxgel5l6cZ75eDblH2uLIzIlV+Sc8ZtM2zl1NrFN23Q3/8mo1rdK86oO2S1yM1/4PfcC7MKGFyYty/5J94dXHwBqQ35oPFo8HLPSheTOqtIMG4OJsK9LuDL4VI6G2mu5P5NO3M/IJYvWU6v4vE4z98nSaoO8MbPIrV7YhJd1etcPIYW6OLDa8W5hqY7PNyrirUGHFzTsNt4sTOw4+y8qIoCwBvgnck4iDgkOIuA==" Mar 24 18:36:09 volumio go-librespot[21914]: time="2026-03-24T18:36:09Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Mar 24 18:36:09 volumio go-librespot[21914]: time="2026-03-24T18:36:09Z" level=debug msg="completed keyexchange" Mar 24 18:36:09 volumio go-librespot[21914]: time="2026-03-24T18:36:09Z" level=debug msg="completed challenge" Mar 24 18:36:09 volumio go-librespot[21914]: time="2026-03-24T18:36:09Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:36:09 volumio volumio[21620]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 24 18:36:09 volumio volumio[21620]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 24 18:36:09 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:36:09 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:36:09 volumio volumio[21620]: info: Starting MyVolumio Remote Streaming Endpoints Mar 24 18:36:09 volumio volumio[21620]: info: MyVolumio login type: Token Mar 24 18:36:09 volumio volumio[21620]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 24 18:36:09 volumio volumio[21620]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 24 18:36:10 volumio volumio[21620]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 24 18:36:10 volumio volumio[21620]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 24 18:36:10 volumio volumio[21620]: info: Streaming services startup Mar 24 18:36:10 volumio volumio[21620]: info: Starting Streaming Daemon Mar 24 18:36:10 volumio sudo[21924]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 24 18:36:10 volumio sudo[21924]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:36:10 volumio volumio[21620]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 24 18:36:10 volumio sudo[21924]: pam_unix(sudo:session): session closed for user root Mar 24 18:36:10 volumio volumio[21620]: info: Initializing connection to go-librespot Websocket Mar 24 18:36:10 volumio volumio[21620]: error: Cannot start Volumio Streaming Daemon Mar 24 18:36:10 volumio volumio[21620]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 24 18:36:10 volumio volumio[21620]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 24 18:36:10 volumio go-librespot[21914]: time="2026-03-24T18:36:10Z" level=debug msg="new websocket client" Mar 24 18:36:10 volumio volumio[21620]: info: Connection to go-librespot Websocket established Mar 24 18:36:10 volumio go-librespot[21914]: time="2026-03-24T18:36:10Z" level=debug msg="connected to ap-gew1.spotify.com:443" Mar 24 18:36:10 volumio go-librespot[21914]: time="2026-03-24T18:36:10Z" level=debug msg="completed keyexchange" Mar 24 18:36:10 volumio go-librespot[21914]: time="2026-03-24T18:36:10Z" level=debug msg="completed challenge" Mar 24 18:36:10 volumio go-librespot[21914]: time="2026-03-24T18:36:10Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:36:10 volumio volumio[21620]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 24 18:36:10 volumio volumio[21620]: info: MyVolumio token set successfully Mar 24 18:36:10 volumio volumio[21620]: info: MYVOLUMIO: Adding device Mar 24 18:36:10 volumio volumio[21620]: info: MYVOLUMIO: Evaluating Server Mar 24 18:36:10 volumio go-librespot[21914]: time="2026-03-24T18:36:10Z" level=debug msg="connected to ap-gew1.spotify.com:80" Mar 24 18:36:10 volumio go-librespot[21914]: time="2026-03-24T18:36:10Z" level=debug msg="completed keyexchange" Mar 24 18:36:10 volumio go-librespot[21914]: time="2026-03-24T18:36:10Z" level=debug msg="completed challenge" Mar 24 18:36:10 volumio go-librespot[21914]: time="2026-03-24T18:36:10Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:36:10 volumio volumio[21620]: info: MyVolumio status changed Mar 24 18:36:10 volumio volumio[21620]: info: Streaming services startup Mar 24 18:36:10 volumio volumio[21620]: info: Starting Streaming Daemon Mar 24 18:36:10 volumio volumio[21620]: info: Removing browser output: myVolumio user plan is not superstar Mar 24 18:36:10 volumio volumio[21620]: info: Removing audio output: Mar 24 18:36:10 volumio volumio[21620]: info: Stoppping Tunnel 1 Mar 24 18:36:11 volumio sudo[21951]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 24 18:36:11 volumio sudo[21951]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:36:11 volumio sudo[21953]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Mar 24 18:36:11 volumio sudo[21953]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 18:36:11 volumio sudo[21951]: pam_unix(sudo:session): session closed for user root Mar 24 18:36:11 volumio volumio[21620]: error: Cannot start Volumio Streaming Daemon Mar 24 18:36:11 volumio volumio[21620]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 24 18:36:11 volumio volumio[21620]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 24 18:36:11 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 18:36:11 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 18:36:11 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 18:36:11 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 18:36:11 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 18:36:11 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 18:36:11 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 18:36:11 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 18:36:11 volumio sudo[21953]: pam_unix(sudo:session): session closed for user root Mar 24 18:36:11 volumio volumio[21620]: info: Remote SSH Stopped Mar 24 18:36:11 volumio volumio[21620]: info: Setting Geolocation for MyVolumio to eu3 Mar 24 18:36:11 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:36:11 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:36:11 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:36:11 volumio volumio[21620]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Mar 24 18:36:11 volumio go-librespot[21914]: time="2026-03-24T18:36:11Z" level=debug msg="connected to ap-gue1.spotify.com:4070" Mar 24 18:36:11 volumio go-librespot[21914]: time="2026-03-24T18:36:11Z" level=debug msg="completed keyexchange" Mar 24 18:36:11 volumio go-librespot[21914]: time="2026-03-24T18:36:11Z" level=debug msg="completed challenge" Mar 24 18:36:11 volumio go-librespot[21914]: time="2026-03-24T18:36:11Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:36:12 volumio volumio[21620]: info: Updating MyVolumio device info Mar 24 18:36:12 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:36:12 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:36:12 volumio volumio[21620]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 18:36:12 volumio go-librespot[21914]: time="2026-03-24T18:36:12Z" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 24 18:36:12 volumio go-librespot[21914]: time="2026-03-24T18:36:12Z" level=debug msg="completed keyexchange" Mar 24 18:36:12 volumio go-librespot[21914]: time="2026-03-24T18:36:12Z" level=debug msg="completed challenge" Mar 24 18:36:12 volumio go-librespot[21914]: time="2026-03-24T18:36:12Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:36:12 volumio volumio[21620]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Mar 24 18:36:13 volumio go-librespot[21914]: time="2026-03-24T18:36:13Z" level=warning msg="failed to connect to AP ap-gae2.spotify.com:80, retrying with a different AP" error="dial tcp 104.199.241.202:80: connect: connection refused" Mar 24 18:36:13 volumio go-librespot[21914]: time="2026-03-24T18:36:13Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Mar 24 18:36:13 volumio go-librespot[21914]: time="2026-03-24T18:36:13Z" level=debug msg="completed keyexchange" Mar 24 18:36:13 volumio go-librespot[21914]: time="2026-03-24T18:36:13Z" level=debug msg="completed challenge" Mar 24 18:36:13 volumio volumio[21620]: info: Getting Spotify volume Mar 24 18:36:13 volumio volumio[21620]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Mar 24 18:36:13 volumio go-librespot[21914]: time="2026-03-24T18:36:13Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:36:13 volumio go-librespot[21914]: time="2026-03-24T18:36:13Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 18:36:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 18:36:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 18:36:13 volumio volumio[21620]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 18:36:13 volumio volumio[21620]: Error: socket hang up Mar 24 18:36:13 volumio volumio[21620]: at connResetException (node:internal/errors:720:14) Mar 24 18:36:13 volumio volumio[21620]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 24 18:36:13 volumio volumio[21620]: at Socket.emit (node:events:526:35) Mar 24 18:36:13 volumio volumio[21620]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 24 18:36:13 volumio volumio[21620]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 24 18:36:13 volumio volumio[21620]: code: 'ECONNRESET', Mar 24 18:36:13 volumio volumio[21620]: response: undefined Mar 24 18:36:13 volumio volumio[21620]: } Mar 24 18:36:13 volumio volumio[21620]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 18:36:13 volumio sudo[21970]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-24 18:35' Mar 24 18:36:13 volumio sudo[21970]: 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="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"