Mar 04 19:08:00 loe go-librespot[1565]: time="2026-03-04T19:08:00+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 19:08:00 loe go-librespot[1565]: time="2026-03-04T19:08:00+01:00" level=debug msg="app state loaded" Mar 04 19:08:00 loe go-librespot[1565]: time="2026-03-04T19:08:00+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 19:08:01 loe go-librespot[1565]: time="2026-03-04T19:08:01+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 19:08:01 loe go-librespot[1565]: time="2026-03-04T19:08:01+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 19:08:01 loe go-librespot[1565]: time="2026-03-04T19:08:01+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 19:08:01 loe go-librespot[1565]: time="2026-03-04T19:08:01+01:00" level=info msg="zeroconf server listening on port 46821" Mar 04 19:08:01 loe go-librespot[1565]: time="2026-03-04T19:08:01+01:00" level=debug msg="obtained new client token: AADIO9Fa61wH6WZxVJYGsP4mvQvgvlr22HCQGHaB5IwpqyynAQJJvsnKe6gu9h2cDjYy3qv4+XGsRb067/OsOQYH4j7q3D5HBJHrcECEMye/uqFg8VIYLdJiMvsyTQR58vsQ+5bBcpDGa4qhSyL5f+o11qgL6ivGt6sWctJzRuT82ReItlpHhc+Z1XcoDZRe6n1XOPUY+QsmFh2A2DOBzhQZ/V0d9LGio+jN9DX6YHS5DVM+f2HJiDj9aw==" Mar 04 19:08:01 loe go-librespot[1565]: time="2026-03-04T19:08:01+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 19:08:01 loe go-librespot[1565]: time="2026-03-04T19:08:01+01:00" level=debug msg="completed keyexchange" Mar 04 19:08:01 loe go-librespot[1565]: time="2026-03-04T19:08:01+01:00" level=debug msg="completed challenge" Mar 04 19:08:01 loe go-librespot[1565]: time="2026-03-04T19:08:01+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 19:08:01 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 19:08:01 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 19:08:04 loe volumio[1260]: error: MPD error: The expression evaluated to a falsy value: Mar 04 19:08:04 loe volumio[1260]: assert.ok(self.idling) Mar 04 19:08:04 loe volumio[1260]: error: The expression evaluated to a falsy value: Mar 04 19:08:04 loe volumio[1260]: assert.ok(self.idling) Mar 04 19:08:04 loe volumio5-onboarding[1548]: failed to create app: failed to initialize host: failed to create socket connection: could not connect to socket.io server: read tcp 127.0.0.1:51924->127.0.0.1:3000: i/o timeout Mar 04 19:08:04 loe systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 04 19:08:04 loe systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 04 19:08:04 loe systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 2. Mar 04 19:08:04 loe systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 04 19:08:04 loe systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 04 19:08:04 loe volumio5-onboarding[1586]: time=2026-03-04T19:08:04.751+01:00 level=INFO msg="running volumio5-device-gateway" version=30d1950e+CHANGES buildDate=2026-01-29T13:10:08Z Mar 04 19:08:04 loe volumio[1260]: info: MPD running with PID1521 Mar 04 19:08:04 loe volumio[1260]: ,establishing connection Mar 04 19:08:04 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 04 19:08:04 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:08:04 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 19:08:04 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 19:08:04 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 19:08:04 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 19:08:04 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:08:04 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 19:08:04 loe go-librespot[1593]: go-librespot daemon starting... Mar 04 19:08:04 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 19:08:04 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 19:08:04 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 19:08:05 loe go-librespot[1594]: time="2026-03-04T19:08:05+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 19:08:05 loe go-librespot[1594]: time="2026-03-04T19:08:05+01:00" level=debug msg="app state loaded" Mar 04 19:08:05 loe go-librespot[1594]: time="2026-03-04T19:08:05+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 19:08:05 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 19:08:05 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 19:08:05 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 19:08:05 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 19:08:05 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 19:08:05 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 19:08:05 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 19:08:05 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 19:08:05 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 19:08:05 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 19:08:05 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 19:08:05 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 19:08:05 loe volumio[1260]: info: No need to fix Spotify hosts Mar 04 19:08:05 loe go-librespot[1594]: time="2026-03-04T19:08:05+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 19:08:05 loe go-librespot[1594]: time="2026-03-04T19:08:05+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 19:08:05 loe go-librespot[1594]: time="2026-03-04T19:08:05+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 19:08:05 loe go-librespot[1594]: time="2026-03-04T19:08:05+01:00" level=info msg="zeroconf server listening on port 34363" Mar 04 19:08:05 loe go-librespot[1594]: time="2026-03-04T19:08:05+01:00" level=debug msg="obtained new client token: AACRo6eHU9xjqBcccGB6m6rW+PP4gYoSvrmcgZ/mNR+VNkT7UxBQ1+Cq/lCWVHjYD3QFyBVukfr0jC6uS3i1zgsLiYL5JtXvP4aJi/wxj2mpXQYCNcKWCCPa5ZvbYTZPQC2fWCxW6irGVjZrqy3DnSO6c7kpFGWz4JAiGacfmNTuSlb0502KOojHC2ropV9nnYDvMdtiJsrtvj3WjD+hHIDCG5pADCKRQLJZ13i/TkhaHROCo5EsU8CKvQ==" Mar 04 19:08:05 loe go-librespot[1594]: time="2026-03-04T19:08:05+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 19:08:05 loe go-librespot[1594]: time="2026-03-04T19:08:05+01:00" level=debug msg="completed keyexchange" Mar 04 19:08:05 loe go-librespot[1594]: time="2026-03-04T19:08:05+01:00" level=debug msg="completed challenge" Mar 04 19:08:06 loe go-librespot[1594]: time="2026-03-04T19:08:06+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 19:08:06 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 19:08:06 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 19:08:06 loe volumio[1260]: error: updateQueue error: null Mar 04 19:08:07 loe ntpd[876]: CLOCK: time stepped by 1.029940 Mar 04 19:08:07 loe ntpd[876]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Mar 04 19:08:07 loe volumio[1260]: 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 04 19:08:08 loe volumio[1260]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 04 19:08:08 loe volumio[1260]: error: updateQueue error: null Mar 04 19:08:08 loe volumio[1260]: info: Starting Shairport Sync Mar 04 19:08:08 loe volumio[1260]: info: Starting Shairport Sync Mar 04 19:08:08 loe volumio[1260]: info: Starting Shairport Sync Mar 04 19:08:08 loe sudo[1634]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 19:08:08 loe sudo[1634]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 19:08:08 loe volumio[1260]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Mar 04 19:08:08 loe sudo[1632]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 19:08:08 loe sudo[1632]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 19:08:09 loe sudo[1636]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 19:08:09 loe sudo[1636]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 19:08:09 loe volumio[1260]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Mar 04 19:08:09 loe systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 04 19:08:09 loe systemd[1]: shairport-sync.service: Deactivated successfully. Mar 04 19:08:09 loe systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 19:08:09 loe systemd[1]: shairport-sync.service: Consumed 3.011s CPU time. Mar 04 19:08:09 loe systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 19:08:09 loe volumio[1260]: info: Received Get System Info Mar 04 19:08:09 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 04 19:08:09 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 04 19:08:09 loe sudo[1634]: pam_unix(sudo:session): session closed for user root Mar 04 19:08:09 loe systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 04 19:08:09 loe systemd[1]: shairport-sync.service: Deactivated successfully. Mar 04 19:08:09 loe systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 19:08:09 loe systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 19:08:09 loe sudo[1632]: pam_unix(sudo:session): session closed for user root Mar 04 19:08:09 loe volumio[1260]: info: Discovery: Getting this device information Mar 04 19:08:09 loe volumio[1260]: info: CoreCommandRouter::volumioGetState Mar 04 19:08:09 loe volumio[1260]: info: CorePlayQueue::getTrack 0 Mar 04 19:08:09 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 19:08:09 loe systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 04 19:08:09 loe systemd[1]: shairport-sync.service: Deactivated successfully. Mar 04 19:08:09 loe systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 19:08:09 loe volumio5-onboarding[1586]: time=2026-03-04T19:08:09.547+01:00 level=INFO msg="system info for a53384b16fd4d7a180fdac1b5068092c" deviceName=Loe deviceVariant=volumio deviceModel= softwareVersion=4.096 Mar 04 19:08:09 loe volumio[1260]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 04 19:08:09 loe systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 19:08:09 loe sudo[1636]: pam_unix(sudo:session): session closed for user root Mar 04 19:08:09 loe volumio[1260]: info: Received Get System Info Mar 04 19:08:09 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 04 19:08:09 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 04 19:08:09 loe volumio[1260]: info: Discovery: Getting this device information Mar 04 19:08:09 loe volumio[1260]: info: CoreCommandRouter::volumioGetState Mar 04 19:08:09 loe volumio[1260]: info: CorePlayQueue::getTrack 0 Mar 04 19:08:09 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 19:08:09 loe volumio[1260]: info: Shairport-Sync Started Mar 04 19:08:09 loe volumio[1260]: Error adding Membership: Error: addMembership EINVAL Mar 04 19:08:09 loe volumio[1260]: info: Shairport-Sync Started Mar 04 19:08:09 loe volumio[1260]: info: Shairport-Sync Started Mar 04 19:08:09 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 04 19:08:09 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 04 19:08:10 loe volumio5-onboarding[1586]: time=2026-03-04T19:08:10.029+01:00 level=INFO msg="enabling local network discovery" Mar 04 19:08:10 loe volumio5-onboarding[1586]: time=2026-03-04T19:08:10.086+01:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 04 19:08:10 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 04 19:08:10 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:08:10 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:08:10 loe go-librespot[1662]: go-librespot daemon starting... Mar 04 19:08:10 loe go-librespot[1663]: time="2026-03-04T19:08:10+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 19:08:10 loe go-librespot[1663]: time="2026-03-04T19:08:10+01:00" level=debug msg="app state loaded" Mar 04 19:08:10 loe go-librespot[1663]: time="2026-03-04T19:08:10+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 19:08:10 loe volumio[1260]: info: go-librespot daemon successfully initialized Mar 04 19:08:10 loe volumio[1260]: info: Received Get System Info Mar 04 19:08:10 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 04 19:08:10 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 04 19:08:10 loe volumio[1260]: info: Discovery: Getting this device information Mar 04 19:08:10 loe volumio[1260]: info: CoreCommandRouter::volumioGetState Mar 04 19:08:10 loe volumio[1260]: info: CorePlayQueue::getTrack 0 Mar 04 19:08:10 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 19:08:10 loe go-librespot[1663]: time="2026-03-04T19:08:10+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 19:08:10 loe go-librespot[1663]: time="2026-03-04T19:08:10+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 19:08:10 loe go-librespot[1663]: time="2026-03-04T19:08:10+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 19:08:11 loe go-librespot[1663]: time="2026-03-04T19:08:11+01:00" level=info msg="zeroconf server listening on port 34259" Mar 04 19:08:11 loe go-librespot[1663]: time="2026-03-04T19:08:11+01:00" level=debug msg="obtained new client token: AACqKxpdYLpFQ5vhraSOU7vXNiFFKvi+tcNhlBvDu2AriIwGAe+mWWE3j5wwPoBWuTLvmEotOmJgREk0ttB2/W3fPgaZtGImbWwtBwO4pWFpB3YUKzaOevScsvXKB2NbJeXe9bS+b5V570FvT1UnPmgu8X21RLHHctndQFZ2rBk5svimrLsSfUizpgJn5BrPL9os8Qo4LihdiWDBvyuhEh8SPSwz2OBSsiHHx/vRAPMeYotw7PGhSSk=" Mar 04 19:08:11 loe go-librespot[1663]: time="2026-03-04T19:08:11+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 19:08:11 loe go-librespot[1663]: time="2026-03-04T19:08:11+01:00" level=debug msg="completed keyexchange" Mar 04 19:08:11 loe go-librespot[1663]: time="2026-03-04T19:08:11+01:00" level=debug msg="completed challenge" Mar 04 19:08:11 loe go-librespot[1663]: time="2026-03-04T19:08:11+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 19:08:11 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 19:08:11 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 19:08:11 loe volumio[1260]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 04 19:08:11 loe volumio[1260]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 04 19:08:11 loe volumio[1260]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 04 19:08:11 loe volumio[1260]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 04 19:08:11 loe volumio[1260]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 04 19:08:11 loe volumio[1260]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 04 19:08:11 loe volumio[1260]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 04 19:08:11 loe volumio[1260]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 04 19:08:11 loe volumio[1260]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 04 19:08:11 loe volumio[1260]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 04 19:08:11 loe volumio[1260]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 04 19:08:11 loe volumio[1260]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 04 19:08:11 loe volumio[1260]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 04 19:08:11 loe volumio[1260]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 04 19:08:11 loe volumio[1260]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 04 19:08:11 loe volumio[1260]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 04 19:08:11 loe volumio[1260]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 04 19:08:11 loe volumio[1260]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 04 19:08:11 loe volumio[1260]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 04 19:08:11 loe volumio[1260]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 04 19:08:11 loe volumio[1260]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 04 19:08:11 loe volumio[1260]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 04 19:08:11 loe volumio[1260]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 04 19:08:11 loe volumio[1260]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 04 19:08:11 loe volumio[1260]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 04 19:08:11 loe volumio[1260]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 04 19:08:11 loe volumio[1260]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 04 19:08:11 loe volumio[1260]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 04 19:08:11 loe volumio[1260]: info: Adding plugin bluetooth to MyMusic Plugins Mar 04 19:08:11 loe volumio[1260]: info: Adding plugin multiroom to MyMusic Plugins Mar 04 19:08:11 loe volumio[1260]: info: Adding plugin metavolumio to MyMusic Plugins Mar 04 19:08:11 loe volumio[1260]: info: Adding plugin cd_controller to MyMusic Plugins Mar 04 19:08:11 loe volumio[1260]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 04 19:08:11 loe volumio[1260]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 04 19:08:11 loe volumio[1260]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 04 19:08:11 loe volumio[1260]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 04 19:08:14 loe volumio-remote-updater[708]: [2026-03-04 19:08:14] [connect] Successful connection Mar 04 19:08:14 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 04 19:08:14 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:08:14 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:08:14 loe go-librespot[1685]: go-librespot daemon starting... Mar 04 19:08:14 loe go-librespot[1686]: time="2026-03-04T19:08:14+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 19:08:15 loe go-librespot[1686]: time="2026-03-04T19:08:15+01:00" level=debug msg="app state loaded" Mar 04 19:08:15 loe go-librespot[1686]: time="2026-03-04T19:08:15+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 19:08:15 loe go-librespot[1686]: time="2026-03-04T19:08:15+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 19:08:15 loe go-librespot[1686]: time="2026-03-04T19:08:15+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 19:08:15 loe go-librespot[1686]: time="2026-03-04T19:08:15+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 19:08:15 loe go-librespot[1686]: time="2026-03-04T19:08:15+01:00" level=info msg="zeroconf server listening on port 35065" Mar 04 19:08:15 loe go-librespot[1686]: time="2026-03-04T19:08:15+01:00" level=debug msg="obtained new client token: AADEb3CUjhyhoVyeWED6lrXs7aRrsjhUp7uko1/8yLS1kOK4veXk7+Ui9AmwJ4ispbXxnDf1fmVDKwNvx5jDDu0WlkVjGB4GMTLWdo6rmF0nIDWsDB1hlSLONtKlLAnZho7m5pv3Ddp9N6Y77rCtX156bnQX/cBhR4ym3gDKEYTBiAg5dObUNEOsTSPdiIumsTknfQVYsXe8mtriiKjL8rBdkhWeQSVTV1wxgm+/a5ATb/6+BStHUvR7uQ==" Mar 04 19:08:15 loe go-librespot[1686]: time="2026-03-04T19:08:15+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 19:08:15 loe go-librespot[1686]: time="2026-03-04T19:08:15+01:00" level=debug msg="completed keyexchange" Mar 04 19:08:15 loe go-librespot[1686]: time="2026-03-04T19:08:15+01:00" level=debug msg="completed challenge" Mar 04 19:08:15 loe go-librespot[1686]: time="2026-03-04T19:08:15+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 19:08:15 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 19:08:15 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 19:08:19 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 04 19:08:19 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:08:19 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:08:19 loe go-librespot[1694]: go-librespot daemon starting... Mar 04 19:08:19 loe go-librespot[1695]: time="2026-03-04T19:08:19+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 19:08:19 loe go-librespot[1695]: time="2026-03-04T19:08:19+01:00" level=debug msg="app state loaded" Mar 04 19:08:19 loe go-librespot[1695]: time="2026-03-04T19:08:19+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 19:08:19 loe go-librespot[1695]: time="2026-03-04T19:08:19+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 19:08:19 loe go-librespot[1695]: time="2026-03-04T19:08:19+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 19:08:19 loe go-librespot[1695]: time="2026-03-04T19:08:19+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 19:08:19 loe go-librespot[1695]: time="2026-03-04T19:08:19+01:00" level=info msg="zeroconf server listening on port 36497" Mar 04 19:08:20 loe go-librespot[1695]: time="2026-03-04T19:08:20+01:00" level=debug msg="obtained new client token: AABPbhbRGaOeKZ6Jx3ayUe79prAezCOnV18f0cvwWGvD8Q0JgkUkw6Z9dPZ0QmJPecsTqPJYqvkl0n9bYJcMomSIvDx3Fuiwv7978ak4LBtlNVGTgWUGb7baz7KBwO7NaSa9i9YlsdosfP6VN4jNlmv5Qcs8S4lrgPbAJaZ8erzjm+ih99zmclu8vUdZOeGurquqWxVN4OMcgSd3e1u3LSGzNwy0vd4aNM9UhIrX4Y0Z6htPMfdA9Qg=" Mar 04 19:08:20 loe go-librespot[1695]: time="2026-03-04T19:08:20+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 19:08:20 loe go-librespot[1695]: time="2026-03-04T19:08:20+01:00" level=debug msg="completed keyexchange" Mar 04 19:08:20 loe go-librespot[1695]: time="2026-03-04T19:08:20+01:00" level=debug msg="completed challenge" Mar 04 19:08:20 loe go-librespot[1695]: time="2026-03-04T19:08:20+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 19:08:20 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 19:08:20 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 19:08:22 loe volumio[1260]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 04 19:08:22 loe volumio[1260]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 04 19:08:22 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 19:08:22 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 19:08:22 loe volumio[1260]: info: Starting MyVolumio Remote Streaming Endpoints Mar 04 19:08:22 loe volumio[1260]: info: MyVolumio login type: Token Mar 04 19:08:23 loe volumio[1260]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 04 19:08:23 loe volumio[1260]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 04 19:08:23 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Mar 04 19:08:23 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:08:23 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:08:23 loe go-librespot[1707]: go-librespot daemon starting... Mar 04 19:08:23 loe go-librespot[1712]: time="2026-03-04T19:08:23+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 19:08:23 loe go-librespot[1712]: time="2026-03-04T19:08:23+01:00" level=debug msg="app state loaded" Mar 04 19:08:23 loe go-librespot[1712]: time="2026-03-04T19:08:23+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 19:08:24 loe go-librespot[1712]: time="2026-03-04T19:08:24+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 19:08:24 loe go-librespot[1712]: time="2026-03-04T19:08:24+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 19:08:24 loe go-librespot[1712]: time="2026-03-04T19:08:24+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 19:08:24 loe go-librespot[1712]: time="2026-03-04T19:08:24+01:00" level=info msg="zeroconf server listening on port 35975" Mar 04 19:08:24 loe go-librespot[1712]: time="2026-03-04T19:08:24+01:00" level=debug msg="obtained new client token: AADR8OxGEQMpp+J3UbWxLPMnUOe3NqmZdQ2TvkiYvyBIuNB6AdowZJr4zvnQ/m2DYn5xDYA8RDHhjdSnBYfG3QezR6/dlC/y04zsYqPCgFEPCu4OEyVAXCU7jGYCc9DbggOxMHzLgN58iRG3LJqFhy2bWRbY1y4dRj175AJOkhu+iEqy2LCkNOcK9dyUGoJuqItROpal7Eccj/Qkjfc6/V3Vs0YaRc4G/O/njK+nfhpT20NRcc1AuX0=" Mar 04 19:08:24 loe go-librespot[1712]: time="2026-03-04T19:08:24+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Mar 04 19:08:24 loe go-librespot[1712]: time="2026-03-04T19:08:24+01:00" 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 04 19:08:24 loe go-librespot[1712]: time="2026-03-04T19:08:24+01:00" level=debug msg="connected to ap-gew4.spotify.com:80" Mar 04 19:08:24 loe go-librespot[1712]: time="2026-03-04T19:08:24+01:00" level=debug msg="completed keyexchange" Mar 04 19:08:24 loe go-librespot[1712]: time="2026-03-04T19:08:24+01:00" level=debug msg="completed challenge" Mar 04 19:08:24 loe go-librespot[1712]: time="2026-03-04T19:08:24+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 19:08:24 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 19:08:24 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 19:08:27 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Mar 04 19:08:27 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:08:27 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:08:27 loe go-librespot[1726]: go-librespot daemon starting... Mar 04 19:08:27 loe go-librespot[1727]: time="2026-03-04T19:08:27+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 19:08:27 loe go-librespot[1727]: time="2026-03-04T19:08:27+01:00" level=debug msg="app state loaded" Mar 04 19:08:27 loe go-librespot[1727]: time="2026-03-04T19:08:27+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 19:08:28 loe go-librespot[1727]: time="2026-03-04T19:08:28+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 19:08:28 loe go-librespot[1727]: time="2026-03-04T19:08:28+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 19:08:28 loe go-librespot[1727]: time="2026-03-04T19:08:28+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 19:08:28 loe go-librespot[1727]: time="2026-03-04T19:08:28+01:00" level=info msg="zeroconf server listening on port 43363" Mar 04 19:08:28 loe go-librespot[1727]: time="2026-03-04T19:08:28+01:00" level=debug msg="obtained new client token: AABlnrlzKz0Ajbdw2dBOz7RaoXNsNF9TOHXlk8bPUJzFzm0yBD8vEnwmFvcg0MHh6KHuosXU03USGgH4RGd7uPGfYwJfLq9iOazoXu8Wv88maXehFcX0LJ2SiK/qMsnxsWktzrLb/4QVc4Dad9HXIZtY69Mlw2gm1MbG/lqywk8JuGUPduLe4i8CID9uvW6HuTwtVlu/Ki9LDruJGLp5PKjFd+tR+9nlofN4UIG/hRW5vV8nzP9ueQP20Q==" Mar 04 19:08:28 loe go-librespot[1727]: time="2026-03-04T19:08:28+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 19:08:28 loe go-librespot[1727]: time="2026-03-04T19:08:28+01:00" level=debug msg="completed keyexchange" Mar 04 19:08:28 loe go-librespot[1727]: time="2026-03-04T19:08:28+01:00" level=debug msg="completed challenge" Mar 04 19:08:28 loe go-librespot[1727]: time="2026-03-04T19:08:28+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 19:08:28 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 19:08:28 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 19:08:29 loe volumio-remote-updater[708]: [2026-03-04 19:08:29] [connect] Successful connection Mar 04 19:08:31 loe volumio[1260]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 04 19:08:31 loe volumio[1260]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 04 19:08:31 loe volumio[1260]: info: Streaming services startup Mar 04 19:08:31 loe volumio[1260]: info: Starting Streaming Daemon Mar 04 19:08:31 loe volumio[1260]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 04 19:08:31 loe sudo[1736]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 04 19:08:31 loe sudo[1736]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 19:08:31 loe sudo[1736]: pam_unix(sudo:session): session closed for user root Mar 04 19:08:31 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Mar 04 19:08:31 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:08:32 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:08:32 loe go-librespot[1742]: go-librespot daemon starting... Mar 04 19:08:32 loe volumio[1260]: info: Initializing connection to go-librespot Websocket Mar 04 19:08:32 loe go-librespot[1743]: time="2026-03-04T19:08:32+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 19:08:32 loe go-librespot[1743]: time="2026-03-04T19:08:32+01:00" level=debug msg="app state loaded" Mar 04 19:08:32 loe go-librespot[1743]: time="2026-03-04T19:08:32+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 19:08:32 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 19:08:32 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 19:08:32 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 04 19:08:32 loe go-librespot[1743]: time="2026-03-04T19:08:32+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 04 19:08:32 loe go-librespot[1743]: time="2026-03-04T19:08:32+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 04 19:08:32 loe go-librespot[1743]: time="2026-03-04T19:08:32+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 04 19:08:32 loe go-librespot[1743]: time="2026-03-04T19:08:32+01:00" level=info msg="zeroconf server listening on port 33885" Mar 04 19:08:32 loe go-librespot[1743]: time="2026-03-04T19:08:32+01:00" level=debug msg="obtained new client token: AAD9hysJ5PrG/xdhh+BCHTqmGp20z/7zXfCg+uSRkTa3QEhK6Q2e13W2K5oYmp33J5QaZm6xu4Wkq+RJt5AH8aWzJR7qlXDfQ93nM+VMW5LYuH+ivQIMfQSIEi4O35/MAxzICx5QRyawd/01lPUWDkKD7grWs0YSwde4Uprg0dAg27EOImLSH6KBfg92ykFMHW6gIJiBGBQ0sNYmJ34P3HGj8IXSqtfK3uiRq/VnVD5RLlt4Lxg9aRJwtQ==" Mar 04 19:08:33 loe go-librespot[1743]: time="2026-03-04T19:08:33+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 19:08:33 loe volumio[1260]: error: Cannot start Volumio Streaming Daemon Mar 04 19:08:33 loe volumio[1260]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 04 19:08:33 loe volumio[1260]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 04 19:08:33 loe go-librespot[1743]: time="2026-03-04T19:08:33+01:00" level=debug msg="completed keyexchange" Mar 04 19:08:33 loe go-librespot[1743]: time="2026-03-04T19:08:33+01:00" level=debug msg="completed challenge" Mar 04 19:08:33 loe go-librespot[1743]: time="2026-03-04T19:08:33+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 19:08:33 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 19:08:33 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 19:08:33 loe volumio[1260]: info: Error connecting to go-librespot Websocket: Error: socket hang up Mar 04 19:08:34 loe volumio-remote-updater[708]: [2026-03-04 19:08:34] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1772647709 101 Mar 04 19:08:34 loe volumio[1260]: 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: 3 Mar 04 19:08:34 loe volumio[1260]: info: CoreCommandRouter::volumioGetState Mar 04 19:08:34 loe volumio[1260]: info: CorePlayQueue::getTrack 0 Mar 04 19:08:35 loe volumio[1260]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 04 19:08:36 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Mar 04 19:08:36 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:08:36 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:08:36 loe go-librespot[1768]: go-librespot daemon starting... Mar 04 19:08:36 loe go-librespot[1769]: time="2026-03-04T19:08:36+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 19:08:36 loe go-librespot[1769]: time="2026-03-04T19:08:36+01:00" level=debug msg="app state loaded" Mar 04 19:08:36 loe go-librespot[1769]: time="2026-03-04T19:08:36+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 19:08:37 loe go-librespot[1769]: time="2026-03-04T19:08:37+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 19:08:37 loe go-librespot[1769]: time="2026-03-04T19:08:37+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 19:08:37 loe go-librespot[1769]: time="2026-03-04T19:08:37+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 19:08:37 loe go-librespot[1769]: time="2026-03-04T19:08:37+01:00" level=info msg="zeroconf server listening on port 34625" Mar 04 19:08:37 loe go-librespot[1769]: time="2026-03-04T19:08:37+01:00" level=debug msg="obtained new client token: AACaAvgip0ov6mONmmIdvgdQysd/Cp9pwBa4V4m8G7+h6mNX5Hb+GJFZdc4oDpPXo7HEhHmTOpuFeXfwd+gQP6k6zO05UpHdngVsqVu5c/AeZFNX8YMHcMr2ftzlXgmAEzdEh5N5bqy6vfBcWklZv04KpYQ25wNrN55bmdgzSi2wOHob8mgi26BekrGulN0/MsSR5ZgdnR8gxiKvsB72gT+sdSIOpsUxxQ1FKLgibeenfybxgMwyt31D+A==" Mar 04 19:08:37 loe go-librespot[1769]: time="2026-03-04T19:08:37+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 19:08:37 loe go-librespot[1769]: time="2026-03-04T19:08:37+01:00" level=debug msg="completed keyexchange" Mar 04 19:08:37 loe go-librespot[1769]: time="2026-03-04T19:08:37+01:00" level=debug msg="completed challenge" Mar 04 19:08:37 loe go-librespot[1769]: time="2026-03-04T19:08:37+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 19:08:37 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 19:08:37 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 19:08:37 loe volumio-remote-updater[708]: Test mode disabled Mar 04 19:08:37 loe volumio-remote-updater[708]: Alpha mode disabled Mar 04 19:08:37 loe volumio-remote-updater[708]: Alpha legacy test mode disabled Mar 04 19:08:37 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Mar 04 19:08:37 loe volumio[1260]: info: Initializing connection to go-librespot Websocket Mar 04 19:08:38 loe volumio[1260]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 04 19:08:38 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 04 19:08:38 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 04 19:08:38 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 04 19:08:38 loe volumio[1260]: info: MyVolumio token set successfully Mar 04 19:08:38 loe volumio[1260]: info: MYVOLUMIO: Adding device Mar 04 19:08:38 loe volumio[1260]: info: MYVOLUMIO: Evaluating Server Mar 04 19:08:38 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 04 19:08:38 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 04 19:08:38 loe volumio[1260]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 19:08:40 loe volumio5-onboarding[1586]: failed to bootstrap state: failed to get music providers: could not get available plugins: could not get available plugins: context deadline exceeded Mar 04 19:08:40 loe systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 04 19:08:40 loe systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 04 19:08:40 loe volumio[1260]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Mar 04 19:08:40 loe volumio[1260]: info: MyVolumio Plan changed: premium Mar 04 19:08:40 loe volumio[1260]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Mar 04 19:08:40 loe volumio[1260]: info: Removing browser output: myVolumio user plan is not superstar Mar 04 19:08:40 loe systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 3. Mar 04 19:08:40 loe systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 04 19:08:40 loe volumio[1260]: info: Removing audio output: Mar 04 19:08:40 loe volumio[1260]: info: MYVOLUMIO: Adding device Mar 04 19:08:40 loe volumio[1260]: info: MYVOLUMIO: Evaluating Server Mar 04 19:08:40 loe systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 04 19:08:40 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Mar 04 19:08:40 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:08:40 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:08:40 loe go-librespot[1802]: go-librespot daemon starting... Mar 04 19:08:40 loe volumio5-onboarding[1798]: time=2026-03-04T19:08:40.678+01:00 level=INFO msg="running volumio5-device-gateway" version=30d1950e+CHANGES buildDate=2026-01-29T13:10:08Z Mar 04 19:08:40 loe go-librespot[1806]: time="2026-03-04T19:08:40+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 19:08:40 loe go-librespot[1806]: time="2026-03-04T19:08:40+01:00" level=debug msg="app state loaded" Mar 04 19:08:40 loe go-librespot[1806]: time="2026-03-04T19:08:40+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 19:08:41 loe go-librespot[1806]: time="2026-03-04T19:08:41+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 04 19:08:41 loe go-librespot[1806]: time="2026-03-04T19:08:41+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 04 19:08:41 loe go-librespot[1806]: time="2026-03-04T19:08:41+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 04 19:08:41 loe go-librespot[1806]: time="2026-03-04T19:08:41+01:00" level=info msg="zeroconf server listening on port 34141" Mar 04 19:08:41 loe go-librespot[1806]: time="2026-03-04T19:08:41+01:00" level=debug msg="obtained new client token: AABuFk3wENx1+czWwiExfZxdvNt/mL3tndV2kAH53KNxpWorzUxCt1lZQJo5y1TS6UeZiHtaT2R3enMZm+DMjX2t7wp9Ki9HZuvqOcOt8n6MJQ6A66N78ZFMdvYKDYKNhipDpaZt270EgrzFWGWjDVgDRGQnO8dlzQBHAORd3JTPbN43HLNNOdRWyiyQbVDjvI4gjTGweCwaF0XiwwdYO4eWzu3RwX1bEqmyT83wA0ZdAOlYjax4idkeOA==" Mar 04 19:08:41 loe go-librespot[1806]: time="2026-03-04T19:08:41+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 19:08:41 loe go-librespot[1806]: time="2026-03-04T19:08:41+01:00" level=debug msg="completed keyexchange" Mar 04 19:08:41 loe go-librespot[1806]: time="2026-03-04T19:08:41+01:00" level=debug msg="completed challenge" Mar 04 19:08:41 loe go-librespot[1806]: time="2026-03-04T19:08:41+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 19:08:41 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 19:08:41 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 19:08:42 loe volumio[1260]: info: Setting Geolocation for MyVolumio to eu9 Mar 04 19:08:42 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 19:08:42 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 19:08:42 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 19:08:42 loe volumio[1260]: info: Initializing connection to go-librespot Websocket Mar 04 19:08:42 loe volumio[1260]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 4 Mar 04 19:08:42 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 19:08:42 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 19:08:42 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Mar 04 19:08:42 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Mar 04 19:08:42 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Mar 04 19:08:42 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Mar 04 19:08:42 loe volumio[1260]: info: CoreCommandRouter::volumioGetBrowseSources Mar 04 19:08:43 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 19:08:43 loe volumio[1260]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 4 Mar 04 19:08:43 loe volumio[1260]: info: Received Get System Info Mar 04 19:08:43 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 04 19:08:43 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 04 19:08:43 loe volumio[1260]: info: Discovery: Getting this device information Mar 04 19:08:43 loe volumio[1260]: info: CoreCommandRouter::volumioGetState Mar 04 19:08:43 loe volumio[1260]: info: CorePlayQueue::getTrack 0 Mar 04 19:08:43 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 19:08:43 loe volumio5-onboarding[1798]: time=2026-03-04T19:08:43.643+01:00 level=INFO msg="system info for a53384b16fd4d7a180fdac1b5068092c" deviceName=Loe deviceVariant=volumio deviceModel= softwareVersion=4.096 Mar 04 19:08:43 loe volumio[1260]: info: Setting Geolocation for MyVolumio to eu8 Mar 04 19:08:43 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 19:08:43 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 19:08:43 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 19:08:43 loe volumio[1260]: info: Successfully Added MyVolumio device Mar 04 19:08:43 loe volumio[1260]: info: Updating MyVolumio device info Mar 04 19:08:43 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 19:08:43 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 19:08:43 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 19:08:43 loe volumio[1260]: info: Remote config written successfully Mar 04 19:08:43 loe volumio[1260]: info: Starting Tunnel 1 Mar 04 19:08:43 loe volumio[1260]: info: Starting Tunnel Connection Checker Mar 04 19:08:44 loe volumio[1260]: info: Completed starting MyVolumio Plugin Mar 04 19:08:44 loe volumio[1260]: info: Received Get System Info Mar 04 19:08:44 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 04 19:08:44 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 04 19:08:44 loe volumio[1260]: info: Discovery: Getting this device information Mar 04 19:08:44 loe volumio[1260]: info: CoreCommandRouter::volumioGetState Mar 04 19:08:44 loe volumio[1260]: info: CorePlayQueue::getTrack 0 Mar 04 19:08:44 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 19:08:44 loe volumio[1260]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 19:08:44 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Mar 04 19:08:44 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:08:44 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:08:44 loe go-librespot[1847]: go-librespot daemon starting... Mar 04 19:08:44 loe go-librespot[1848]: time="2026-03-04T19:08:44+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 19:08:44 loe go-librespot[1848]: time="2026-03-04T19:08:44+01:00" level=debug msg="app state loaded" Mar 04 19:08:44 loe go-librespot[1848]: time="2026-03-04T19:08:44+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 19:08:45 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 04 19:08:45 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 04 19:08:45 loe volumio5-onboarding[1798]: time=2026-03-04T19:08:45.062+01:00 level=INFO msg="enabling local network discovery" Mar 04 19:08:45 loe volumio[1260]: info: MYVolumio Device enabled Mar 04 19:08:45 loe volumio[1260]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Mar 04 19:08:45 loe volumio5-onboarding[1798]: time=2026-03-04T19:08:45.141+01:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 04 19:08:45 loe volumio[1260]: info: MyVolumio status changed Mar 04 19:08:45 loe volumio[1260]: info: Streaming services startup Mar 04 19:08:45 loe volumio[1260]: info: Starting Streaming Daemon Mar 04 19:08:45 loe sudo[1859]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 04 19:08:45 loe go-librespot[1848]: time="2026-03-04T19:08:45+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 19:08:45 loe go-librespot[1848]: time="2026-03-04T19:08:45+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 19:08:45 loe go-librespot[1848]: time="2026-03-04T19:08:45+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 19:08:45 loe sudo[1859]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 19:08:45 loe go-librespot[1848]: time="2026-03-04T19:08:45+01:00" level=info msg="zeroconf server listening on port 37483" Mar 04 19:08:45 loe go-librespot[1848]: time="2026-03-04T19:08:45+01:00" level=debug msg="obtained new client token: AAB5fB+9txyK0phME2Tj2GHQvp/OQ276ZuXdxFfU0990GK2MnL8FRlPxZG7hsjz6t5EfJtYiykP99YDgQ9gRCvpZ3kAm0shSwaEmXTNDGSey1QqorwpIr6me5J303lIYh3Cr0Cu+Xtv7Vcewx1ScE8UMFiOMAjstGVlxC1RBtEhrXQpWvtXwqihIFO4/j9/FdYalIqBsSYJbJJaQQRf9g5bchyohXOQNaojvY+fxhpjAKKQt+CchIm2dHQ==" Mar 04 19:08:45 loe sudo[1859]: pam_unix(sudo:session): session closed for user root Mar 04 19:08:45 loe go-librespot[1848]: time="2026-03-04T19:08:45+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 19:08:45 loe go-librespot[1848]: time="2026-03-04T19:08:45+01:00" level=debug msg="completed keyexchange" Mar 04 19:08:45 loe go-librespot[1848]: time="2026-03-04T19:08:45+01:00" level=debug msg="completed challenge" Mar 04 19:08:45 loe volumio[1260]: info: Updating MyVolumio device info Mar 04 19:08:45 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 19:08:45 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 19:08:45 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 19:08:45 loe go-librespot[1848]: time="2026-03-04T19:08:45+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 19:08:45 loe volumio[1260]: info: Received Get System Info Mar 04 19:08:45 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 19:08:45 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 19:08:45 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 04 19:08:45 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 04 19:08:45 loe volumio[1260]: info: Discovery: Getting this device information Mar 04 19:08:45 loe volumio[1260]: info: CoreCommandRouter::volumioGetState Mar 04 19:08:45 loe volumio[1260]: info: CorePlayQueue::getTrack 0 Mar 04 19:08:45 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 19:08:46 loe volumio[1260]: info: Successfully Added MyVolumio device Mar 04 19:08:46 loe volumio[1260]: error: Cannot start Volumio Streaming Daemon Mar 04 19:08:46 loe volumio[1260]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 04 19:08:46 loe volumio[1260]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 04 19:08:46 loe volumio-remote-updater[708]: Test mode disabled Mar 04 19:08:46 loe volumio-remote-updater[708]: Alpha mode disabled Mar 04 19:08:46 loe volumio-remote-updater[708]: Alpha legacy test mode disabled Mar 04 19:08:47 loe volumio[1260]: info: CoreCommandRouter::volumioGetState Mar 04 19:08:47 loe volumio[1260]: info: CorePlayQueue::getTrack 0 Mar 04 19:08:47 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Mar 04 19:08:47 loe volumio[1260]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Mar 04 19:08:48 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Mar 04 19:08:48 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:08:49 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:08:49 loe go-librespot[1867]: go-librespot daemon starting... Mar 04 19:08:49 loe go-librespot[1868]: time="2026-03-04T19:08:49+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 19:08:49 loe go-librespot[1868]: time="2026-03-04T19:08:49+01:00" level=debug msg="app state loaded" Mar 04 19:08:49 loe go-librespot[1868]: time="2026-03-04T19:08:49+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 19:08:49 loe go-librespot[1868]: time="2026-03-04T19:08:49+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 19:08:49 loe go-librespot[1868]: time="2026-03-04T19:08:49+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 19:08:49 loe go-librespot[1868]: time="2026-03-04T19:08:49+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 19:08:49 loe go-librespot[1868]: time="2026-03-04T19:08:49+01:00" level=info msg="zeroconf server listening on port 35487" Mar 04 19:08:49 loe volumio[1260]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Mar 04 19:08:49 loe volumio[1260]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Mar 04 19:08:49 loe go-librespot[1868]: time="2026-03-04T19:08:49+01:00" level=debug msg="obtained new client token: AACTGJHVpiwl45l3TZTX15D/ciDo+Yuegb77zNbNxrnQhXcDuSRYyjd8YvKoTjT1p0+2W8HZAJSxJvpq33GrivRyI3nhYV3R9mB3jAVgFsBH6Fu0o0yyz2ZmBAVqaEC5KAHOEZCVCvq8AoadFxnDYBMq82vWZi/lcGLNvRr2x8Wf27nBkwybGbyQyK6Q2q9xHV1AIStYZM+Ve+Es1NRycxVZs0+toOxpcpdBtuFb+P/jnq6sHIhBWNCJdw==" Mar 04 19:08:50 loe go-librespot[1868]: time="2026-03-04T19:08:50+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 19:08:50 loe go-librespot[1868]: time="2026-03-04T19:08:50+01:00" level=debug msg="completed keyexchange" Mar 04 19:08:50 loe go-librespot[1868]: time="2026-03-04T19:08:50+01:00" level=debug msg="completed challenge" Mar 04 19:08:50 loe go-librespot[1868]: time="2026-03-04T19:08:50+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 19:08:50 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 19:08:50 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 19:08:53 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Mar 04 19:08:53 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:08:53 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:08:53 loe go-librespot[1876]: go-librespot daemon starting... Mar 04 19:08:53 loe go-librespot[1877]: time="2026-03-04T19:08:53+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 19:08:53 loe go-librespot[1877]: time="2026-03-04T19:08:53+01:00" level=debug msg="app state loaded" Mar 04 19:08:53 loe go-librespot[1877]: time="2026-03-04T19:08:53+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 19:08:54 loe go-librespot[1877]: time="2026-03-04T19:08:54+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 19:08:54 loe go-librespot[1877]: time="2026-03-04T19:08:54+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 19:08:54 loe go-librespot[1877]: time="2026-03-04T19:08:54+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 19:08:54 loe go-librespot[1877]: time="2026-03-04T19:08:54+01:00" level=info msg="zeroconf server listening on port 38029" Mar 04 19:08:54 loe go-librespot[1877]: time="2026-03-04T19:08:54+01:00" level=debug msg="obtained new client token: AAABl0tjdV6gSO1/D0rkioGR2AGB1Iulto56ZekgFFiW5r8S11jAjH5s6IT2SRlp7gIpjueFbgk006J0tVyP5nfQzxX4VBaxfZbewUtGr8tjNi+Ezapgmqt5f6bQbl9zSTIIwaOsBHRPJe74YrTpSZAUrnBfBQUDTA9ESVQbqGDJ0pybdgCMntzMgD7HZncSd6whcUdmQhh8JlSU60WGLnLgkan9cgVHz/3hHeWuKz9QLSgBSSjyKyuYVQ==" Mar 04 19:08:54 loe go-librespot[1877]: time="2026-03-04T19:08:54+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 19:08:54 loe go-librespot[1877]: time="2026-03-04T19:08:54+01:00" level=debug msg="completed keyexchange" Mar 04 19:08:54 loe go-librespot[1877]: time="2026-03-04T19:08:54+01:00" level=debug msg="completed challenge" Mar 04 19:08:54 loe go-librespot[1877]: time="2026-03-04T19:08:54+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 19:08:54 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 19:08:54 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 19:08:57 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Mar 04 19:08:57 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:08:57 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:08:57 loe go-librespot[1899]: go-librespot daemon starting... Mar 04 19:08:57 loe go-librespot[1900]: time="2026-03-04T19:08:57+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 19:08:57 loe go-librespot[1900]: time="2026-03-04T19:08:57+01:00" level=debug msg="app state loaded" Mar 04 19:08:57 loe go-librespot[1900]: time="2026-03-04T19:08:57+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 19:08:58 loe go-librespot[1900]: time="2026-03-04T19:08:58+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 19:08:58 loe go-librespot[1900]: time="2026-03-04T19:08:58+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 19:08:58 loe go-librespot[1900]: time="2026-03-04T19:08:58+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 19:08:58 loe go-librespot[1900]: time="2026-03-04T19:08:58+01:00" level=info msg="zeroconf server listening on port 35199" Mar 04 19:08:58 loe go-librespot[1900]: time="2026-03-04T19:08:58+01:00" level=debug msg="obtained new client token: AADpg+jn7f7pG52weUX72RM+SqO9Fmzp22MvqsgXE/Cpc1+RLt/sdZbCCc1UifbYehLRRFQ4FG2zu2QseeRTjzsv8mo72ABSmSEoGMqLfPiTEp4oTZXcCJqlCIozWIydYPH5CMirBwTVXDR/V9G5qZOvLE84bfLqQJeOzqtxXCVKaI/yuA/042SrvMNuIAnre7Z+mCZpSsqLziE81j6+BNHQ4HlWPBbTazafjPTtWuQnYPHx37968w4CJA==" Mar 04 19:08:58 loe go-librespot[1900]: time="2026-03-04T19:08:58+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 19:08:58 loe go-librespot[1900]: time="2026-03-04T19:08:58+01:00" level=debug msg="completed keyexchange" Mar 04 19:08:58 loe go-librespot[1900]: time="2026-03-04T19:08:58+01:00" level=debug msg="completed challenge" Mar 04 19:08:58 loe go-librespot[1900]: time="2026-03-04T19:08:58+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 19:08:58 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 19:08:58 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 19:09:01 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Mar 04 19:09:01 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:09:01 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:09:01 loe go-librespot[1908]: go-librespot daemon starting... Mar 04 19:09:01 loe go-librespot[1909]: time="2026-03-04T19:09:01+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 19:09:02 loe go-librespot[1909]: time="2026-03-04T19:09:02+01:00" level=debug msg="app state loaded" Mar 04 19:09:02 loe go-librespot[1909]: time="2026-03-04T19:09:02+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 19:09:02 loe go-librespot[1909]: time="2026-03-04T19:09:02+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 19:09:02 loe go-librespot[1909]: time="2026-03-04T19:09:02+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 19:09:02 loe go-librespot[1909]: time="2026-03-04T19:09:02+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 19:09:02 loe go-librespot[1909]: time="2026-03-04T19:09:02+01:00" level=info msg="zeroconf server listening on port 40849" Mar 04 19:09:02 loe go-librespot[1909]: time="2026-03-04T19:09:02+01:00" level=debug msg="obtained new client token: AABLLFQ2uOHoGmhZDComSxPUzXUw+h1JoMZsYf1pgyctJqCdcW8+YeAilDGzrOfTJrEDvJEbJaE5MfYoAGWWGoTCIP3sVPfi2PzCrP3NYQs8lYz76fk9H4uYx9CuSXOwiIFUTfM6LJya8QzH9z8SWunKF6CcDhBAoMLgcWFmvZ0VRSniPFXGSuNyyIQ1sFADHSDm0w7dghc0xsse160mXyRsrc1vjAlHLLnlWQF/cnbc5ftksk4a+p75Fw==" Mar 04 19:09:02 loe go-librespot[1909]: time="2026-03-04T19:09:02+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 19:09:02 loe go-librespot[1909]: time="2026-03-04T19:09:02+01:00" level=debug msg="completed keyexchange" Mar 04 19:09:02 loe go-librespot[1909]: time="2026-03-04T19:09:02+01:00" level=debug msg="completed challenge" Mar 04 19:09:03 loe go-librespot[1909]: time="2026-03-04T19:09:03+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 19:09:03 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 19:09:03 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 19:09:04 loe volumio[1260]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Mar 04 19:09:05 loe sudo[1931]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Mar 04 19:09:05 loe sudo[1931]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 19:09:05 loe sudo[1931]: pam_unix(sudo:session): session closed for user root Mar 04 19:09:05 loe volumio[1260]: info: MRS: MultiRoom plugin initialized Mar 04 19:09:05 loe volumio[1260]: info: MRS: STOPPING SNAPCLIENT Mar 04 19:09:05 loe volumio[1260]: info: MRS: Snap server stop Mar 04 19:09:05 loe volumio[1260]: info: MRS: STOPPING volumioStreaming Mar 04 19:09:05 loe sudo[1949]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Mar 04 19:09:05 loe sudo[1949]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 19:09:06 loe volumio[1260]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Mar 04 19:09:06 loe sudo[1951]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Mar 04 19:09:06 loe sudo[1951]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 19:09:06 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Mar 04 19:09:06 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:09:06 loe sudo[1953]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Mar 04 19:09:06 loe sudo[1953]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 19:09:06 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:09:06 loe go-librespot[1958]: go-librespot daemon starting... Mar 04 19:09:06 loe go-librespot[1959]: time="2026-03-04T19:09:06+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 19:09:06 loe go-librespot[1959]: time="2026-03-04T19:09:06+01:00" level=debug msg="app state loaded" Mar 04 19:09:06 loe go-librespot[1959]: time="2026-03-04T19:09:06+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 19:09:06 loe sudo[1949]: pam_unix(sudo:session): session closed for user root Mar 04 19:09:06 loe sudo[1956]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Mar 04 19:09:06 loe sudo[1951]: pam_unix(sudo:session): session closed for user root Mar 04 19:09:06 loe sudo[1956]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 19:09:06 loe sudo[1956]: pam_unix(sudo:session): session closed for user root Mar 04 19:09:06 loe volumio[1260]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Mar 04 19:09:06 loe sudo[1953]: pam_unix(sudo:session): session closed for user root Mar 04 19:09:06 loe volumio[1260]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Mar 04 19:09:06 loe go-librespot[1959]: time="2026-03-04T19:09:06+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 19:09:06 loe go-librespot[1959]: time="2026-03-04T19:09:06+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 19:09:06 loe go-librespot[1959]: time="2026-03-04T19:09:06+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 19:09:06 loe go-librespot[1959]: time="2026-03-04T19:09:06+01:00" level=info msg="zeroconf server listening on port 42333" Mar 04 19:09:07 loe go-librespot[1959]: time="2026-03-04T19:09:07+01:00" level=debug msg="obtained new client token: AADz2tQAyexzHOujmWNjU1qUTsqtingj7L15J4vsMUCRoYIDSGiNj2CFGszbPxwWh9Di7Wkh9QowOnuisujnkkfa/B7Q76bsck/27gJBNrf11OcynM5/Z0tQ2GNJQQCNfPurWNLhavsaBdj0jxWY1HY+YN97Cpyv3Iv8tYzGTbmSGc38N323NujBgIZJiakMvHvhJzn0GyJ5pMqCIBrE+3kRYc98zAb1/Yu31qvdtsUB71C6YMzQ3hg=" Mar 04 19:09:07 loe go-librespot[1959]: time="2026-03-04T19:09:07+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 19:09:07 loe go-librespot[1959]: time="2026-03-04T19:09:07+01:00" level=debug msg="completed keyexchange" Mar 04 19:09:07 loe go-librespot[1959]: time="2026-03-04T19:09:07+01:00" level=debug msg="completed challenge" Mar 04 19:09:07 loe go-librespot[1959]: time="2026-03-04T19:09:07+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 19:09:07 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 19:09:07 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 19:09:07 loe volumio[1260]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Mar 04 19:09:07 loe volumio[1260]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Mar 04 19:09:07 loe volumio[1260]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Mar 04 19:09:07 loe volumio[1260]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Mar 04 19:09:08 loe volumio[1260]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Mar 04 19:09:09 loe volumio[1260]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Mar 04 19:09:09 loe volumio[1260]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Mar 04 19:09:09 loe volumio[1260]: info: Preparing to generate the ALSA configuration file Mar 04 19:09:10 loe volumio[1260]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 04 19:09:10 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 04 19:09:10 loe volumio[1260]: info: Successfully Updated MyVolumio device Mar 04 19:09:10 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Mar 04 19:09:10 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:09:10 loe volumio[1260]: info: Initializing connection to go-librespot Websocket Mar 04 19:09:10 loe volumio[1260]: error: Failed to update MyVolumio device: undefined Mar 04 19:09:10 loe volumio[1260]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Mar 04 19:09:10 loe volumio[1260]: info: Reading ALSA contributions from plugins. Mar 04 19:09:10 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:09:10 loe go-librespot[1968]: go-librespot daemon starting... Mar 04 19:09:10 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 04 19:09:10 loe go-librespot[1969]: time="2026-03-04T19:09:10+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 19:09:10 loe go-librespot[1969]: time="2026-03-04T19:09:10+01:00" level=debug msg="app state loaded" Mar 04 19:09:10 loe go-librespot[1969]: time="2026-03-04T19:09:10+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 19:09:10 loe volumio[1260]: info: MRS: Removed streaming files Mar 04 19:09:10 loe volumio[1260]: info: MRS: volumioStreaming STOPPED Mar 04 19:09:10 loe volumio[1260]: info: MRS: SNAPSERVER STOPPED Mar 04 19:09:10 loe volumio[1260]: info: MRS: SNAPCLIENT STOPPED Mar 04 19:09:10 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 04 19:09:10 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 04 19:09:11 loe go-librespot[1969]: time="2026-03-04T19:09:11+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 04 19:09:11 loe go-librespot[1969]: time="2026-03-04T19:09:11+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 04 19:09:11 loe go-librespot[1969]: time="2026-03-04T19:09:11+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 04 19:09:11 loe volumio[1260]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 19:09:11 loe go-librespot[1969]: time="2026-03-04T19:09:11+01:00" level=info msg="zeroconf server listening on port 35601" Mar 04 19:09:11 loe go-librespot[1969]: time="2026-03-04T19:09:11+01:00" level=debug msg="obtained new client token: AABXocPthihIJQw/YUhmGqd57ctda+mJRskBwWAeUz/SbQrF+xyJE6+2ozONz2UEegA9sYfhcCgr7Er44qKxn7IceXw6pK53ZIUFROjlR1kRdSI6gOBXAVMaUP3fCCOM07CciAKvzxhKbKYdChdUEQZScEgL7jA8S801OfPanerLUz733YpDAMfVhukPYsPzlhaTlZKZ8YbrHFgVpbP8q4nrxcpShKHEvm5FnuDWXgKG3Dw/eVBIYkmeew==" Mar 04 19:09:11 loe go-librespot[1969]: time="2026-03-04T19:09:11+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 19:09:11 loe go-librespot[1969]: time="2026-03-04T19:09:11+01:00" level=debug msg="completed keyexchange" Mar 04 19:09:11 loe go-librespot[1969]: time="2026-03-04T19:09:11+01:00" level=debug msg="completed challenge" Mar 04 19:09:11 loe go-librespot[1969]: time="2026-03-04T19:09:11+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 19:09:11 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 19:09:11 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 19:09:12 loe volumio[1260]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Mar 04 19:09:13 loe sudo[1985]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Mar 04 19:09:13 loe sudo[1985]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 19:09:13 loe volumio[1260]: info: Asound.conf file written Mar 04 19:09:13 loe 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 04 19:09:13 loe 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 04 19:09:13 loe systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Mar 04 19:09:13 loe autossh[1991]: port set to 0, monitoring disabled Mar 04 19:09:13 loe autossh[1991]: starting ssh (count 1) Mar 04 19:09:13 loe autossh[1991]: ssh child pid is 1994 Mar 04 19:09:13 loe sudo[1985]: pam_unix(sudo:session): session closed for user root Mar 04 19:09:13 loe sudo[1990]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Mar 04 19:09:13 loe sudo[1990]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 19:09:13 loe sudo[1990]: pam_unix(sudo:session): session closed for user root Mar 04 19:09:13 loe volumiossh-tunnel[1994]: Warning: Permanently added '[eu8.myvolumio.org]:2222' (RSA) to the list of known hosts. Mar 04 19:09:14 loe volumio[1260]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Mar 04 19:09:14 loe volumio[1260]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Mar 04 19:09:14 loe volumio[1260]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Mar 04 19:09:14 loe volumio[1260]: No state is present for card vc4hdmi Mar 04 19:09:14 loe volumio[1260]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Mar 04 19:09:14 loe volumio[1260]: Found hardware: "vc4-hdmi" "" "" "" "" Mar 04 19:09:14 loe volumio[1260]: Hardware is initialized using a generic method Mar 04 19:09:14 loe volumio[1260]: No state is present for card vc4hdmi Mar 04 19:09:14 loe volumio[1260]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:3 use case configuration -2 Mar 04 19:09:14 loe volumio[1260]: info: Output device has changed, restarting MPD Mar 04 19:09:14 loe volumio[1260]: info: Output device has changed, restarting Shairport Sync Mar 04 19:09:14 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 19:09:14 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 19:09:14 loe sudo[2000]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 19:09:14 loe sudo[2000]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 19:09:14 loe sudo[2000]: pam_unix(sudo:session): session closed for user root Mar 04 19:09:14 loe sudo[2002]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 19:09:14 loe sudo[2002]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 19:09:14 loe volumio[1260]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 19:09:14 loe volumio[1260]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Mar 04 19:09:14 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 19:09:14 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Mar 04 19:09:14 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:09:14 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:09:14 loe go-librespot[2010]: go-librespot daemon starting... Mar 04 19:09:14 loe systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 04 19:09:14 loe volumio[1260]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Mar 04 19:09:14 loe volumio[1260]: ------------------------------------ BT MESSAGE: [FUNC] onStart Mar 04 19:09:14 loe volumio[1260]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Mar 04 19:09:14 loe go-librespot[2012]: time="2026-03-04T19:09:14+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 19:09:14 loe go-librespot[2012]: time="2026-03-04T19:09:14+01:00" level=debug msg="app state loaded" Mar 04 19:09:14 loe go-librespot[2012]: time="2026-03-04T19:09:14+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 19:09:15 loe volumio[1260]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Mar 04 19:09:15 loe volumio[1260]: ------------------------------------ BT MESSAGE: [metaCache] Created directory: /tmp/bluetooth-cache/ Mar 04 19:09:15 loe volumio[1260]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Mar 04 19:09:15 loe volumio5-onboarding[1798]: failed to bootstrap state: failed to get music providers: could not get available plugins: could not get available plugins: context deadline exceeded Mar 04 19:09:15 loe systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 04 19:09:15 loe systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 04 19:09:15 loe volumio[1260]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Mar 04 19:09:15 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Mar 04 19:09:15 loe volumio[1260]: info: MRS: Pushing multiroomSync output for this device Mar 04 19:09:15 loe volumio[1260]: info: MRS: Pushing multiroomSync output Mar 04 19:09:15 loe systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 4. Mar 04 19:09:15 loe systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 04 19:09:15 loe volumio[1260]: info: Adding audio output: Mar 04 19:09:15 loe volumio[1260]: info: Adding audio output: Mar 04 19:09:15 loe systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 04 19:09:15 loe volumio5-onboarding[2034]: time=2026-03-04T19:09:15.578+01:00 level=INFO msg="running volumio5-device-gateway" version=30d1950e+CHANGES buildDate=2026-01-29T13:10:08Z Mar 04 19:09:15 loe systemd[1]: mpd.service: Deactivated successfully. Mar 04 19:09:15 loe systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 04 19:09:15 loe systemd[1]: mpd.service: Consumed 10.081s CPU time. Mar 04 19:09:15 loe systemd[1]: mpd.socket: Deactivated successfully. Mar 04 19:09:15 loe systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 04 19:09:15 loe systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 04 19:09:15 loe go-librespot[2012]: time="2026-03-04T19:09:15+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 04 19:09:15 loe go-librespot[2012]: time="2026-03-04T19:09:15+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 04 19:09:15 loe go-librespot[2012]: time="2026-03-04T19:09:15+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 04 19:09:15 loe volumio[1260]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Mar 04 19:09:15 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 19:09:15 loe go-librespot[2012]: time="2026-03-04T19:09:15+01:00" level=info msg="zeroconf server listening on port 39477" Mar 04 19:09:15 loe systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 04 19:09:15 loe systemd[1]: Starting mpd.service - Music Player Daemon... Mar 04 19:09:15 loe volumio[1260]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Mar 04 19:09:15 loe go-librespot[2012]: time="2026-03-04T19:09:15+01:00" level=debug msg="obtained new client token: AABufCVyr6QEDhEWLn6W7oYc8MML2AmQ7eWyZ+KWWh8RsoMRtpqJGYqgVEP3gMHpVtjP29CfPIFm2TawCD9czNUS0V/7ivMsZ+DByMrHj2663N/iJB1Q+/0nkzhf3ZEv4bR4lQKI+wHsyei9GnjxWw49BNZxqtBa0qkF0tk/1R0lw5alUr/tm0iQBq0eQLuHOhB/7pLFEHZNP07bi2s0WYGbacProbgASr9YZhY9MrVBr1YydXrHZZtjCw==" Mar 04 19:09:15 loe volumio[1260]: info: Adding METAVOLUMIO REST API Endpoints Mar 04 19:09:15 loe volumio[1260]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Mar 04 19:09:15 loe volumio[1260]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Mar 04 19:09:15 loe volumio[1260]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Mar 04 19:09:15 loe volumio[1260]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Mar 04 19:09:15 loe volumio[1260]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Mar 04 19:09:16 loe volumio[1260]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Mar 04 19:09:16 loe go-librespot[2012]: time="2026-03-04T19:09:16+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 19:09:16 loe volumio[1260]: info: Preparing CD Folders Mar 04 19:09:16 loe volumio[1260]: info: Adding CD REST API Endpoints Mar 04 19:09:16 loe volumio[1260]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Mar 04 19:09:16 loe volumio[1260]: info: Starting UDEV Watcher for CD Mar 04 19:09:16 loe volumio[1260]: info: Detecting CD presence with UDEV Mar 04 19:09:16 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Mar 04 19:09:16 loe go-librespot[2012]: time="2026-03-04T19:09:16+01:00" level=debug msg="completed keyexchange" Mar 04 19:09:16 loe go-librespot[2012]: time="2026-03-04T19:09:16+01:00" level=debug msg="completed challenge" Mar 04 19:09:16 loe go-librespot[2012]: time="2026-03-04T19:09:16+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 19:09:16 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 19:09:16 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 19:09:16 loe bluetoothd[941]: Path / reserved for Adv Monitor app :1.22 Mar 04 19:09:16 loe sudo[2045]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 04 19:09:16 loe sudo[2045]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 04 19:09:16 loe sudo[2045]: pam_unix(sudo:session): session closed for user root Mar 04 19:09:16 loe bluetoothd[941]: Adv Monitor app :1.22 disconnected from D-Bus Mar 04 19:09:19 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Mar 04 19:09:19 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:09:19 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:09:19 loe go-librespot[2054]: go-librespot daemon starting... Mar 04 19:09:19 loe go-librespot[2055]: time="2026-03-04T19:09:19+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 19:09:19 loe go-librespot[2055]: time="2026-03-04T19:09:19+01:00" level=debug msg="app state loaded" Mar 04 19:09:19 loe go-librespot[2055]: time="2026-03-04T19:09:19+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 19:09:20 loe go-librespot[2055]: time="2026-03-04T19:09:20+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 19:09:20 loe go-librespot[2055]: time="2026-03-04T19:09:20+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 19:09:20 loe go-librespot[2055]: time="2026-03-04T19:09:20+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 19:09:20 loe go-librespot[2055]: time="2026-03-04T19:09:20+01:00" level=info msg="zeroconf server listening on port 41491" Mar 04 19:09:20 loe go-librespot[2055]: time="2026-03-04T19:09:20+01:00" level=debug msg="obtained new client token: AADTSAdHP+FPGoRQQTtCVc0Rq9u2+pPZz9pkKFZgeficj7bvdzEgA9Ms3bkTslQjSrcngvWxLnW5Gzz37yy/7sNDvwfD2K/+6EsvPs/34KXeiKgFMtf0wt8YGTxuJztPvko7lGMTs/6ID1qYx9X8y57GRnq+uNL/JphlzoM9+xqh/Wf+z4WJCv2iGinZ3F1Ugotb8lYF5oo/YIf7p/913J5vQswzzrIFhrN1oX0VRn1OAL5vjXxP1tU=" Mar 04 19:09:20 loe go-librespot[2055]: time="2026-03-04T19:09:20+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 19:09:20 loe go-librespot[2055]: time="2026-03-04T19:09:20+01:00" level=debug msg="completed keyexchange" Mar 04 19:09:20 loe go-librespot[2055]: time="2026-03-04T19:09:20+01:00" level=debug msg="completed challenge" Mar 04 19:09:20 loe go-librespot[2055]: time="2026-03-04T19:09:20+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 19:09:20 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 19:09:20 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 19:09:21 loe mpd[2049]: 2026-03-04T19:09:21 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 04 19:09:21 loe systemd[1]: Started mpd.service - Music Player Daemon. Mar 04 19:09:21 loe sudo[2002]: pam_unix(sudo:session): session closed for user root Mar 04 19:09:21 loe volumio[1260]: warn: [cd-plugin] cdspeedctl: device or media not ready Mar 04 19:09:21 loe volumio[1260]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Mar 04 19:09:21 loe volumio[1260]: info: Adding inputs REST Endpoints Mar 04 19:09:21 loe volumio[1260]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Mar 04 19:09:21 loe volumio[1260]: info: Scanning Audio Inputs Mar 04 19:09:22 loe volumio[1260]: info: Checking against Known Cards name Mar 04 19:09:22 loe volumio[1260]: info: Adding Server instance for streaming Mar 04 19:09:22 loe volumio[1260]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Mar 04 19:09:22 loe volumio[1260]: info: Adding HIGHRESAUDIO REST API Endpoints Mar 04 19:09:22 loe volumio[1260]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Mar 04 19:09:22 loe volumio[1260]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Mar 04 19:09:22 loe volumio[1260]: info: Refreshing TIDAL token Mar 04 19:09:22 loe volumio[1260]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Mar 04 19:09:22 loe volumio[1260]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Mar 04 19:09:22 loe volumio[1260]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Mar 04 19:09:22 loe volumio[1260]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Mar 04 19:09:22 loe volumio[1260]: info: QobuzConnect: Starting Qobuz Connect socket and service Mar 04 19:09:22 loe sudo[2069]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Mar 04 19:09:22 loe sudo[2069]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 19:09:22 loe volumio[1260]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Mar 04 19:09:22 loe volumio[1260]: info: Stopping AccessToken refresher cron for QOBUZ Mar 04 19:09:22 loe sudo[2074]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Mar 04 19:09:22 loe sudo[2074]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 19:09:23 loe sudo[2069]: pam_unix(sudo:session): session closed for user root Mar 04 19:09:23 loe volumio[1260]: info: AccessToken refresher cron started for QOBUZ Mar 04 19:09:23 loe volumio[1260]: info: Adding QOBUZ REST API Endpoints Mar 04 19:09:23 loe sudo[2074]: pam_unix(sudo:session): session closed for user root Mar 04 19:09:23 loe sudo[2078]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Mar 04 19:09:23 loe sudo[2078]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 19:09:23 loe volumio[1260]: error: MyVolumio Plugins failed to start in a timely fashion Mar 04 19:09:23 loe volumio[1260]: error: Plugin audio_interface bluetooth failed to complete 'onStart' in a timely fashion Mar 04 19:09:23 loe volumio[1260]: error: Plugin audio_interface multiroom failed to complete 'onStart' in a timely fashion Mar 04 19:09:23 loe volumio[1260]: error: Plugin music_service tidal failed to complete 'onStart' in a timely fashion Mar 04 19:09:23 loe volumio[1260]: error: Plugin music_service tidalconnect failed to complete 'onStart' in a timely fashion Mar 04 19:09:23 loe volumio[1260]: error: Plugin music_service qobuzconnect failed to complete 'onStart' in a timely fashion Mar 04 19:09:23 loe volumio[1260]: [Metrics] CommandRouter: 130s 73.23ms Mar 04 19:09:23 loe volumio[1260]: info: CoreCommandRouter::volumiosetStartupVolume Mar 04 19:09:23 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 19:09:23 loe volumio[1260]: info: VolumeController:: Setting startup Volume 5 Mar 04 19:09:23 loe volumio[1260]: info: VolumeController::SetAlsaVolume5 Mar 04 19:09:23 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Mar 04 19:09:23 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:09:23 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 19:09:23 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:09:23 loe go-librespot[2080]: go-librespot daemon starting... Mar 04 19:09:23 loe systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Mar 04 19:09:23 loe volumio[1260]: info: CoreCommandRouter::Close All Modals sent Mar 04 19:09:23 loe volumio[1260]: info: CoreCommandRouter::Close All Modals sent Mar 04 19:09:23 loe volumio[1260]: info: CoreStateMachine::pushState Mar 04 19:09:23 loe volumio[1260]: info: CorePlayQueue::getTrack 0 Mar 04 19:09:23 loe sudo[2078]: pam_unix(sudo:session): session closed for user root Mar 04 19:09:23 loe go-librespot[2082]: time="2026-03-04T19:09:23+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 19:09:23 loe go-librespot[2082]: time="2026-03-04T19:09:23+01:00" level=debug msg="app state loaded" Mar 04 19:09:23 loe go-librespot[2082]: time="2026-03-04T19:09:23+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 19:09:23 loe volumio[1260]: info: CoreCommandRouter::volumioPushState Mar 04 19:09:23 loe volumio[1260]: info: MRS: Pushing multiroomSync output update for this device Mar 04 19:09:23 loe volumio[1260]: info: MRS: Pushing multiroomSync output Mar 04 19:09:24 loe volumio[1260]: info: CoreCommandRouter::volumioGetState Mar 04 19:09:24 loe volumio[1260]: info: CorePlayQueue::getTrack 0 Mar 04 19:09:24 loe volumio[1260]: info: Initializing connection to go-librespot Websocket Mar 04 19:09:24 loe volumio[1260]: info: MRS: Getting audio outputs on start Mar 04 19:09:24 loe volumio[1260]: info: MRS: Requesting all other devices output Mar 04 19:09:24 loe volumio[1260]: error: Cannot download Available plugins list: Error: ESOCKETTIMEDOUT Mar 04 19:09:24 loe go-librespot[2082]: time="2026-03-04T19:09:24+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 19:09:24 loe go-librespot[2082]: time="2026-03-04T19:09:24+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 19:09:24 loe go-librespot[2082]: time="2026-03-04T19:09:24+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 19:09:24 loe go-librespot[2082]: time="2026-03-04T19:09:24+01:00" level=info msg="zeroconf server listening on port 42043" Mar 04 19:09:24 loe go-librespot[2082]: time="2026-03-04T19:09:24+01:00" level=debug msg="obtained new client token: AAAdqZCQ7cDsIEQGawL1f95JdQxacqaLOz7EjgdlkVjQRMqHXY7ZPW0o+sjBQZPLgw1ylKOlThznR2U41+0FWgSvfkzUD3qMmu++g6PS2Q1W3IAW0YVBuuMFwuABjcYDFXfdg5YlszcP7fOcgSS2uUcZLpB57IhcwuprLRNc2HmXFkk5jRnVUDQKaBZwZJQmBk44jbPcEPGBudHin2H8tuStQkZ5l7aGad63FUR3tza/v6I/QeB2BCasJg==" Mar 04 19:09:24 loe go-librespot[2082]: time="2026-03-04T19:09:24+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Mar 04 19:09:24 loe go-librespot[2082]: time="2026-03-04T19:09:24+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 04 19:09:24 loe go-librespot[2082]: time="2026-03-04T19:09:24+01:00" level=debug msg="completed keyexchange" Mar 04 19:09:24 loe go-librespot[2082]: time="2026-03-04T19:09:24+01:00" level=debug msg="completed challenge" Mar 04 19:09:24 loe go-librespot[2082]: time="2026-03-04T19:09:24+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 19:09:24 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 19:09:24 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 19:09:25 loe volumio[1260]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on Mar 04 19:09:25 loe volumio[1260]: info: MPD Permissions set Mar 04 19:09:25 loe volumio[1260]: info: Remote SSH Started Mar 04 19:09:25 loe volumio5-onboarding[2034]: failed to create app: failed to initialize host: failed to create socket connection: could not connect to socket.io server: read tcp 127.0.0.1:32968->127.0.0.1:3000: i/o timeout Mar 04 19:09:25 loe systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 04 19:09:25 loe systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 04 19:09:25 loe sudo[2098]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Mar 04 19:09:25 loe sudo[2098]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 19:09:25 loe systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 5. Mar 04 19:09:25 loe systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 04 19:09:25 loe systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 04 19:09:26 loe volumio5-onboarding[2110]: time=2026-03-04T19:09:26.031+01:00 level=INFO msg="running volumio5-device-gateway" version=30d1950e+CHANGES buildDate=2026-01-29T13:10:08Z Mar 04 19:09:26 loe systemd[1]: Started volumiobt.service - Volumio Bluetooth Module. Mar 04 19:09:26 loe sudo[2098]: pam_unix(sudo:session): session closed for user root Mar 04 19:09:26 loe volumiobt[2120]: INFO [BTSTART] Ensuring Bluetooth directory exists... Mar 04 19:09:26 loe sudo[2121]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /var/lib/bluetooth Mar 04 19:09:26 loe sudo[2121]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 19:09:26 loe sudo[2121]: pam_unix(sudo:session): session closed for user root Mar 04 19:09:26 loe sudo[2123]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth Mar 04 19:09:26 loe sudo[2123]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 19:09:26 loe sudo[2123]: pam_unix(sudo:session): session closed for user root Mar 04 19:09:26 loe volumiobt[2125]: INFO [BTSTART] Powering on Bluetooth if needed... Mar 04 19:09:26 loe bluetoothd[941]: Path / reserved for Adv Monitor app :1.23 Mar 04 19:09:26 loe bluetoothd[941]: Adv Monitor app :1.23 disconnected from D-Bus Mar 04 19:09:26 loe volumiobt[2128]: INFO [BTSTART] Making Bluetooth discoverable and pairable... Mar 04 19:09:26 loe volumiobt[2129]: [176B blob data] Mar 04 19:09:26 loe volumiobt[2129]: [157B blob data] Mar 04 19:09:26 loe volumiobt[2129]: [157B blob data] Mar 04 19:09:26 loe volumiobt[2129]: [157B blob data] Mar 04 19:09:26 loe volumiobt[2129]: [113B blob data] Mar 04 19:09:26 loe volumiobt[2129]: [bluetoothctl]> discoverable on Mar 04 19:09:26 loe volumiobt[2129]: Warning: setting discoverable while discoverable-timeout not set(0) is not recommended Mar 04 19:09:26 loe volumiobt[2129]: [bluetoothctl]> pairable on Mar 04 19:09:26 loe bluetoothd[941]: Path / reserved for Adv Monitor app :1.24 Mar 04 19:09:26 loe bluetoothd[941]: Adv Monitor app :1.24 disconnected from D-Bus Mar 04 19:09:26 loe volumiobt[2129]: [bluetoothctl]> Mar 04 19:09:26 loe volumiobt[2130]: INFO [BTSTART] Registering Bluetooth agent... Mar 04 19:09:26 loe volumiobt[2131]: [NEW] Media /org/bluez/hci0 Mar 04 19:09:26 loe volumiobt[2131]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb Mar 04 19:09:26 loe volumiobt[2131]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb Mar 04 19:09:26 loe volumiobt[2131]: SupportedUUIDs: 0000FDF0-0000-1000-8000-00805f9b34fb Mar 04 19:09:26 loe bluetoothd[941]: Path / reserved for Adv Monitor app :1.25 Mar 04 19:09:26 loe bluetoothd[941]: Adv Monitor app :1.25 disconnected from D-Bus Mar 04 19:09:26 loe volumiobt[2132]: No agent is registered Mar 04 19:09:26 loe volumiobt[2132]: [NEW] Media /org/bluez/hci0 Mar 04 19:09:26 loe volumiobt[2132]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb Mar 04 19:09:26 loe volumiobt[2132]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb Mar 04 19:09:26 loe volumiobt[2132]: SupportedUUIDs: 0000FDF0-0000-1000-8000-00805f9b34fb Mar 04 19:09:26 loe bluetoothd[941]: Path / reserved for Adv Monitor app :1.26 Mar 04 19:09:27 loe bluetoothd[941]: Adv Monitor app :1.26 disconnected from D-Bus Mar 04 19:09:27 loe volumiobt[2133]: INFO [BTSTART] Agent registered successfully. Mar 04 19:09:27 loe volumiobt[2134]: INFO [BTSTART] Starting A2DP agent (a2dp-agent)... Mar 04 19:09:28 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Mar 04 19:09:28 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:09:28 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:09:28 loe go-librespot[2136]: go-librespot daemon starting... Mar 04 19:09:28 loe go-librespot[2137]: time="2026-03-04T19:09:28+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 19:09:28 loe go-librespot[2137]: time="2026-03-04T19:09:28+01:00" level=debug msg="app state loaded" Mar 04 19:09:28 loe go-librespot[2137]: time="2026-03-04T19:09:28+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 19:09:28 loe volumiobt[2135]: INFO:a2dp-agent:Connecting to system bus. Mar 04 19:09:28 loe go-librespot[2137]: time="2026-03-04T19:09:28+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 19:09:28 loe go-librespot[2137]: time="2026-03-04T19:09:28+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 19:09:28 loe go-librespot[2137]: time="2026-03-04T19:09:28+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 19:09:28 loe volumiobt[2135]: INFO:a2dp-agent:Found Bluetooth adapter at: /org/bluez/hci0 Mar 04 19:09:28 loe volumiobt[2135]: INFO:a2dp-agent:Enabling infinite discovery on adapter. Mar 04 19:09:29 loe go-librespot[2137]: time="2026-03-04T19:09:29+01:00" level=info msg="zeroconf server listening on port 33271" Mar 04 19:09:29 loe volumiobt[2135]: INFO:a2dp-agent:Registering agent. Mar 04 19:09:29 loe volumiobt[2135]: INFO:a2dp-agent:Searching for MediaPlayer1 interface... Mar 04 19:09:29 loe volumiobt[2135]: WARNING:a2dp-agent:No active MediaPlayer1 found. Metadata updates won't work. Mar 04 19:09:29 loe go-librespot[2137]: time="2026-03-04T19:09:29+01:00" level=debug msg="obtained new client token: AAC9oMZulEQbUe08ZIgGb1UpwpqDDzZpVDK4Qa7AUuHBtWQb9ztSFFdG9XWoTs5RhA8nKBrhZY57TWOqLei+p0KrkHoOsJKcibKbUgchzaTxuyL7DUDq66jLSiRNeTKdDoxV9FQQdng0K3pJRDoiP5VRdU6DWlLP+C7rBgmyYMgZPQuRqqHbhQHmsPSn+TcMsNnI41q2j3Il9TkwmL5cOK4ryUWP9rlp24pr9A7bcJvWzO/3KA5JYe8=" Mar 04 19:09:29 loe go-librespot[2137]: time="2026-03-04T19:09:29+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 19:09:29 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Mar 04 19:09:29 loe go-librespot[2137]: time="2026-03-04T19:09:29+01:00" level=debug msg="completed keyexchange" Mar 04 19:09:29 loe go-librespot[2137]: time="2026-03-04T19:09:29+01:00" level=debug msg="completed challenge" Mar 04 19:09:29 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 04 19:09:29 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Mar 04 19:09:29 loe go-librespot[2137]: time="2026-03-04T19:09:29+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 19:09:29 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 19:09:29 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 19:09:29 loe volumio[1260]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 19:09:30 loe volumio[1260]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully Mar 04 19:09:30 loe volumio[1260]: info: CoreCommandRouter::volumioStop Mar 04 19:09:30 loe volumio[1260]: info: CoreStateMachine::stop Mar 04 19:09:30 loe volumio[1260]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 04 19:09:30 loe volumio[1260]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart Mar 04 19:09:30 loe volumio[1260]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 04 19:09:30 loe volumio[1260]: info: TidalConnect service stoped! Mar 04 19:09:31 loe volumio[1260]: info: Executing endpoint qc_getconfig Mar 04 19:09:31 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Mar 04 19:09:31 loe qobuz-connect[2088]: 20260304 19:09:31.792 [2088.2088] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Mar 04 19:09:31 loe volumio[1260]: info: BOOT COMPLETED Mar 04 19:09:31 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 19:09:31 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 19:09:31 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 19:09:31 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 19:09:31 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 19:09:31 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 19:09:31 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 19:09:31 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 19:09:32 loe qobuz-connect[2088]: 20260304 19:09:32.014 [2088.2088] INFO VolumeManager: [0xbe4408]: Setting new playback volume: 75 Mar 04 19:09:32 loe qobuz-connect[2088]: 20260304 19:09:32.014 [2088.2088] INFO VolumeManager: [0xbe4408]: Setting new mute state: 0 Mar 04 19:09:32 loe qobuz-connect[2088]: 20260304 19:09:32.014 [2088.2088] INFO QobuzConnect: [0xbe4dd8]: Client initialized! Mar 04 19:09:32 loe qobuz-connect[2088]: 20260304 19:09:32.014 [2088.2088] INFO SampleApp: Starting Avahi advertising, name: Loe, service name: _qobuz-connect._tcp Mar 04 19:09:32 loe qobuz-connect[2088]: 20260304 19:09:32.074 [2088.2088] INFO LocalConfigManager: [0xbe3ce8]: Starting Local Configuration server Mar 04 19:09:32 loe qobuz-connect[2088]: 20260304 19:09:32.074 [2088.2088] INFO SampleApp: Starting Local configuration server Mar 04 19:09:32 loe qobuz-connect[2088]: 20260304 19:09:32.075 [2088.2088] INFO SampleApp: Playback volume changed: 75 Mar 04 19:09:32 loe qobuz-connect[2088]: 20260304 19:09:32.075 [2088.2088] INFO SampleApp: Connected to UNIX socket client 0xbce818 Mar 04 19:09:32 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 19:09:32 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 19:09:32 loe volumio[1260]: info: Access Token successfully retrieved Mar 04 19:09:32 loe volumio[1260]: error: Hi Res Audio Failed Login: [object Object] Mar 04 19:09:32 loe volumio[1260]: error: updateQueue error: null Mar 04 19:09:32 loe volumio[1260]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Mar 04 19:09:32 loe volumio[1260]: info: QobuzConnect: QOBUZ Connect daemon connected Mar 04 19:09:32 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Mar 04 19:09:32 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:09:32 loe volumio[1260]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 5 Mar 04 19:09:32 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:09:32 loe go-librespot[2162]: go-librespot daemon starting... Mar 04 19:09:32 loe go-librespot[2164]: time="2026-03-04T19:09:32+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 19:09:32 loe go-librespot[2164]: time="2026-03-04T19:09:32+01:00" level=debug msg="app state loaded" Mar 04 19:09:32 loe go-librespot[2164]: time="2026-03-04T19:09:32+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 19:09:32 loe volumio[1260]: info: Initializing connection to go-librespot Websocket Mar 04 19:09:33 loe volumio[1260]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 5 Mar 04 19:09:33 loe volumio[1260]: info: Received Get System Info Mar 04 19:09:33 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 04 19:09:33 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 04 19:09:33 loe volumio[1260]: info: Discovery: Getting this device information Mar 04 19:09:33 loe volumio[1260]: info: CoreCommandRouter::volumioGetState Mar 04 19:09:33 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 19:09:33 loe volumio5-onboarding[2110]: time=2026-03-04T19:09:33.160+01:00 level=INFO msg="system info for a53384b16fd4d7a180fdac1b5068092c" deviceName=Loe deviceVariant=volumio deviceModel= softwareVersion=4.096 Mar 04 19:09:33 loe volumio[1260]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Mar 04 19:09:33 loe volumio[1260]: info: CoreCommandRouter::volumioGetState Mar 04 19:09:33 loe volumio[1260]: info: Received Get System Info Mar 04 19:09:33 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 04 19:09:33 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 04 19:09:33 loe volumio[1260]: info: Discovery: Getting this device information Mar 04 19:09:33 loe volumio[1260]: info: CoreCommandRouter::volumioGetState Mar 04 19:09:33 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 19:09:33 loe go-librespot[2164]: time="2026-03-04T19:09:33+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 19:09:33 loe go-librespot[2164]: time="2026-03-04T19:09:33+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 19:09:33 loe go-librespot[2164]: time="2026-03-04T19:09:33+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 19:09:33 loe go-librespot[2164]: time="2026-03-04T19:09:33+01:00" level=info msg="zeroconf server listening on port 33043" Mar 04 19:09:33 loe volumio[1260]: info: CoreCommandRouter::volumioGetState Mar 04 19:09:33 loe go-librespot[2164]: time="2026-03-04T19:09:33+01:00" level=debug msg="obtained new client token: AAAMoVqFOABDOZec2YatWSpV66nZPKgWM+wrDxk/maBO3caxOOsN+I/T1bTmn4/RLRUo6vQ8Zwy2b+JBErIGLXRiYqMMevVjWWbh8h39EnMguZIcwUgIpdYiOfKh0sd5ZvRr+6lh3DAmLk19rRaVN4eVLBOR7KRhl90gs2UYBljInaMWLxC2ThJJbkD7pUu3PTL0677cxgLpsEp1bDN6/3YKUvgWdJwj0ECHFyxUIdt02VER69+afxrMNA==" Mar 04 19:09:33 loe go-librespot[2164]: time="2026-03-04T19:09:33+01:00" level=debug msg="new websocket client" Mar 04 19:09:33 loe go-librespot[2164]: time="2026-03-04T19:09:33+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 19:09:33 loe go-librespot[2164]: time="2026-03-04T19:09:33+01:00" level=debug msg="completed keyexchange" Mar 04 19:09:33 loe go-librespot[2164]: time="2026-03-04T19:09:33+01:00" level=debug msg="completed challenge" Mar 04 19:09:33 loe volumio[1260]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Mar 04 19:09:33 loe volumio[1260]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Mar 04 19:09:33 loe volumio[1260]: info: Starting Shairport Sync Mar 04 19:09:33 loe go-librespot[2164]: time="2026-03-04T19:09:33+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed peeking unencrypted bytes: failed peeking uncrypted: EOF" Mar 04 19:09:33 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 19:09:33 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 19:09:33 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 04 19:09:33 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 04 19:09:33 loe volumio[1260]: info: MRS: Found cast device: Chromecast-84d0dcfc86c31e08fb7722859cd1fe00 Mar 04 19:09:33 loe volumio[1260]: info: Adding audio output: Mar 04 19:09:33 loe volumio5-onboarding[2110]: time=2026-03-04T19:09:33.990+01:00 level=INFO msg="enabling local network discovery" Mar 04 19:09:34 loe volumio5-onboarding[2110]: time=2026-03-04T19:09:34.069+01:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 04 19:09:34 loe sudo[2177]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 19:09:34 loe sudo[2177]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 19:09:34 loe systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 04 19:09:34 loe systemd[1]: shairport-sync.service: Deactivated successfully. Mar 04 19:09:34 loe systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 19:09:34 loe systemd[1]: shairport-sync.service: Consumed 2.534s CPU time. Mar 04 19:09:34 loe systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 19:09:34 loe sudo[2177]: pam_unix(sudo:session): session closed for user root Mar 04 19:09:34 loe volumio[1260]: info: Connection to go-librespot Websocket established Mar 04 19:09:34 loe volumio[1260]: info: Received Get System Info Mar 04 19:09:34 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 04 19:09:34 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 04 19:09:34 loe volumio[1260]: info: Discovery: Getting this device information Mar 04 19:09:34 loe volumio[1260]: info: CoreCommandRouter::volumioGetState Mar 04 19:09:34 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 19:09:34 loe volumio[1260]: info: Successfully retrieved User Session From TIDAL Mar 04 19:09:35 loe volumio[1260]: info: Connection to go-librespot Websocket closed Mar 04 19:09:35 loe volumio[1260]: info: Shairport-Sync Started Mar 04 19:09:35 loe volumio-remote-updater[708]: Test mode disabled Mar 04 19:09:35 loe volumio-remote-updater[708]: Alpha mode disabled Mar 04 19:09:35 loe volumio-remote-updater[708]: Alpha legacy test mode disabled Mar 04 19:09:35 loe volumio[1260]: info: Successfully retrieved User Subscription From TIDAL Mar 04 19:09:35 loe volumio[1260]: info: Adding TIDAL to Browse Sources Mar 04 19:09:35 loe volumio[1260]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 19:09:35 loe volumio[1260]: info: [1772647775417] CoreMusicLibrary::Adding element TIDAL Mar 04 19:09:35 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 19:09:35 loe volumio[1260]: Cannot find translation for source TIDAL Mar 04 19:09:35 loe volumio[1260]: info: Adding TIDAL REST API Endpoints Mar 04 19:09:35 loe volumio[1260]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 04 19:09:35 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 04 19:09:35 loe sudo[2198]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Mar 04 19:09:35 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 04 19:09:35 loe sudo[2198]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 19:09:36 loe systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Mar 04 19:09:36 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 04 19:09:36 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 04 19:09:36 loe sudo[2198]: pam_unix(sudo:session): session closed for user root Mar 04 19:09:36 loe volumio[1260]: info: CoreCommandRouter::volumioGetState Mar 04 19:09:36 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Mar 04 19:09:36 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:09:37 loe volumio[1260]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.mjORZRjMx8YIlyGajvB2CXSYA5r2.a53384b16fd4d7a180fdac1b5068092c.state.status' Mar 04 19:09:37 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:09:37 loe go-librespot[2217]: go-librespot daemon starting... Mar 04 19:09:37 loe volumio[1260]: info: Executing endpoint tc_getconfig Mar 04 19:09:37 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Mar 04 19:09:37 loe vtcs[2215]: STARTING TidalConnect services, version: 1.6.1 Mar 04 19:09:37 loe vtcs[2215]: STARTED TidalConnect services. Mar 04 19:09:37 loe go-librespot[2218]: time="2026-03-04T19:09:37+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 19:09:37 loe go-librespot[2218]: time="2026-03-04T19:09:37+01:00" level=debug msg="app state loaded" Mar 04 19:09:37 loe go-librespot[2218]: time="2026-03-04T19:09:37+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 19:09:37 loe volumio[1260]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Mar 04 19:09:37 loe volumio[1260]: info: Executing endpoint tc_connect Mar 04 19:09:37 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Mar 04 19:09:37 loe volumio[1260]: info: Connecting to TidalConnect Mar 04 19:09:37 loe go-librespot[2218]: time="2026-03-04T19:09:37+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 04 19:09:37 loe go-librespot[2218]: time="2026-03-04T19:09:37+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 04 19:09:37 loe go-librespot[2218]: time="2026-03-04T19:09:37+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 04 19:09:37 loe volumio[1260]: info: Getting Spotify volume Mar 04 19:09:37 loe go-librespot[2218]: time="2026-03-04T19:09:37+01:00" level=info msg="zeroconf server listening on port 38843" Mar 04 19:09:37 loe volumio[1260]: info: CoreCommandRouter::servicePushState Mar 04 19:09:37 loe volumio[1260]: info: CoreStateMachine::pushState Mar 04 19:09:37 loe volumio[1260]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 19:09:37 loe volumio[1260]: info: CoreCommandRouter::volumioPushState Mar 04 19:09:37 loe volumio[1260]: info: MRS: Pushing multiroomSync output update for this device Mar 04 19:09:37 loe go-librespot[2218]: time="2026-03-04T19:09:37+01:00" level=debug msg="obtained new client token: AABrXEe5OoqcaWgeRAPSofZlUabzrkUBDzZG6kbRKXJq8zFQRxiQq1RD+G75cazAIMJAuL2xZ2OJ9riP2ikDPWyTHPcXYY/nCfCkbLAZ/goHo5oWyDr5Eh77hpryFqSKil72nPdDul59peLWuvkpa5m+sgHmiKBpMVGD7Wzl2feBR3n2aDX70zpWBicH+ccBukFVRvvJKqzlQoU+DVk6/0rAFYxgNf17sjbrDsCpTZ7DwHaWnS/UkuTChg==" Mar 04 19:09:38 loe volumio[1260]: info: MRS: Pushing multiroomSync output Mar 04 19:09:38 loe volumio[1260]: info: CoreCommandRouter::volumioGetState Mar 04 19:09:38 loe go-librespot[2218]: time="2026-03-04T19:09:38+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 19:09:38 loe volumio[1260]: info: CorePlayQueue::getTrack 0 Mar 04 19:09:38 loe volumio[1260]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received tidalconnect Mar 04 19:09:38 loe volumio[1260]: info: CoreCommandRouter::servicePushState Mar 04 19:09:38 loe volumio[1260]: info: CoreStateMachine::pushState Mar 04 19:09:38 loe volumio[1260]: info: CoreCommandRouter::volumioPushState Mar 04 19:09:38 loe volumio[1260]: info: MRS: Pushing multiroomSync output update for this device Mar 04 19:09:38 loe volumio[1260]: info: MRS: Pushing multiroomSync output Mar 04 19:09:38 loe volumio[1260]: info: CoreCommandRouter::volumioGetState Mar 04 19:09:38 loe volumio[1260]: info: CorePlayQueue::getTrack 0 Mar 04 19:09:38 loe volumio[1260]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received tidalconnect Mar 04 19:09:38 loe go-librespot[2218]: time="2026-03-04T19:09:38+01:00" level=debug msg="completed keyexchange" Mar 04 19:09:38 loe go-librespot[2218]: time="2026-03-04T19:09:38+01:00" level=debug msg="completed challenge" Mar 04 19:09:38 loe go-librespot[2218]: time="2026-03-04T19:09:38+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 19:09:38 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 19:09:38 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 19:09:38 loe volumio[1260]: info: Initializing connection to go-librespot Websocket Mar 04 19:09:38 loe volumio[1260]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 04 19:09:38 loe volumio[1260]: Error: socket hang up Mar 04 19:09:38 loe volumio[1260]: at connResetException (node:internal/errors:720:14) Mar 04 19:09:38 loe volumio[1260]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 04 19:09:38 loe volumio[1260]: at Socket.emit (node:events:526:35) Mar 04 19:09:38 loe volumio[1260]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 04 19:09:38 loe volumio[1260]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 04 19:09:38 loe volumio[1260]: code: 'ECONNRESET', Mar 04 19:09:38 loe volumio[1260]: response: undefined Mar 04 19:09:38 loe volumio[1260]: } Mar 04 19:09:38 loe volumio[1260]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 04 19:09:41 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Mar 04 19:09:41 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:09:41 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:09:41 loe go-librespot[2252]: go-librespot daemon starting... Mar 04 19:09:41 loe go-librespot[2253]: time="2026-03-04T19:09:41+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 19:09:41 loe go-librespot[2253]: time="2026-03-04T19:09:41+01:00" level=debug msg="app state loaded" Mar 04 19:09:41 loe go-librespot[2253]: time="2026-03-04T19:09:41+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 19:09:42 loe go-librespot[2253]: time="2026-03-04T19:09:42+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 19:09:42 loe go-librespot[2253]: time="2026-03-04T19:09:42+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 19:09:42 loe go-librespot[2253]: time="2026-03-04T19:09:42+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 19:09:42 loe go-librespot[2253]: time="2026-03-04T19:09:42+01:00" level=info msg="zeroconf server listening on port 46185" Mar 04 19:09:42 loe go-librespot[2253]: time="2026-03-04T19:09:42+01:00" level=debug msg="obtained new client token: AADKHwJLQBtvY8QiwQU/5YXXAirMJVPsiEqmNIRFw05HfZjqFWnXJuLqv0SxBod0bi/wm4UDTmkKMpeQ9wBp9o5SrHMvbiqczIi0RlW+1ChYEU0oMs6w3dckRRDgsYPXMALCwVeNe5HafwCYz46iAXnxlTgrtk7dA3ssscDUnvdLIlS6G96MN2EluwVHMYarDpxkiPzCIywMiKKnjqb7+x4J+INIxauZCKGVS3LB7QIk8+76YCvtFk0Rjw==" Mar 04 19:09:42 loe go-librespot[2253]: time="2026-03-04T19:09:42+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 19:09:42 loe go-librespot[2253]: time="2026-03-04T19:09:42+01:00" level=debug msg="completed keyexchange" Mar 04 19:09:42 loe go-librespot[2253]: time="2026-03-04T19:09:42+01:00" level=debug msg="completed challenge" Mar 04 19:09:42 loe go-librespot[2253]: time="2026-03-04T19:09:42+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 19:09:42 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 19:09:42 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 19:09:45 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Mar 04 19:09:45 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:09:46 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:09:46 loe go-librespot[2260]: go-librespot daemon starting... Mar 04 19:09:46 loe go-librespot[2261]: time="2026-03-04T19:09:46+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 19:09:46 loe go-librespot[2261]: time="2026-03-04T19:09:46+01:00" level=debug msg="app state loaded" Mar 04 19:09:46 loe go-librespot[2261]: time="2026-03-04T19:09:46+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 19:09:46 loe go-librespot[2261]: time="2026-03-04T19:09:46+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 19:09:46 loe go-librespot[2261]: time="2026-03-04T19:09:46+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 19:09:46 loe go-librespot[2261]: time="2026-03-04T19:09:46+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 19:09:46 loe go-librespot[2261]: time="2026-03-04T19:09:46+01:00" level=info msg="zeroconf server listening on port 40651" Mar 04 19:09:46 loe go-librespot[2261]: time="2026-03-04T19:09:46+01:00" level=debug msg="obtained new client token: AACpufsZsGG3qly4mkJbQNnlyKMUVFJENFqj8XdmwP6hmR6fbnNh7W6MeGmjTs2lRt9ol7p0der8a/JURo00qXLYafI1qiPsRrbaiZAf8l4sEZKYxDmcENVm4mJVtLYt81DLt8YP/sCLkkTG01VQ3AMRnjzWSe5MSE/cuDXkHkaXaq/5bIU+IB3NAB6LaJmPAP88uERvTPtidN25XXpT+8tqa1A9Chlu9Z8K98IidUPWE6MxBlnkYEHASA==" Mar 04 19:09:46 loe go-librespot[2261]: time="2026-03-04T19:09:46+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 19:09:47 loe go-librespot[2261]: time="2026-03-04T19:09:47+01:00" level=debug msg="completed keyexchange" Mar 04 19:09:47 loe go-librespot[2261]: time="2026-03-04T19:09:47+01:00" level=debug msg="completed challenge" Mar 04 19:09:47 loe go-librespot[2261]: time="2026-03-04T19:09:47+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 19:09:47 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 19:09:47 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 19:09:48 loe sudo[2285]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-04 19:08' Mar 04 19:09:48 loe sudo[2285]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 19:09:50 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Mar 04 19:09:50 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:09:50 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 19:09:50 loe go-librespot[2287]: go-librespot daemon starting... Mar 04 19:09:50 loe go-librespot[2288]: time="2026-03-04T19:09:50+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 19:09:50 loe go-librespot[2288]: time="2026-03-04T19:09:50+01:00" level=debug msg="app state loaded" Mar 04 19:09:50 loe go-librespot[2288]: time="2026-03-04T19:09:50+01:00" level=info msg="api server listening on 127.0.0.1:9879" 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="a78d359cf1dc63ac74e9d151015afd30d31a709a" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Feb 5 14:07:07 UTC 2026" VOLUMIO_VERSION="4.096" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5e37060f9823263a753eb5e84030104f"