Aug 26 20:51:00 volumio volumio[2013]: error: MPD error: The expression evaluated to a falsy value: Aug 26 20:51:00 volumio volumio[2013]: assert.ok(self.idling) Aug 26 20:51:00 volumio volumio[2013]: error: The expression evaluated to a falsy value: Aug 26 20:51:00 volumio volumio[2013]: assert.ok(self.idling) Aug 26 20:51:00 volumio volumio[2013]: 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 Aug 26 20:51:00 volumio volumio[2013]: info: MPD running with PID2323 Aug 26 20:51:00 volumio volumio[2013]: ,establishing connection Aug 26 20:51:01 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:51:01 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:51:01 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:51:01 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:51:01 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:51:01 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:51:01 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:51:01 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:51:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 26 20:51:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:51:01 volumio go-librespot[2424]: go-librespot daemon starting... Aug 26 20:51:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:51:01 volumio go-librespot[2426]: time="2026-08-26T20:51:01-06:00" level=info msg="running go-librespot 0.7.1" Aug 26 20:51:01 volumio go-librespot[2426]: time="2026-08-26T20:51:01-06:00" level=debug msg="app state loaded" Aug 26 20:51:01 volumio go-librespot[2426]: time="2026-08-26T20:51:01-06:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 20:51:01 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 20:51:01 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:51:01 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:51:01 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:51:01 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:51:01 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:51:01 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:51:01 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:51:01 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:51:01 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:51:01 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 20:51:01 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:51:01 volumio volumio[2013]: info: No need to fix Spotify hosts Aug 26 20:51:01 volumio go-librespot[2426]: time="2026-08-26T20:51:01-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 26 20:51:01 volumio go-librespot[2426]: time="2026-08-26T20:51:01-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 26 20:51:01 volumio go-librespot[2426]: time="2026-08-26T20:51:01-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 26 20:51:02 volumio go-librespot[2426]: time="2026-08-26T20:51:02-06:00" level=info msg="zeroconf server listening on port 41511" Aug 26 20:51:02 volumio go-librespot[2426]: time="2026-08-26T20:51:02-06:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 20:51:02 volumio go-librespot[2426]: time="2026-08-26T20:51:02-06:00" level=debug msg="obtained new client token: AAHPBaNzjE9whHcGfzzAFHZkatoGdvn0A+hHIIRioiiGIUfl5nUQJZbrHzBjcDue4rr+vdcpaCQFdFp8IH2rUpLUECNFw2MRDp1my9DIfKF43w+binsoRqCxwg7891dp0d+mEk4iU4seV9+qVEwfwmMCNhncSr08SBkxxi+Sjp9h9EpLptUrugWZS/sAYCnyJztN04cX/n3ZQz4kW9PRGrdThIqFP1GxAU2E8KTEwhAPq4zwl2iZpg==" Aug 26 20:51:02 volumio go-librespot[2426]: time="2026-08-26T20:51:02-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 26 20:51:02 volumio go-librespot[2426]: time="2026-08-26T20:51:02-06:00" level=debug msg="completed keyexchange" Aug 26 20:51:02 volumio go-librespot[2426]: time="2026-08-26T20:51:02-06:00" level=debug msg="completed challenge" Aug 26 20:51:02 volumio volumio[2013]: error: updateQueue error: null Aug 26 20:51:02 volumio go-librespot[2426]: time="2026-08-26T20:51:02-06:00" level=info msg="authenticated AP" username="tm****ke" Aug 26 20:51:02 volumio go-librespot[2426]: time="2026-08-26T20:51:02-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 20:51:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 20:51:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 20:51:03 volumio volumio[2013]: 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 Aug 26 20:51:03 volumio volumio[2013]: info: Received Get System Info Aug 26 20:51:03 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 20:51:03 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 20:51:03 volumio volumio[2013]: info: Discovery: Getting this device information Aug 26 20:51:03 volumio volumio[2013]: info: CoreCommandRouter::volumioGetState Aug 26 20:51:03 volumio volumio[2013]: info: CorePlayQueue::getTrack 0 Aug 26 20:51:03 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 20:51:03 volumio volumio5-onboarding[2383]: time=2026-08-26T20:51:03.434-06:00 level=INFO msg="system info for f4469a921dbd9a63301124ccdad4ae13" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.119 Aug 26 20:51:03 volumio volumio5-onboarding[2383]: time=2026-08-26T20:51:03.453-06:00 level=INFO msg="bootstrapping state" hasInternet=true Aug 26 20:51:03 volumio volumio[2013]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Aug 26 20:51:04 volumio volumio[2013]: info: Received Get System Info Aug 26 20:51:04 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 20:51:04 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 20:51:04 volumio volumio[2013]: info: Discovery: Getting this device information Aug 26 20:51:04 volumio volumio[2013]: info: CoreCommandRouter::volumioGetState Aug 26 20:51:04 volumio volumio[2013]: info: CorePlayQueue::getTrack 0 Aug 26 20:51:04 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 20:51:05 volumio volumio[2013]: info: New Spotify access tokenBQDXh2HVFs... Aug 26 20:51:05 volumio volumio[2013]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 26 20:51:05 volumio volumio-remote-updater[680]: Test mode disabled Aug 26 20:51:05 volumio volumio-remote-updater[680]: Alpha mode disabled Aug 26 20:51:05 volumio volumio-remote-updater[680]: Alpha legacy test mode disabled Aug 26 20:51:05 volumio volumio[2013]: error: updateQueue error: null Aug 26 20:51:05 volumio volumio[2013]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Aug 26 20:51:05 volumio volumio[2013]: info: Starting Shairport Sync Aug 26 20:51:05 volumio volumio[2013]: info: Starting Shairport Sync Aug 26 20:51:05 volumio volumio[2013]: info: Starting Shairport Sync Aug 26 20:51:05 volumio sudo[2487]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 26 20:51:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 26 20:51:05 volumio sudo[2487]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 20:51:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:51:05 volumio sudo[2485]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 26 20:51:05 volumio sudo[2485]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 20:51:05 volumio volumio[2013]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Aug 26 20:51:05 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Aug 26 20:51:05 volumio sudo[2489]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 26 20:51:06 volumio sudo[2489]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 20:51:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:51:06 volumio go-librespot[2492]: go-librespot daemon starting... Aug 26 20:51:06 volumio go-librespot[2494]: time="2026-08-26T20:51:06-06:00" level=info msg="running go-librespot 0.7.1" Aug 26 20:51:06 volumio go-librespot[2494]: time="2026-08-26T20:51:06-06:00" level=debug msg="app state loaded" Aug 26 20:51:06 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 26 20:51:06 volumio go-librespot[2494]: time="2026-08-26T20:51:06-06:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 20:51:06 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Aug 26 20:51:06 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 26 20:51:06 volumio systemd[1]: shairport-sync.service: Consumed 2.872s CPU time. Aug 26 20:51:06 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 26 20:51:06 volumio sudo[2485]: pam_unix(sudo:session): session closed for user root Aug 26 20:51:06 volumio sudo[2487]: pam_unix(sudo:session): session closed for user root Aug 26 20:51:06 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 26 20:51:06 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Aug 26 20:51:06 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 26 20:51:06 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 26 20:51:06 volumio sudo[2489]: pam_unix(sudo:session): session closed for user root Aug 26 20:51:06 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 26 20:51:06 volumio volumio5-onboarding[2383]: time=2026-08-26T20:51:06.685-06:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Aug 26 20:51:06 volumio volumio5-onboarding[2383]: time=2026-08-26T20:51:06.688-06:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Aug 26 20:51:06 volumio volumio5-onboarding[2383]: time=2026-08-26T20:51:06.688-06:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" Aug 26 20:51:06 volumio go-librespot[2494]: time="2026-08-26T20:51:06-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 26 20:51:06 volumio go-librespot[2494]: time="2026-08-26T20:51:06-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 26 20:51:06 volumio go-librespot[2494]: time="2026-08-26T20:51:06-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 26 20:51:06 volumio go-librespot[2494]: time="2026-08-26T20:51:06-06:00" level=info msg="zeroconf server listening on port 39335" Aug 26 20:51:06 volumio go-librespot[2494]: time="2026-08-26T20:51:06-06:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 20:51:07 volumio volumio[2013]: info: go-librespot daemon successfully initialized Aug 26 20:51:07 volumio go-librespot[2494]: time="2026-08-26T20:51:07-06:00" level=debug msg="obtained new client token: AAEISHYc5mVa+bEpn+Wn9Z3+2K8dzTE0FLRrgsT59GvYQ2YxXgzAhv7TBrt8lPRa4rUTMrO6tQzciSTpoAXx4xhWfqxsp3mVdb5q++suqYrddb44OKufegahKmBr1NxsCS4o2yY2bop6xHUk8++jbmJkP3a1c3WQmRALw2KiR+v0uG4PPa5QiEza9+JY46AV5otgALTasKz+xO/zY7wMBR7RjPYN2hDeOGOAS7+KMNqZj0E0I8+m6A==" Aug 26 20:51:07 volumio volumio[2013]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Aug 26 20:51:07 volumio volumio[2013]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Aug 26 20:51:07 volumio volumio[2013]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Aug 26 20:51:07 volumio volumio[2013]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Aug 26 20:51:07 volumio volumio[2013]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Aug 26 20:51:07 volumio volumio[2013]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Aug 26 20:51:07 volumio volumio[2013]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Aug 26 20:51:07 volumio volumio[2013]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Aug 26 20:51:07 volumio volumio[2013]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Aug 26 20:51:07 volumio go-librespot[2494]: time="2026-08-26T20:51:07-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 26 20:51:07 volumio volumio[2013]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Aug 26 20:51:07 volumio volumio[2013]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Aug 26 20:51:07 volumio volumio[2013]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Aug 26 20:51:07 volumio volumio[2013]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Aug 26 20:51:07 volumio volumio[2013]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Aug 26 20:51:07 volumio volumio[2013]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Aug 26 20:51:07 volumio volumio[2013]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Aug 26 20:51:07 volumio volumio[2013]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Aug 26 20:51:07 volumio volumio[2013]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Aug 26 20:51:07 volumio volumio[2013]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Aug 26 20:51:07 volumio volumio[2013]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Aug 26 20:51:07 volumio volumio[2013]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Aug 26 20:51:07 volumio volumio[2013]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Aug 26 20:51:07 volumio volumio[2013]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Aug 26 20:51:07 volumio volumio[2013]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Aug 26 20:51:07 volumio volumio[2013]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Aug 26 20:51:07 volumio volumio[2013]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Aug 26 20:51:07 volumio volumio[2013]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Aug 26 20:51:07 volumio volumio[2013]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Aug 26 20:51:07 volumio go-librespot[2494]: time="2026-08-26T20:51:07-06:00" level=debug msg="completed keyexchange" Aug 26 20:51:07 volumio go-librespot[2494]: time="2026-08-26T20:51:07-06:00" level=debug msg="completed challenge" Aug 26 20:51:07 volumio volumio[2013]: info: Adding plugin bluetooth to MyMusic Plugins Aug 26 20:51:07 volumio go-librespot[2494]: time="2026-08-26T20:51:07-06:00" level=info msg="authenticated AP" username="tm****ke" Aug 26 20:51:07 volumio volumio[2013]: info: Adding plugin multiroom to MyMusic Plugins Aug 26 20:51:07 volumio volumio[2013]: info: Adding plugin metavolumio to MyMusic Plugins Aug 26 20:51:07 volumio volumio[2013]: info: Adding plugin cd_controller to MyMusic Plugins Aug 26 20:51:07 volumio volumio[2013]: info: Adding plugin qobuzconnect to MyMusic Plugins Aug 26 20:51:07 volumio volumio[2013]: info: Adding plugin smart_inputs to MyMusic Plugins Aug 26 20:51:07 volumio volumio[2013]: info: Adding plugin tidalconnect to MyMusic Plugins Aug 26 20:51:07 volumio volumio[2013]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Aug 26 20:51:07 volumio go-librespot[2494]: time="2026-08-26T20:51:07-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 20:51:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 20:51:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 20:51:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Aug 26 20:51:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:51:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:51:11 volumio go-librespot[2532]: go-librespot daemon starting... Aug 26 20:51:11 volumio go-librespot[2533]: time="2026-08-26T20:51:11-06:00" level=info msg="running go-librespot 0.7.1" Aug 26 20:51:11 volumio go-librespot[2533]: time="2026-08-26T20:51:11-06:00" level=debug msg="app state loaded" Aug 26 20:51:11 volumio go-librespot[2533]: time="2026-08-26T20:51:11-06:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 20:51:11 volumio go-librespot[2533]: time="2026-08-26T20:51:11-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 26 20:51:11 volumio go-librespot[2533]: time="2026-08-26T20:51:11-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 26 20:51:11 volumio go-librespot[2533]: time="2026-08-26T20:51:11-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 26 20:51:11 volumio go-librespot[2533]: time="2026-08-26T20:51:11-06:00" level=info msg="zeroconf server listening on port 44817" Aug 26 20:51:11 volumio go-librespot[2533]: time="2026-08-26T20:51:11-06:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 20:51:11 volumio go-librespot[2533]: time="2026-08-26T20:51:11-06:00" level=debug msg="obtained new client token: AAGw0nxoD1tMFEoQgdYziVxe8l67nsHOh8/gDCOG1xukrLej3TOFrcSSnyalrnq/UsE2HAp+21ZOe/8dvuw7yLWqMIxhpHhXeNW/I66k71ZEdKdyDBRx/z5p3ldb9yi9HvzqsBirjuZV56+/inLqkVDaDvuFjv7Zz7kdXQRShW+sc3k4v4rIIKoK/aFUFSMXnOFmN4lDJFsoxuWuVAWf0VLIHe2HIycfjT4JaPC4c44Zj7atbdJNIhxE" Aug 26 20:51:12 volumio go-librespot[2533]: time="2026-08-26T20:51:12-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Aug 26 20:51:12 volumio go-librespot[2533]: time="2026-08-26T20:51:12-06:00" level=debug msg="connected to ap-guc3.spotify.com:443" Aug 26 20:51:12 volumio go-librespot[2533]: time="2026-08-26T20:51:12-06:00" level=debug msg="completed keyexchange" Aug 26 20:51:12 volumio go-librespot[2533]: time="2026-08-26T20:51:12-06:00" level=debug msg="completed challenge" Aug 26 20:51:12 volumio go-librespot[2533]: time="2026-08-26T20:51:12-06:00" level=info msg="authenticated AP" username="tm****ke" Aug 26 20:51:12 volumio go-librespot[2533]: time="2026-08-26T20:51:12-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 20:51:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 20:51:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 20:51:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Aug 26 20:51:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:51:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:51:15 volumio go-librespot[2556]: go-librespot daemon starting... Aug 26 20:51:15 volumio go-librespot[2557]: time="2026-08-26T20:51:15-06:00" level=info msg="running go-librespot 0.7.1" Aug 26 20:51:15 volumio go-librespot[2557]: time="2026-08-26T20:51:15-06:00" level=debug msg="app state loaded" Aug 26 20:51:15 volumio go-librespot[2557]: time="2026-08-26T20:51:15-06:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 20:51:16 volumio go-librespot[2557]: time="2026-08-26T20:51:16-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 26 20:51:16 volumio go-librespot[2557]: time="2026-08-26T20:51:16-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 26 20:51:16 volumio go-librespot[2557]: time="2026-08-26T20:51:16-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 26 20:51:16 volumio go-librespot[2557]: time="2026-08-26T20:51:16-06:00" level=info msg="zeroconf server listening on port 39385" Aug 26 20:51:16 volumio go-librespot[2557]: time="2026-08-26T20:51:16-06:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 20:51:16 volumio go-librespot[2557]: time="2026-08-26T20:51:16-06:00" level=debug msg="obtained new client token: AAGXUzSkCEyAtd/v7WkWc4327cqQDPcS+UK4oa1IGnVIiNBsKfjagLw0aQQ/7fkpFdQIyBhqONl0l0LPso26WLgZqKxjb+EPqj/oGO38E4R6FfEscjEurv4dxwq2k+AJMUDYhD5GWkv4PgM+tIJ7IHQDgL1UDmCno7ILx7QK/Cyux7ug5AE5VHd3lqNXsH9vGgDxgj+P6jbHfwC3QqQE3tuKyLcgCEg5IR5YpTSlK4SHlXl4zq3knpt4" Aug 26 20:51:16 volumio go-librespot[2557]: time="2026-08-26T20:51:16-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 26 20:51:17 volumio go-librespot[2557]: time="2026-08-26T20:51:17-06:00" level=debug msg="completed keyexchange" Aug 26 20:51:17 volumio go-librespot[2557]: time="2026-08-26T20:51:17-06:00" level=debug msg="completed challenge" Aug 26 20:51:17 volumio go-librespot[2557]: time="2026-08-26T20:51:17-06:00" level=info msg="authenticated AP" username="tm****ke" Aug 26 20:51:17 volumio go-librespot[2557]: time="2026-08-26T20:51:17-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 20:51:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 20:51:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 20:51:19 volumio volumio[2013]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Aug 26 20:51:19 volumio volumio[2013]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Aug 26 20:51:19 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 20:51:19 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 20:51:19 volumio volumio[2013]: info: Starting MyVolumio Remote Streaming Endpoints Aug 26 20:51:19 volumio volumio[2013]: info: MyVolumio login type: Token Aug 26 20:51:19 volumio volumio[2013]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Aug 26 20:51:19 volumio volumio[2013]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Aug 26 20:51:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Aug 26 20:51:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:51:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:51:20 volumio go-librespot[2567]: go-librespot daemon starting... Aug 26 20:51:20 volumio go-librespot[2568]: time="2026-08-26T20:51:20-06:00" level=info msg="running go-librespot 0.7.1" Aug 26 20:51:20 volumio go-librespot[2568]: time="2026-08-26T20:51:20-06:00" level=debug msg="app state loaded" Aug 26 20:51:20 volumio go-librespot[2568]: time="2026-08-26T20:51:20-06:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 20:51:21 volumio go-librespot[2568]: time="2026-08-26T20:51:21-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 26 20:51:21 volumio go-librespot[2568]: time="2026-08-26T20:51:21-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 26 20:51:21 volumio go-librespot[2568]: time="2026-08-26T20:51:21-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 26 20:51:21 volumio go-librespot[2568]: time="2026-08-26T20:51:21-06:00" level=info msg="zeroconf server listening on port 39839" Aug 26 20:51:21 volumio go-librespot[2568]: time="2026-08-26T20:51:21-06:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 20:51:21 volumio go-librespot[2568]: time="2026-08-26T20:51:21-06:00" level=debug msg="obtained new client token: AAFAFfcVQxwkQDoQZ36EzXhZl+pX/t4f1lQW+ekx2yXaZMXsbb4y/DSCLs2K1FgH78DDLgS2d39Nl4uotSYFSAyIiIAe0ZgiMsMFCk4qP+dOe4JZ1auCRSs+6aEUFCAwkx0EJzWqAr/8pQYGb5wo/bEYp8M1rKHaSdQZO5bE7jUPeGufvqXpfWJ58az/+yyuY49z23j+LIaxcZNI91EAxgqP/3vI1JnJMY2V1NGH0oZEn1PAR/3l9EIP" Aug 26 20:51:21 volumio go-librespot[2568]: time="2026-08-26T20:51:21-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 26 20:51:21 volumio go-librespot[2568]: time="2026-08-26T20:51:21-06:00" level=debug msg="completed keyexchange" Aug 26 20:51:21 volumio go-librespot[2568]: time="2026-08-26T20:51:21-06:00" level=debug msg="completed challenge" Aug 26 20:51:22 volumio go-librespot[2568]: time="2026-08-26T20:51:22-06:00" level=info msg="authenticated AP" username="tm****ke" Aug 26 20:51:22 volumio go-librespot[2568]: time="2026-08-26T20:51:22-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 20:51:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 20:51:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 20:51:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Aug 26 20:51:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:51:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:51:25 volumio go-librespot[2593]: go-librespot daemon starting... Aug 26 20:51:25 volumio go-librespot[2595]: time="2026-08-26T20:51:25-06:00" level=info msg="running go-librespot 0.7.1" Aug 26 20:51:25 volumio go-librespot[2595]: time="2026-08-26T20:51:25-06:00" level=debug msg="app state loaded" Aug 26 20:51:25 volumio go-librespot[2595]: time="2026-08-26T20:51:25-06:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 20:51:26 volumio go-librespot[2595]: time="2026-08-26T20:51:26-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 26 20:51:26 volumio go-librespot[2595]: time="2026-08-26T20:51:26-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 26 20:51:26 volumio go-librespot[2595]: time="2026-08-26T20:51:26-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 26 20:51:26 volumio go-librespot[2595]: time="2026-08-26T20:51:26-06:00" level=info msg="zeroconf server listening on port 41467" Aug 26 20:51:26 volumio go-librespot[2595]: time="2026-08-26T20:51:26-06:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 20:51:26 volumio go-librespot[2595]: time="2026-08-26T20:51:26-06:00" level=debug msg="obtained new client token: AAE7MeW5g78sjAj6fDtejyFRfR+5Ui33HV7AOHng19tCnG1O6IY7wMcTz11NU5u07Q5nE0CfwZKf3TJQZ66MGLsMe3RdjLKr/WGLzw0RXqY5axgZ/IiCrA9QpeKkxx2EQmN0ud6vr46+4VpXkqitWF8bTN7yD6mto/TXzZrfKpsqBWgped12GWWtDdSXokuT6xHAFo2lNw2DXVewifev4etQQ4ku2LZt6ec3WqeqQzBjalocY0foZ7dP" Aug 26 20:51:26 volumio go-librespot[2595]: time="2026-08-26T20:51:26-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Aug 26 20:51:26 volumio go-librespot[2595]: time="2026-08-26T20:51:26-06:00" level=debug msg="connected to ap-guc3.spotify.com:443" Aug 26 20:51:26 volumio go-librespot[2595]: time="2026-08-26T20:51:26-06:00" level=debug msg="completed keyexchange" Aug 26 20:51:26 volumio go-librespot[2595]: time="2026-08-26T20:51:26-06:00" level=debug msg="completed challenge" Aug 26 20:51:26 volumio go-librespot[2595]: time="2026-08-26T20:51:26-06:00" level=info msg="authenticated AP" username="tm****ke" Aug 26 20:51:26 volumio go-librespot[2595]: time="2026-08-26T20:51:26-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 20:51:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 20:51:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 20:51:28 volumio volumio[2013]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Aug 26 20:51:28 volumio volumio[2013]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Aug 26 20:51:28 volumio volumio[2013]: info: Streaming services startup Aug 26 20:51:28 volumio volumio[2013]: info: Starting Streaming Daemon Aug 26 20:51:29 volumio volumio[2013]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Aug 26 20:51:29 volumio sudo[2605]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/systemctl restart volumio-streaming-daemon.service Aug 26 20:51:29 volumio sudo[2605]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 20:51:29 volumio sudo[2605]: pam_unix(sudo:session): session closed for user root Aug 26 20:51:29 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 26 20:51:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Aug 26 20:51:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:51:30 volumio volumio[2013]: info: Shairport-Sync Started Aug 26 20:51:30 volumio volumio[2013]: Error adding Membership: Error: addMembership EINVAL Aug 26 20:51:30 volumio volumio[2013]: info: Shairport-Sync Started Aug 26 20:51:30 volumio volumio[2013]: info: Shairport-Sync Started Aug 26 20:51:30 volumio volumio[2013]: info: Initializing connection to go-librespot Websocket Aug 26 20:51:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:51:30 volumio go-librespot[2611]: go-librespot daemon starting... Aug 26 20:51:30 volumio go-librespot[2612]: time="2026-08-26T20:51:30-06:00" level=info msg="running go-librespot 0.7.1" Aug 26 20:51:30 volumio go-librespot[2612]: time="2026-08-26T20:51:30-06:00" level=debug msg="app state loaded" Aug 26 20:51:30 volumio go-librespot[2612]: time="2026-08-26T20:51:30-06:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 20:51:30 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 26 20:51:30 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 20:51:30 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 26 20:51:31 volumio go-librespot[2612]: time="2026-08-26T20:51:31-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 26 20:51:31 volumio go-librespot[2612]: time="2026-08-26T20:51:31-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 26 20:51:31 volumio go-librespot[2612]: time="2026-08-26T20:51:31-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 26 20:51:31 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 26 20:51:31 volumio go-librespot[2612]: time="2026-08-26T20:51:31-06:00" level=info msg="zeroconf server listening on port 39087" Aug 26 20:51:31 volumio go-librespot[2612]: time="2026-08-26T20:51:31-06:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 20:51:31 volumio go-librespot[2612]: time="2026-08-26T20:51:31-06:00" level=debug msg="obtained new client token: AAFnjAPxkaceoDjz1sMVQFPvp1LSN7OesyLYHKS67VAEiwnco2+92S655X02OoMx/ZflFwap9iQj249JNsYFnZrmYGjaUnh1B0jK+0kqSqqC9y1YtT+OE//sXQzv6AC7EzdghPrBwAZ4xhf8dR0fgegbEG/9DjkJjHGUXk+rEmQCnKs1WmAQYDw9Eg6FNX2R1Mp86SmA7q3ejKc/jTLqT52v8ICE1UmCiKFv6xO6BCDxt3zUAzGNUYtg" Aug 26 20:51:31 volumio go-librespot[2612]: time="2026-08-26T20:51:31-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 26 20:51:31 volumio volumio[2013]: error: Cannot start Volumio Streaming Daemon Aug 26 20:51:31 volumio volumio[2013]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 26 20:51:31 volumio volumio[2013]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 26 20:51:31 volumio go-librespot[2612]: time="2026-08-26T20:51:31-06:00" level=debug msg="completed keyexchange" Aug 26 20:51:31 volumio go-librespot[2612]: time="2026-08-26T20:51:31-06:00" level=debug msg="completed challenge" Aug 26 20:51:31 volumio go-librespot[2612]: time="2026-08-26T20:51:31-06:00" level=info msg="authenticated AP" username="tm****ke" Aug 26 20:51:31 volumio volumio[2013]: info: Received Get System Info Aug 26 20:51:31 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 20:51:31 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 20:51:31 volumio volumio[2013]: info: Discovery: Getting this device information Aug 26 20:51:31 volumio volumio[2013]: info: CoreCommandRouter::volumioGetState Aug 26 20:51:31 volumio volumio[2013]: info: CorePlayQueue::getTrack 0 Aug 26 20:51:31 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 20:51:31 volumio go-librespot[2612]: time="2026-08-26T20:51:31-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 20:51:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 20:51:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 20:51:31 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 26 20:51:31 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 26 20:51:31 volumio volumio5-onboarding[2383]: time=2026-08-26T20:51:31.869-06:00 level=INFO msg="enabling local network discovery" Aug 26 20:51:31 volumio volumio[2013]: info: Error connecting to go-librespot Websocket: Error: socket hang up Aug 26 20:51:31 volumio volumio5-onboarding[2383]: time=2026-08-26T20:51:31.926-06:00 level=INFO msg="enabling BLE discovery" Aug 26 20:51:32 volumio volumio[2013]: info: CoreCommandRouter::volumioGetState Aug 26 20:51:32 volumio volumio[2013]: info: CorePlayQueue::getTrack 0 Aug 26 20:51:32 volumio volumio5-onboarding[2383]: time=2026-08-26T20:51:32.901-06:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 26 20:51:33 volumio volumio-remote-updater[680]: Test mode disabled Aug 26 20:51:33 volumio volumio-remote-updater[680]: Alpha mode disabled Aug 26 20:51:33 volumio volumio-remote-updater[680]: Alpha legacy test mode disabled Aug 26 20:51:33 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Aug 26 20:51:34 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 26 20:51:34 volumio volumio[2013]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Aug 26 20:51:34 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Aug 26 20:51:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Aug 26 20:51:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:51:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:51:34 volumio go-librespot[2632]: go-librespot daemon starting... Aug 26 20:51:35 volumio go-librespot[2637]: time="2026-08-26T20:51:35-06:00" level=info msg="running go-librespot 0.7.1" Aug 26 20:51:35 volumio go-librespot[2637]: time="2026-08-26T20:51:35-06:00" level=debug msg="app state loaded" Aug 26 20:51:35 volumio go-librespot[2637]: time="2026-08-26T20:51:35-06:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 20:51:35 volumio volumio[2013]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Aug 26 20:51:35 volumio go-librespot[2637]: time="2026-08-26T20:51:35-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 26 20:51:35 volumio go-librespot[2637]: time="2026-08-26T20:51:35-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 26 20:51:35 volumio go-librespot[2637]: time="2026-08-26T20:51:35-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 26 20:51:35 volumio go-librespot[2637]: time="2026-08-26T20:51:35-06:00" level=info msg="zeroconf server listening on port 43489" Aug 26 20:51:35 volumio go-librespot[2637]: time="2026-08-26T20:51:35-06:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 20:51:35 volumio volumio[2013]: info: Initializing connection to go-librespot Websocket Aug 26 20:51:35 volumio go-librespot[2637]: time="2026-08-26T20:51:35-06:00" level=debug msg="obtained new client token: AAEqlrIdofaJd74EGyxIEkTnn+DnX3+XfPjoEVyiUCDVtMhOoTDDZEfTjE1E/PKCQo7K4KgFrQdUIAF97Z8jiTQYLjxqldBGGvJm5oCOAfdW9Ue0cJbcTaGc5bVFFs7rRkWJzpoGo+rZZHh32PFlJ/JwsNE4/3oP0Q4xthOpjiml5jCHhCYsD44okCV47lXG3Hd7yavpkA3/Zc2azd5fvMrnpPoNF0L0qjNKLKhtqLwdEDP0q3DEwcnN" Aug 26 20:51:35 volumio volumio[2013]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Aug 26 20:51:35 volumio go-librespot[2637]: time="2026-08-26T20:51:35-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 26 20:51:35 volumio go-librespot[2637]: time="2026-08-26T20:51:35-06:00" level=debug msg="completed keyexchange" Aug 26 20:51:35 volumio go-librespot[2637]: time="2026-08-26T20:51:35-06:00" level=debug msg="completed challenge" Aug 26 20:51:36 volumio go-librespot[2637]: time="2026-08-26T20:51:36-06:00" level=info msg="authenticated AP" username="tm****ke" Aug 26 20:51:36 volumio go-librespot[2637]: time="2026-08-26T20:51:36-06:00" level=debug msg="new websocket client" Aug 26 20:51:36 volumio go-librespot[2637]: time="2026-08-26T20:51:36-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 20:51:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 20:51:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 20:51:36 volumio volumio[2013]: info: Connection to go-librespot Websocket established Aug 26 20:51:37 volumio volumio[2013]: SPOTIFY: User informations: {"account_id":"Dp60g7c0rV","country":"CA","display_name":"tmstooke","email":"thomas+spotify@mnemonist.ca","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/tmstooke"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/tmstooke","id":"tmstooke","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee856fb3e930b1992dd5dd69271d","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b826fb3e930b1992dd5dd69271d","width":64}],"product":"premium","type":"user","uri":"spotify:user:tmstooke"} Aug 26 20:51:37 volumio volumio[2013]: info: Spotify Successfully logged in Aug 26 20:51:37 volumio volumio[2013]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 26 20:51:37 volumio volumio[2013]: info: [1787799097112] CoreMusicLibrary::Adding element Spotify Aug 26 20:51:37 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 20:51:37 volumio volumio[2013]: Cannot find translation for source Spotify Aug 26 20:51:37 volumio volumio[2013]: info: Connection to go-librespot Websocket closed Aug 26 20:51:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Aug 26 20:51:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:51:39 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:51:39 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:51:39 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Aug 26 20:51:39 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Aug 26 20:51:39 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Aug 26 20:51:39 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Aug 26 20:51:39 volumio volumio[2013]: info: CoreCommandRouter::volumioGetBrowseSources Aug 26 20:51:39 volumio volumio[2013]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 26 20:51:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:51:39 volumio go-librespot[2654]: go-librespot daemon starting... Aug 26 20:51:39 volumio go-librespot[2655]: time="2026-08-26T20:51:39-06:00" level=info msg="running go-librespot 0.7.1" Aug 26 20:51:39 volumio go-librespot[2655]: time="2026-08-26T20:51:39-06:00" level=debug msg="app state loaded" Aug 26 20:51:39 volumio go-librespot[2655]: time="2026-08-26T20:51:39-06:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 20:51:39 volumio volumio[2013]: info: MyVolumio token set successfully Aug 26 20:51:39 volumio volumio[2013]: info: MYVOLUMIO: Adding device Aug 26 20:51:39 volumio volumio[2013]: info: MYVOLUMIO: Evaluating Server Aug 26 20:51:39 volumio volumio[2013]: info: CoreCommandRouter::volumioGetState Aug 26 20:51:39 volumio volumio[2013]: info: CorePlayQueue::getTrack 0 Aug 26 20:51:40 volumio volumio[2013]: info: Getting Spotify volume Aug 26 20:51:40 volumio go-librespot[2655]: time="2026-08-26T20:51:40-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 26 20:51:40 volumio go-librespot[2655]: time="2026-08-26T20:51:40-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 26 20:51:40 volumio go-librespot[2655]: time="2026-08-26T20:51:40-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 26 20:51:40 volumio go-librespot[2655]: time="2026-08-26T20:51:40-06:00" level=info msg="zeroconf server listening on port 40537" Aug 26 20:51:40 volumio go-librespot[2655]: time="2026-08-26T20:51:40-06:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 20:51:40 volumio go-librespot[2655]: time="2026-08-26T20:51:40-06:00" level=debug msg="obtained new client token: AAExVwrriW3H34ne/gEqhbT09oPZole6Twis2YuT7EUNUHiIdS9hvObnAuXuEtt/DmYyJIk6jh9aSG4NUOz4Wo+wmBGjl3/Psyujioeh+t5Ht31Pb8nptGdkMFijrLRNbG/FNqaIG89/E9TTi6xMuCHtRd8HNQSLftPHS5yRac29m5haQvkUtUIpNNaXiQXN6Q/EEhMv02Kr8NyCQwbUPNNJvKOcb8c/B4H4PVJeZ0BhW6+jW04gvsPP" Aug 26 20:51:40 volumio go-librespot[2655]: time="2026-08-26T20:51:40-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 26 20:51:40 volumio go-librespot[2655]: time="2026-08-26T20:51:40-06:00" level=debug msg="completed keyexchange" Aug 26 20:51:40 volumio go-librespot[2655]: time="2026-08-26T20:51:40-06:00" level=debug msg="completed challenge" Aug 26 20:51:40 volumio go-librespot[2655]: time="2026-08-26T20:51:40-06:00" level=info msg="authenticated AP" username="tm****ke" Aug 26 20:51:41 volumio go-librespot[2655]: time="2026-08-26T20:51:41-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 20:51:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 20:51:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 20:51:41 volumio volumio[2013]: info: MyVolumio status changed Aug 26 20:51:41 volumio volumio[2013]: info: Streaming services startup Aug 26 20:51:41 volumio volumio[2013]: info: Starting Streaming Daemon Aug 26 20:51:41 volumio volumio[2013]: info: Removing browser output: myVolumio user plan is not superstar Aug 26 20:51:41 volumio volumio[2013]: info: Removing audio output: Aug 26 20:51:41 volumio volumio[2013]: info: Stoppping Tunnel 1 Aug 26 20:51:42 volumio volumio[2013]: info: Initializing connection to go-librespot Websocket Aug 26 20:51:42 volumio sudo[2683]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/systemctl restart volumio-streaming-daemon.service Aug 26 20:51:42 volumio sudo[2683]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 20:51:42 volumio sudo[2685]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Aug 26 20:51:42 volumio sudo[2685]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 20:51:42 volumio volumio[2013]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 26 20:51:42 volumio sudo[2683]: pam_unix(sudo:session): session closed for user root Aug 26 20:51:42 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 26 20:51:42 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 26 20:51:42 volumio volumio[2013]: Error: socket hang up Aug 26 20:51:42 volumio volumio[2013]: at connResetException (node:internal/errors:720:14) Aug 26 20:51:42 volumio volumio[2013]: at Socket.socketOnEnd (node:_http_client:519:23) Aug 26 20:51:42 volumio volumio[2013]: at Socket.emit (node:events:526:35) Aug 26 20:51:42 volumio volumio[2013]: at endReadableNT (node:internal/streams/readable:1376:12) Aug 26 20:51:42 volumio volumio[2013]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Aug 26 20:51:42 volumio volumio[2013]: code: 'ECONNRESET', Aug 26 20:51:42 volumio volumio[2013]: response: undefined Aug 26 20:51:42 volumio volumio[2013]: } Aug 26 20:51:42 volumio volumio[2013]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 26 20:51:42 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 26 20:51:42 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 26 20:51:42 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 26 20:51:42 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 26 20:51:42 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 26 20:51:42 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 26 20:51:42 volumio sudo[2685]: pam_unix(sudo:session): session closed for user root Aug 26 20:51:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Aug 26 20:51:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:51:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:51:44 volumio go-librespot[2700]: go-librespot daemon starting... Aug 26 20:51:44 volumio go-librespot[2701]: time="2026-08-26T20:51:44-06:00" level=info msg="running go-librespot 0.7.1" Aug 26 20:51:44 volumio go-librespot[2701]: time="2026-08-26T20:51:44-06:00" level=debug msg="app state loaded" Aug 26 20:51:44 volumio go-librespot[2701]: time="2026-08-26T20:51:44-06:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 20:51:45 volumio go-librespot[2701]: time="2026-08-26T20:51:45-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 26 20:51:45 volumio go-librespot[2701]: time="2026-08-26T20:51:45-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 26 20:51:45 volumio go-librespot[2701]: time="2026-08-26T20:51:45-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 26 20:51:45 volumio go-librespot[2701]: time="2026-08-26T20:51:45-06:00" level=info msg="zeroconf server listening on port 42951" Aug 26 20:51:45 volumio go-librespot[2701]: time="2026-08-26T20:51:45-06:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 20:51:45 volumio go-librespot[2701]: time="2026-08-26T20:51:45-06:00" level=debug msg="obtained new client token: AAEMzoelONjqTegIPq17nIoNZN1yW5GF8CI3G3RqNpLI0iyrxtbVIXA5FKcCfAsOL1nt1TGGzO4Y8zhV0xX0+DZfiISN6e0qTimDk2GTO3flnLqzqCoXtOQuncft4wB3n3RE1BDRokReAfOHru4dM25AvwL0qHWNMxqcsk6I+tv87+kuVtaJyb0SdWUqfRFNSWl/q3TwMgv8u0iSThRAbOLXsjwcUq50xnbUkufIPgEnJ04eE8D6wbh8" Aug 26 20:51:45 volumio go-librespot[2701]: time="2026-08-26T20:51:45-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 26 20:51:45 volumio go-librespot[2701]: time="2026-08-26T20:51:45-06:00" level=debug msg="completed keyexchange" Aug 26 20:51:45 volumio go-librespot[2701]: time="2026-08-26T20:51:45-06:00" level=debug msg="completed challenge" Aug 26 20:51:45 volumio go-librespot[2701]: time="2026-08-26T20:51:45-06:00" level=info msg="authenticated AP" username="tm****ke" Aug 26 20:51:45 volumio go-librespot[2701]: time="2026-08-26T20:51:45-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 20:51:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 20:51:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 20:51:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Aug 26 20:51:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:51:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:51:49 volumio go-librespot[2728]: go-librespot daemon starting... Aug 26 20:51:49 volumio go-librespot[2729]: time="2026-08-26T20:51:49-06:00" level=info msg="running go-librespot 0.7.1" Aug 26 20:51:49 volumio go-librespot[2729]: time="2026-08-26T20:51:49-06:00" level=debug msg="app state loaded" Aug 26 20:51:49 volumio go-librespot[2729]: time="2026-08-26T20:51:49-06:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 20:51:49 volumio go-librespot[2729]: time="2026-08-26T20:51:49-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 26 20:51:49 volumio go-librespot[2729]: time="2026-08-26T20:51:49-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 26 20:51:49 volumio go-librespot[2729]: time="2026-08-26T20:51:49-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 26 20:51:49 volumio go-librespot[2729]: time="2026-08-26T20:51:49-06:00" level=info msg="zeroconf server listening on port 40657" Aug 26 20:51:49 volumio go-librespot[2729]: time="2026-08-26T20:51:49-06:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 20:51:50 volumio go-librespot[2729]: time="2026-08-26T20:51:50-06:00" level=debug msg="obtained new client token: AAF5Uf1p1ENOPsdlZKVL50KqWNyOHiG/qSJyq5ZInBctSUelcTjSX2ULVrezwBalHdCzdm+9vjsiW32ri4Y5xxQLf1Gk5QFDHc+7XLpxabOcEtdPWgOjKjMnuenq+8MGLVDEgEW4TszwC1Wtx/IVoJF/2yPbKouCcmKO416mrXsHjnbWd/cS0RKyOqpwt+v61qEwoaXegzBTWAaxK6CCkNwPW1G5AeIRTZzWTththLqcnJrJzEBUxA==" Aug 26 20:51:50 volumio go-librespot[2729]: time="2026-08-26T20:51:50-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 26 20:51:50 volumio go-librespot[2729]: time="2026-08-26T20:51:50-06:00" level=debug msg="completed keyexchange" Aug 26 20:51:50 volumio go-librespot[2729]: time="2026-08-26T20:51:50-06:00" level=debug msg="completed challenge" Aug 26 20:51:50 volumio go-librespot[2729]: time="2026-08-26T20:51:50-06:00" level=info msg="authenticated AP" username="tm****ke" Aug 26 20:51:50 volumio go-librespot[2729]: time="2026-08-26T20:51:50-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 20:51:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 20:51:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 20:51:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Aug 26 20:51:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:51:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:51:53 volumio go-librespot[2739]: go-librespot daemon starting... Aug 26 20:51:54 volumio go-librespot[2743]: time="2026-08-26T20:51:54-06:00" level=info msg="running go-librespot 0.7.1" Aug 26 20:51:54 volumio go-librespot[2743]: time="2026-08-26T20:51:54-06:00" level=debug msg="app state loaded" Aug 26 20:51:54 volumio go-librespot[2743]: time="2026-08-26T20:51:54-06:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 20:51:54 volumio sudo[2742]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-26 20:50' Aug 26 20:51:54 volumio sudo[2742]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 20:51:54 volumio go-librespot[2743]: time="2026-08-26T20:51:54-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 26 20:51:54 volumio go-librespot[2743]: time="2026-08-26T20:51:54-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 26 20:51:54 volumio go-librespot[2743]: time="2026-08-26T20:51:54-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 26 20:51:54 volumio go-librespot[2743]: time="2026-08-26T20:51:54-06:00" level=info msg="zeroconf server listening on port 44829" Aug 26 20:51:54 volumio go-librespot[2743]: time="2026-08-26T20:51:54-06:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 20:51:54 volumio go-librespot[2743]: time="2026-08-26T20:51:54-06:00" level=debug msg="obtained new client token: AAFeprvAZJqg+70rIFEVd2lo6HRMdwuFj7UnDBdMEGrbaFBjNfXwJQu6g9x4KANAkJ5RH/lk9zuTsjLUEDAlvrJpqaLusKvq8KmAmTYXcYqjSo8EYJn4T2fsq//yxCK8BaplIx7yyW8MonBZhLEPBcNncajXD8xEcs1vG0WOJjdvmGQI3WhYqWi/kTPsCwHUCA4Pp4yzGwf4OjCPdRo9xcCcj3TiNfu5wA5LXs9EqbyaCAE0JfEly4uC" Aug 26 20:51:55 volumio go-librespot[2743]: time="2026-08-26T20:51:55-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 26 20:51:55 volumio go-librespot[2743]: time="2026-08-26T20:51:55-06:00" level=debug msg="completed keyexchange" Aug 26 20:51:55 volumio go-librespot[2743]: time="2026-08-26T20:51:55-06:00" level=debug msg="completed challenge" Aug 26 20:51:55 volumio go-librespot[2743]: time="2026-08-26T20:51:55-06:00" level=info msg="authenticated AP" username="tm****ke" Aug 26 20:51:55 volumio go-librespot[2743]: time="2026-08-26T20:51:55-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 20:51:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 20:51:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 20:51:56 volumio sudo[2742]: pam_unix(sudo:session): session closed for user root Aug 26 20:51:57 volumio volumio5-onboarding[2383]: time=2026-08-26T20:51:57.624-06:00 level=ERROR msg="failed reading message" error="read tcp 127.0.0.1:41678->127.0.0.1:3000: read: connection reset by peer" Aug 26 20:51:57 volumio volumio-remote-updater[680]: [2026-08-26 20:51:57] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Aug 26 20:51:57 volumio volumio-remote-updater[680]: [2026-08-26 20:51:57] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Aug 26 20:51:57 volumio volumio5-onboarding[2383]: time=2026-08-26T20:51:57.633-06:00 level=WARN msg="reconnection attempt failed" error="read tcp 127.0.0.1:44666->127.0.0.1:3000: read: connection reset by peer" Aug 26 20:51:57 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Aug 26 20:51:57 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Aug 26 20:51:57 volumio systemd[1]: volumio.service: Consumed 3min 36.399s CPU time. Aug 26 20:51:57 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Aug 26 20:51:57 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 2. Aug 26 20:51:57 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Aug 26 20:51:57 volumio systemd[1]: volumio.service: Consumed 3min 36.399s CPU time. Aug 26 20:51:57 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Aug 26 20:51:57 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Aug 26 20:51:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Aug 26 20:51:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:51:58 volumio volumio5-onboarding[2383]: time=2026-08-26T20:51:58.637-06:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Aug 26 20:51:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:51:58 volumio go-librespot[2790]: go-librespot daemon starting... Aug 26 20:51:58 volumio go-librespot[2791]: time="2026-08-26T20:51:58-06:00" level=info msg="running go-librespot 0.7.1" Aug 26 20:51:58 volumio go-librespot[2791]: time="2026-08-26T20:51:58-06:00" level=debug msg="app state loaded" Aug 26 20:51:58 volumio go-librespot[2791]: time="2026-08-26T20:51:58-06:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 20:51:59 volumio go-librespot[2791]: time="2026-08-26T20:51:59-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 26 20:51:59 volumio go-librespot[2791]: time="2026-08-26T20:51:59-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 26 20:51:59 volumio go-librespot[2791]: time="2026-08-26T20:51:59-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 26 20:51:59 volumio go-librespot[2791]: time="2026-08-26T20:51:59-06:00" level=info msg="zeroconf server listening on port 43541" Aug 26 20:51:59 volumio go-librespot[2791]: time="2026-08-26T20:51:59-06:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 20:51:59 volumio volumio5-onboarding[2383]: time=2026-08-26T20:51:59.643-06:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Aug 26 20:51:59 volumio go-librespot[2791]: time="2026-08-26T20:51:59-06:00" level=debug msg="obtained new client token: AAFZ1SxR3DxpCW7pSMS0K+nM512s0qppR+Gz3kw9JfYGRVMMYnxl0c8JWj3NBIy5xKzQlMjtqNmim02tZAZHU8hfRduNyLr/RVU+Gjw70zq3+yfOHv1COXE9fi4H92y9ta+OivqW0Fte6XTqMrQMFEvB2sOk+UXqTi8s+c8ghUGQl79JjANf4rrTOx+o+G6V+cfQ6G59topUX1ylMPtMauDk4BfaXHtUfPaoBeAV5IST4AT9HjSsV0BS" Aug 26 20:51:59 volumio go-librespot[2791]: time="2026-08-26T20:51:59-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 26 20:52:00 volumio go-librespot[2791]: time="2026-08-26T20:52:00-06:00" level=debug msg="completed keyexchange" Aug 26 20:52:00 volumio go-librespot[2791]: time="2026-08-26T20:52:00-06:00" level=debug msg="completed challenge" Aug 26 20:52:00 volumio go-librespot[2791]: time="2026-08-26T20:52:00-06:00" level=info msg="authenticated AP" username="tm****ke" Aug 26 20:52:00 volumio go-librespot[2791]: time="2026-08-26T20:52:00-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 20:52:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 20:52:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 20:52:00 volumio volumio5-onboarding[2383]: time=2026-08-26T20:52:00.646-06:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Aug 26 20:52:01 volumio volumio5-onboarding[2383]: time=2026-08-26T20:52:01.649-06:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Aug 26 20:52:02 volumio volumio-remote-updater[680]: [2026-08-26 20:52:02] [connect] Successful connection Aug 26 20:52:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Aug 26 20:52:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:52:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:52:03 volumio go-librespot[2801]: go-librespot daemon starting... Aug 26 20:52:03 volumio go-librespot[2802]: time="2026-08-26T20:52:03-06:00" level=info msg="running go-librespot 0.7.1" Aug 26 20:52:03 volumio go-librespot[2802]: time="2026-08-26T20:52:03-06:00" level=debug msg="app state loaded" Aug 26 20:52:03 volumio go-librespot[2802]: time="2026-08-26T20:52:03-06:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 20:52:04 volumio go-librespot[2802]: time="2026-08-26T20:52:04-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 26 20:52:04 volumio go-librespot[2802]: time="2026-08-26T20:52:04-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 26 20:52:04 volumio go-librespot[2802]: time="2026-08-26T20:52:04-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 26 20:52:04 volumio go-librespot[2802]: time="2026-08-26T20:52:04-06:00" level=info msg="zeroconf server listening on port 33615" Aug 26 20:52:04 volumio go-librespot[2802]: time="2026-08-26T20:52:04-06:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 20:52:04 volumio go-librespot[2802]: time="2026-08-26T20:52:04-06:00" level=debug msg="obtained new client token: AAHfDmjTBSjBiCiN7eqSZ+eSO5GlJiIbU5nssAV5OHB/wQ+V1Drjo+WcyfegpFwMB4V+mGnCtrAPZocBso4ffRVzE2D/zC4JKl4AXDclMghSYu/w5B1X15FYfpkm3YtQCYZHL1m4vubTqoYGmmpdqDOyANlD0VWMknRCrZ6274C1Z8WL92KYcPfGKuGqGekSHd/tHb2nFWyDeOJjYaL1lWvVJIYP8py/qmnyobXiE06dBUhTaznxIccF" Aug 26 20:52:04 volumio volumio[2780]: info: ------------------------------------------- Aug 26 20:52:04 volumio volumio[2780]: info: ----- Volumio3 ---- Aug 26 20:52:04 volumio volumio[2780]: info: ------------------------------------------- Aug 26 20:52:04 volumio volumio[2780]: info: ----- System startup ---- Aug 26 20:52:04 volumio volumio[2780]: info: ------------------------------------------- Aug 26 20:52:04 volumio go-librespot[2802]: time="2026-08-26T20:52:04-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 26 20:52:04 volumio go-librespot[2802]: time="2026-08-26T20:52:04-06:00" level=debug msg="completed keyexchange" Aug 26 20:52:04 volumio go-librespot[2802]: time="2026-08-26T20:52:04-06:00" level=debug msg="completed challenge" Aug 26 20:52:04 volumio go-librespot[2802]: time="2026-08-26T20:52:04-06:00" level=info msg="authenticated AP" username="tm****ke" Aug 26 20:52:05 volumio go-librespot[2802]: time="2026-08-26T20:52:05-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 20:52:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 20:52:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 20:52:07 volumio volumio[2780]: info: MYVOLUMIO Environment detected Aug 26 20:52:07 volumio volumio[2780]: info: Plugin folders cleanup Aug 26 20:52:07 volumio volumio[2780]: info: Scanning into folder /volumio/app/plugins/ Aug 26 20:52:07 volumio volumio[2780]: info: Scanning category audio_interface Aug 26 20:52:07 volumio volumio[2780]: info: Scanning category miscellanea Aug 26 20:52:07 volumio volumio[2780]: info: Scanning category music_service Aug 26 20:52:07 volumio volumio[2780]: info: Scanning category plugins.json Aug 26 20:52:07 volumio volumio[2780]: info: Scanning category system_controller Aug 26 20:52:07 volumio volumio[2780]: info: Scanning category user_interface Aug 26 20:52:07 volumio volumio[2780]: info: Scanning into folder /data/plugins/ Aug 26 20:52:07 volumio volumio[2780]: info: Scanning category music_service Aug 26 20:52:07 volumio volumio[2780]: info: Plugin folders cleanup completed Aug 26 20:52:07 volumio volumio[2780]: info: ------------------------------------------- Aug 26 20:52:07 volumio volumio[2780]: info: ----- Core plugins startup ---- Aug 26 20:52:07 volumio volumio[2780]: info: ------------------------------------------- Aug 26 20:52:07 volumio volumio[2780]: info: Loading plugins from folder /volumio/app/plugins/ Aug 26 20:52:07 volumio volumio[2780]: info: Adding plugin upnp to MyMusic Plugins Aug 26 20:52:07 volumio volumio[2780]: info: Adding plugin airplay_emulation to MyMusic Plugins Aug 26 20:52:07 volumio volumio[2780]: info: Adding plugin upnp_browser to MyMusic Plugins Aug 26 20:52:07 volumio volumio[2780]: info: Loading plugins from folder /data/plugins/ Aug 26 20:52:07 volumio volumio[2780]: info: Loading plugin "system"... Aug 26 20:52:07 volumio volumio[2780]: info: Loading plugin "appearance"... Aug 26 20:52:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Aug 26 20:52:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:52:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:52:08 volumio go-librespot[2828]: go-librespot daemon starting... Aug 26 20:52:08 volumio go-librespot[2829]: time="2026-08-26T20:52:08-06:00" level=info msg="running go-librespot 0.7.1" Aug 26 20:52:08 volumio go-librespot[2829]: time="2026-08-26T20:52:08-06:00" level=debug msg="app state loaded" Aug 26 20:52:08 volumio go-librespot[2829]: time="2026-08-26T20:52:08-06:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 20:52:08 volumio go-librespot[2829]: time="2026-08-26T20:52:08-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 26 20:52:08 volumio go-librespot[2829]: time="2026-08-26T20:52:08-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 26 20:52:08 volumio go-librespot[2829]: time="2026-08-26T20:52:08-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 26 20:52:09 volumio go-librespot[2829]: time="2026-08-26T20:52:09-06:00" level=info msg="zeroconf server listening on port 40867" Aug 26 20:52:09 volumio go-librespot[2829]: time="2026-08-26T20:52:09-06:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 20:52:09 volumio go-librespot[2829]: time="2026-08-26T20:52:09-06:00" level=debug msg="obtained new client token: AAF/WlqATqFrzZ4oDrYwBYrjmnycMcRMO0E8Dud4uAnZjZSruxcztBLbopwpkdmh8S05/R/TIw8KMzmy5QdlO+kglrX1niyMdvZeot0zs7S28+GdwOTjj0egcSpgN5Ts4+uLmnihsHOUOSXMJBpat7q74AFPLoxD8kgzz5f3WLblNULBG12biY7RQj8DO4lntQdksY91pkipa1NTv6JRKqzdDh+G8qy3R+sqx8sGjdWFXXDGnN+iEg==" Aug 26 20:52:09 volumio go-librespot[2829]: time="2026-08-26T20:52:09-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 26 20:52:09 volumio go-librespot[2829]: time="2026-08-26T20:52:09-06:00" level=debug msg="completed keyexchange" Aug 26 20:52:09 volumio go-librespot[2829]: time="2026-08-26T20:52:09-06:00" level=debug msg="completed challenge" Aug 26 20:52:09 volumio go-librespot[2829]: time="2026-08-26T20:52:09-06:00" level=info msg="authenticated AP" username="tm****ke" Aug 26 20:52:09 volumio volumio[2780]: info: Loading plugin "network"... Aug 26 20:52:09 volumio volumio[2780]: info: Refreshing Cached IP Addresses Aug 26 20:52:09 volumio go-librespot[2829]: time="2026-08-26T20:52:09-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 20:52:09 volumio volumio[2780]: info: Loading plugin "services"... Aug 26 20:52:09 volumio volumio[2780]: info: Loading plugin "volumio5onboarding"... Aug 26 20:52:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 20:52:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 20:52:09 volumio volumio[2780]: info: Loading plugin "alsa_controller"... Aug 26 20:52:09 volumio sudo[2842]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 26 20:52:09 volumio sudo[2842]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 20:52:09 volumio sudo[2840]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 26 20:52:09 volumio sudo[2842]: pam_unix(sudo:session): session closed for user root Aug 26 20:52:09 volumio sudo[2840]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 20:52:09 volumio sudo[2840]: pam_unix(sudo:session): session closed for user root Aug 26 20:52:09 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 26 20:52:09 volumio volumio[2780]: info: Loading plugin "wizard"... Aug 26 20:52:09 volumio volumio[2780]: info: Loading plugin "networkfs"... Aug 26 20:52:09 volumio volumio[2780]: info: Starting Udev Watcher for removable devices Aug 26 20:52:10 volumio volumio[2780]: info: Ignoring mount for partition: boot Aug 26 20:52:10 volumio volumio[2780]: info: Ignoring mount for partition: volumio Aug 26 20:52:10 volumio volumio[2780]: info: Ignoring mount for partition: volumio_data Aug 26 20:52:10 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 26 20:52:10 volumio volumio[2780]: info: Loading plugin "volumio_command_line_client"... Aug 26 20:52:10 volumio volumio[2780]: info: Loading plugin "upnp"... Aug 26 20:52:10 volumio volumio[2780]: info: [1787799130030] Starting Upmpd Daemon Aug 26 20:52:10 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 26 20:52:10 volumio volumio[2780]: info: Loading plugin "my_music"... Aug 26 20:52:10 volumio volumio[2780]: info: Loading plugin "mpd"... Aug 26 20:52:10 volumio volumio[2780]: info: Loading plugin "upnp_browser"... Aug 26 20:52:12 volumio volumio5-onboarding[2383]: time=2026-08-26T20:52:12.651-06:00 level=WARN msg="reconnection attempt failed" error="read tcp 127.0.0.1:44732->127.0.0.1:3000: i/o timeout" Aug 26 20:52:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Aug 26 20:52:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:52:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:52:12 volumio go-librespot[2870]: go-librespot daemon starting... Aug 26 20:52:12 volumio go-librespot[2871]: time="2026-08-26T20:52:12-06:00" level=info msg="running go-librespot 0.7.1" Aug 26 20:52:12 volumio go-librespot[2871]: time="2026-08-26T20:52:12-06:00" level=debug msg="app state loaded" Aug 26 20:52:13 volumio go-librespot[2871]: time="2026-08-26T20:52:13-06:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 20:52:13 volumio go-librespot[2871]: time="2026-08-26T20:52:13-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 26 20:52:13 volumio go-librespot[2871]: time="2026-08-26T20:52:13-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 26 20:52:13 volumio go-librespot[2871]: time="2026-08-26T20:52:13-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 26 20:52:13 volumio volumio[2780]: info: Starting UPNP Browser Aug 26 20:52:13 volumio volumio[2780]: info: Loading plugin "alarm-clock"... Aug 26 20:52:13 volumio go-librespot[2871]: time="2026-08-26T20:52:13-06:00" level=info msg="zeroconf server listening on port 33103" Aug 26 20:52:13 volumio go-librespot[2871]: time="2026-08-26T20:52:13-06:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 20:52:13 volumio go-librespot[2871]: time="2026-08-26T20:52:13-06:00" level=debug msg="obtained new client token: AAEspn1N1GS09lpyRWqcQuOMlZFn7L926OffxZRryMILZw3UEcGWe39GbBKjb+ZGeJMRpD7YNkoekl0W4CIRR6skVjgc9wZn9o7YlHLXQyKWxtka63SnKLOeEpnieZIGm4pHOXDR2EJmT+5aBeMc3TDGZRg5Kq9G43Z6d4Mxd/c3zutpicIjTE0D2E0uU+qCyVZuPKudQpVTu/3Q+CRh40BVjijXHU6pZlx03yVsbv01LzjVOD7vSayc" Aug 26 20:52:13 volumio go-librespot[2871]: time="2026-08-26T20:52:13-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 26 20:52:13 volumio volumio[2780]: info: Loading plugin "airplay_emulation"... Aug 26 20:52:13 volumio volumio[2780]: info: Starting Shairport Sync Aug 26 20:52:13 volumio volumio[2780]: info: Loading plugin "last_100"... Aug 26 20:52:13 volumio volumio[2780]: info: Loading plugin "webradio"... Aug 26 20:52:13 volumio go-librespot[2871]: time="2026-08-26T20:52:13-06:00" level=debug msg="completed keyexchange" Aug 26 20:52:13 volumio go-librespot[2871]: time="2026-08-26T20:52:13-06:00" level=debug msg="completed challenge" Aug 26 20:52:13 volumio go-librespot[2871]: time="2026-08-26T20:52:13-06:00" level=info msg="authenticated AP" username="tm****ke" Aug 26 20:52:13 volumio volumio[2780]: info: Loading plugin "i2s_dacs"... Aug 26 20:52:14 volumio volumio[2780]: info: Loading plugin "volumiodiscovery"... Aug 26 20:52:14 volumio volumio[2780]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 26 20:52:14 volumio volumio[2780]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 26 20:52:14 volumio node[2780]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 26 20:52:14 volumio volumio[2780]: *** WARNING *** For more information see Aug 26 20:52:14 volumio volumio[2780]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 26 20:52:14 volumio volumio[2780]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 26 20:52:14 volumio volumio[2780]: *** WARNING *** For more information see Aug 26 20:52:14 volumio node[2780]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 26 20:52:14 volumio node[2780]: *** WARNING *** For more information see Aug 26 20:52:14 volumio node[2780]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 26 20:52:14 volumio node[2780]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 26 20:52:14 volumio node[2780]: *** WARNING *** For more information see Aug 26 20:52:14 volumio volumio[2780]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 26 20:52:14 volumio volumio[2780]: info: Discovery: Started advertising with name: Volumio Aug 26 20:52:14 volumio go-librespot[2871]: time="2026-08-26T20:52:14-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 20:52:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 20:52:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 20:52:14 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 26 20:52:14 volumio volumio[2780]: info: Loading plugin "spop"... Aug 26 20:52:15 volumio volumio-remote-updater[680]: [2026-08-26 20:52:15] [connect] Successful connection Aug 26 20:52:16 volumio volumio[2780]: info: Loading plugin "outputs"... Aug 26 20:52:16 volumio volumio[2780]: info: Loading plugin "albumart"... Aug 26 20:52:16 volumio volumio[2780]: info: Plugin example_plugin is not enabled Aug 26 20:52:16 volumio volumio[2780]: info: Loading plugin "inputs"... Aug 26 20:52:16 volumio volumio[2780]: info: Loading plugin "updater_comm"... Aug 26 20:52:16 volumio volumio[2780]: info: Plugin mpdemulation is not enabled Aug 26 20:52:16 volumio volumio[2780]: info: Loading plugin "rest_api"... Aug 26 20:52:16 volumio volumio[2780]: info: Loading plugin "websocket"... Aug 26 20:52:16 volumio volumio[2780]: info: Starting Socket.io Server version 1.7.4 Aug 26 20:52:16 volumio volumio[2780]: info: Loading i18n strings for locale en Aug 26 20:52:16 volumio volumio[2780]: Updating browse sources language Aug 26 20:52:16 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 20:52:16 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 26 20:52:16 volumio volumio[2780]: info: CoreCommandRouter::initPlayerControls Aug 26 20:52:16 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:52:16 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:52:16 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:52:16 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:52:16 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:52:16 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:52:16 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:52:16 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:52:16 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 26 20:52:16 volumio volumio[2780]: Express server listening on port 3000 Aug 26 20:52:16 volumio volumio[2780]: [Metrics] WebUI: 14s 224.12ms Aug 26 20:52:16 volumio volumio[2780]: info: CoreStateMachine::resetVolumioState Aug 26 20:52:16 volumio volumio[2780]: info: CoreStateMachine::getcurrentVolume Aug 26 20:52:16 volumio volumio[2780]: info: CoreCommandRouter::volumioRetrievevolume Aug 26 20:52:16 volumio volumio[2780]: info: Cannot read play queue from file Aug 26 20:52:16 volumio volumio[2780]: info: Volumio Network Manager: Network status updated: 1 Aug 26 20:52:17 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 20:52:17 volumio volumio[2882]: Forking 3 albumart workers Aug 26 20:52:17 volumio volumio[2780]: 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: 1 Aug 26 20:52:17 volumio volumio[2780]: info: VolumeController:: Volume=100 Mute =false Aug 26 20:52:17 volumio volumio[2780]: info: CoreStateMachine::pushState Aug 26 20:52:17 volumio volumio[2780]: info: CorePlayQueue::getTrack 0 Aug 26 20:52:17 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 26 20:52:17 volumio volumio[2780]: info: CoreCommandRouter::volumioPushState Aug 26 20:52:17 volumio volumio[2780]: info: CoreStateMachine::updateTrackBlock Aug 26 20:52:17 volumio volumio[2780]: info: CorePlayQueue::getTrackBlock Aug 26 20:52:17 volumio volumio[2780]: info: CoreCommandRouter::volumioRetrievevolume Aug 26 20:52:17 volumio volumio[2780]: info: CoreStateMachine::setRepeat null single undefined Aug 26 20:52:17 volumio volumio[2780]: info: CoreStateMachine::pushState Aug 26 20:52:17 volumio volumio[2780]: info: CorePlayQueue::getTrack 0 Aug 26 20:52:17 volumio volumio[2780]: info: CoreCommandRouter::volumioPushState Aug 26 20:52:17 volumio volumio[2780]: info: CoreStateMachine::setRandom null Aug 26 20:52:17 volumio volumio[2780]: info: CoreStateMachine::pushState Aug 26 20:52:17 volumio volumio[2780]: info: CorePlayQueue::getTrack 0 Aug 26 20:52:17 volumio volumio[2780]: info: CoreCommandRouter::volumioPushState Aug 26 20:52:17 volumio volumio[2780]: info: Setting Device type: Raspberry PI Aug 26 20:52:17 volumio volumio[2780]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Aug 26 20:52:17 volumio volumio[2780]: info: USB Boot Capable - System SBC Revision found in cpuinfo: a22082 Aug 26 20:52:17 volumio volumio[2780]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Aug 26 20:52:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Aug 26 20:52:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:52:17 volumio volumio-remote-updater[680]: [2026-08-26 20:52:17] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1787799135 101 Aug 26 20:52:17 volumio volumio[2780]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Aug 26 20:52:17 volumio volumio[2780]: info: Completed loading Core Plugins Aug 26 20:52:17 volumio volumio[2780]: info: Preparing to generate the ALSA configuration file Aug 26 20:52:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:52:17 volumio go-librespot[2931]: go-librespot daemon starting... Aug 26 20:52:17 volumio go-librespot[2934]: time="2026-08-26T20:52:17-06:00" level=info msg="running go-librespot 0.7.1" Aug 26 20:52:17 volumio go-librespot[2934]: time="2026-08-26T20:52:17-06:00" level=debug msg="app state loaded" Aug 26 20:52:17 volumio volumio[2780]: 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 Aug 26 20:52:17 volumio go-librespot[2934]: time="2026-08-26T20:52:17-06:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 20:52:17 volumio volumio[2780]: 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 Aug 26 20:52:17 volumio volumio[2780]: info: Discovery: adding eb45a37f-934b-4d48-b6f2-3cd6b9296ebf Aug 26 20:52:17 volumio volumio[2780]: info: Discovery: Found device Volumio Aug 26 20:52:17 volumio volumio[2780]: info: CoreCommandRouter::volumioGetState Aug 26 20:52:17 volumio volumio[2780]: info: CorePlayQueue::getTrack 0 Aug 26 20:52:17 volumio volumio[2780]: info: Discovery: this is already registered, eb45a37f-934b-4d48-b6f2-3cd6b9296ebf Aug 26 20:52:17 volumio volumio[2780]: info: Discovery: Found device Volumio Aug 26 20:52:17 volumio volumio[2780]: info: CoreCommandRouter::volumioGetState Aug 26 20:52:17 volumio volumio[2780]: info: CorePlayQueue::getTrack 0 Aug 26 20:52:17 volumio volumio[2780]: info: VolumeController:: Volume=100 Mute =false Aug 26 20:52:17 volumio volumio[2780]: info: CoreStateMachine::pushState Aug 26 20:52:17 volumio volumio[2780]: info: CorePlayQueue::getTrack 0 Aug 26 20:52:17 volumio volumio[2780]: info: CoreCommandRouter::volumioPushState Aug 26 20:52:17 volumio volumio[2780]: info: Asound.conf file unchanged, so no further update is needed Aug 26 20:52:17 volumio volumio[2780]: info: Output device has changed, restarting MPD Aug 26 20:52:17 volumio volumio[2780]: info: Output device has changed, restarting Shairport Sync Aug 26 20:52:17 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:52:17 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 20:52:17 volumio sudo[2946]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 26 20:52:17 volumio sudo[2946]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 20:52:17 volumio sudo[2946]: pam_unix(sudo:session): session closed for user root Aug 26 20:52:17 volumio sudo[2948]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 26 20:52:17 volumio sudo[2948]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 20:52:17 volumio volumio[2780]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 26 20:52:18 volumio volumio[2780]: info: ___________ START PLUGINS ___________ Aug 26 20:52:18 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Aug 26 20:52:18 volumio volumio[2780]: info: ControllerMpd::onStart: Initializing MPD Aug 26 20:52:18 volumio volumio[2780]: info: Creating MPD Configuration file Aug 26 20:52:18 volumio go-librespot[2934]: time="2026-08-26T20:52:18-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 26 20:52:18 volumio go-librespot[2934]: time="2026-08-26T20:52:18-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 26 20:52:18 volumio go-librespot[2934]: time="2026-08-26T20:52:18-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 26 20:52:18 volumio sudo[2957]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Aug 26 20:52:18 volumio systemd[1]: mpd.service: Deactivated successfully. Aug 26 20:52:18 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 26 20:52:18 volumio systemd[1]: mpd.service: Consumed 5.622s CPU time. Aug 26 20:52:18 volumio sudo[2957]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 20:52:18 volumio systemd[1]: mpd.socket: Deactivated successfully. Aug 26 20:52:18 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 26 20:52:18 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 26 20:52:18 volumio go-librespot[2934]: time="2026-08-26T20:52:18-06:00" level=info msg="zeroconf server listening on port 34285" Aug 26 20:52:18 volumio go-librespot[2934]: time="2026-08-26T20:52:18-06:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 20:52:18 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 26 20:52:18 volumio volumio[2780]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 26 20:52:18 volumio volumio[2780]: info: [1787799138295] CoreMusicLibrary::Adding element Media Servers Aug 26 20:52:18 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 20:52:18 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 26 20:52:18 volumio sudo[2959]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 26 20:52:18 volumio sudo[2959]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 20:52:18 volumio sudo[2959]: pam_unix(sudo:session): session closed for user root Aug 26 20:52:18 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Aug 26 20:52:18 volumio sudo[2963]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 26 20:52:18 volumio sudo[2963]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 20:52:18 volumio volumio[2780]: info: UPNP Browser: Client initialized successfully Aug 26 20:52:18 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:52:18 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 20:52:18 volumio go-librespot[2934]: time="2026-08-26T20:52:18-06:00" level=debug msg="obtained new client token: AAHBrd62+gZBu1EA5jP4SwxnxkqIEnSV6UWEhxjRilV4XtBfVnZ/Mud+K25Z1irIatY+F/PHajkwQu3UDRNmmbTaCfoDyotJafix2TZRUHZxCGNqn1IRmEb8S88+vARZBEBf9XKMReHT8qmoJuFIEjXYr+hWRVwMhf6Di0QOZ0WaKytH9LDIqEIOMBqNhFAD/5sBHm03rIyw0uGeRD40PPqpp+dAFnZzWKAt4C27AisvM8ZthjighrX4" Aug 26 20:52:18 volumio systemd[1]: mpd.service: Deactivated successfully. Aug 26 20:52:18 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 26 20:52:18 volumio systemd[1]: mpd.socket: Deactivated successfully. Aug 26 20:52:18 volumio volumio[2780]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 26 20:52:18 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:52:18 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 20:52:18 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 26 20:52:18 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 26 20:52:18 volumio sudo[2957]: pam_unix(sudo:session): session closed for user root Aug 26 20:52:18 volumio go-librespot[2934]: time="2026-08-26T20:52:18-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 26 20:52:18 volumio volumio[2780]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 26 20:52:18 volumio volumio[2780]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 26 20:52:18 volumio volumio[2780]: info: [1787799138601] CoreMusicLibrary::Adding element Last_100 Aug 26 20:52:18 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 20:52:18 volumio volumio[2780]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 26 20:52:18 volumio volumio[2780]: info: [1787799138612] CoreMusicLibrary::Adding element Webradio Aug 26 20:52:18 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 20:52:18 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 26 20:52:18 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Aug 26 20:52:18 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 26 20:52:18 volumio volumio[2780]: info: Initializing BBC Radios Aug 26 20:52:18 volumio go-librespot[2934]: time="2026-08-26T20:52:18-06:00" level=debug msg="completed keyexchange" Aug 26 20:52:18 volumio go-librespot[2934]: time="2026-08-26T20:52:18-06:00" level=debug msg="completed challenge" Aug 26 20:52:18 volumio go-librespot[2934]: time="2026-08-26T20:52:18-06:00" level=info msg="authenticated AP" username="tm****ke" Aug 26 20:52:18 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 26 20:52:18 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 20:52:18 volumio volumio[2780]: info: Creating Spotify config file Aug 26 20:52:18 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:52:18 volumio go-librespot[2934]: time="2026-08-26T20:52:18-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 20:52:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 20:52:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 20:52:19 volumio sudo[2976]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 26 20:52:19 volumio sudo[2976]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 26 20:52:19 volumio sudo[2976]: pam_unix(sudo:session): session closed for user root Aug 26 20:52:19 volumio volumio[2780]: info: Volumio Calling Home Aug 26 20:52:20 volumio volumio[2780]: 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 Aug 26 20:52:20 volumio volumio[2902]: Starting albumart workers Aug 26 20:52:20 volumio volumio[2780]: 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 Aug 26 20:52:20 volumio sudo[3010]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 26 20:52:20 volumio sudo[3010]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 20:52:20 volumio sudo[3012]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 26 20:52:20 volumio sudo[3012]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 20:52:20 volumio sudo[3010]: pam_unix(sudo:session): session closed for user root Aug 26 20:52:20 volumio sudo[3012]: pam_unix(sudo:session): session closed for user root Aug 26 20:52:20 volumio volumio[2780]: info: MPD Permissions set Aug 26 20:52:20 volumio volumio[2780]: info: MPD Permissions set Aug 26 20:52:20 volumio volumio[2780]: info: Spotify config file written Aug 26 20:52:20 volumio volumio[2904]: Starting albumart workers Aug 26 20:52:21 volumio sudo[3016]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/systemctl restart go-librespot-daemon.service Aug 26 20:52:21 volumio sudo[3016]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 20:52:21 volumio volumio[2903]: Starting albumart workers Aug 26 20:52:21 volumio volumio[2780]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Aug 26 20:52:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:52:21 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:52:21 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:52:21 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:52:21 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:52:21 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:52:21 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:52:21 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:52:21 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:52:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:52:21 volumio go-librespot[3018]: go-librespot daemon starting... Aug 26 20:52:21 volumio sudo[3016]: pam_unix(sudo:session): session closed for user root Aug 26 20:52:21 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 20:52:21 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:52:21 volumio go-librespot[3024]: time="2026-08-26T20:52:21-06:00" level=info msg="running go-librespot 0.7.1" Aug 26 20:52:21 volumio go-librespot[3024]: time="2026-08-26T20:52:21-06:00" level=debug msg="app state loaded" Aug 26 20:52:21 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:52:21 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:52:21 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:52:21 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:52:21 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:52:21 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:52:21 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:52:21 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:52:21 volumio go-librespot[3024]: time="2026-08-26T20:52:21-06:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 20:52:21 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 20:52:21 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 20:52:21 volumio volumio[2780]: info: No need to fix Spotify hosts Aug 26 20:52:22 volumio go-librespot[3024]: time="2026-08-26T20:52:22-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 26 20:52:22 volumio go-librespot[3024]: time="2026-08-26T20:52:22-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 26 20:52:22 volumio go-librespot[3024]: time="2026-08-26T20:52:22-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 26 20:52:22 volumio go-librespot[3024]: time="2026-08-26T20:52:22-06:00" level=info msg="zeroconf server listening on port 41701" Aug 26 20:52:22 volumio go-librespot[3024]: time="2026-08-26T20:52:22-06:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 20:52:22 volumio go-librespot[3024]: time="2026-08-26T20:52:22-06:00" level=debug msg="obtained new client token: AAHHnvoT7wBkre9V8iZK8y0r0Rfv5xuQqJHIlOPB3nymaSHR4VXj9rrWIIMwrMa78PgsIG1Puc7t5Njfr3yeO2xK80GXlQyl2vYbdFnvE7PGBfPVjfs/ei0TNANk3YhR1UcjyAJOLXVuXLHFDzjhax9GFIqfrqzCqzI/1LfcVv1Xx/+9DhBWLdp0OLavTdmxfIg3qnZbnhLWv61IvaprxcJH8CCom75tLD5FXF6nzYuH9R6dwe0hI58y" Aug 26 20:52:22 volumio go-librespot[3024]: time="2026-08-26T20:52:22-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Aug 26 20:52:22 volumio volumio[2780]: info: Volumio called home Aug 26 20:52:22 volumio go-librespot[3024]: time="2026-08-26T20:52:22-06:00" level=debug msg="connected to ap-guc3.spotify.com:443" Aug 26 20:52:22 volumio volumio[2780]: info: Starting Shairport Sync Aug 26 20:52:22 volumio volumio[2780]: info: Starting Shairport Sync Aug 26 20:52:22 volumio go-librespot[3024]: time="2026-08-26T20:52:22-06:00" level=debug msg="completed keyexchange" Aug 26 20:52:22 volumio go-librespot[3024]: time="2026-08-26T20:52:22-06:00" level=debug msg="completed challenge" Aug 26 20:52:22 volumio volumio[2780]: info: Starting Shairport Sync Aug 26 20:52:22 volumio go-librespot[3024]: time="2026-08-26T20:52:22-06:00" level=info msg="authenticated AP" username="tm****ke" Aug 26 20:52:22 volumio volumio[2780]: info: New Spotify access tokenBQClqVkamu... Aug 26 20:52:22 volumio volumio[2780]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 26 20:52:22 volumio sudo[3039]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 26 20:52:22 volumio sudo[3039]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 20:52:22 volumio sudo[3041]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 26 20:52:22 volumio sudo[3041]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 20:52:22 volumio sudo[3043]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 26 20:52:22 volumio sudo[3043]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 20:52:22 volumio sudo[3045]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Aug 26 20:52:22 volumio sudo[3045]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 20:52:22 volumio go-librespot[3024]: time="2026-08-26T20:52:22-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 20:52:22 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 26 20:52:22 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Aug 26 20:52:23 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 26 20:52:23 volumio systemd[1]: shairport-sync.service: Consumed 2.328s CPU time. Aug 26 20:52:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 20:52:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 20:52:23 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 26 20:52:23 volumio sudo[3039]: pam_unix(sudo:session): session closed for user root Aug 26 20:52:23 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 26 20:52:23 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Aug 26 20:52:23 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 26 20:52:23 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 26 20:52:23 volumio sudo[3041]: pam_unix(sudo:session): session closed for user root Aug 26 20:52:23 volumio sudo[3043]: pam_unix(sudo:session): session closed for user root Aug 26 20:52:23 volumio sudo[3045]: pam_unix(sudo:session): session closed for user root Aug 26 20:52:23 volumio volumio[2780]: info: Shairport-Sync Started Aug 26 20:52:23 volumio volumio[2780]: Error adding Membership: Error: addMembership EINVAL Aug 26 20:52:23 volumio volumio[2780]: info: Upmpdcli Daemon Started Aug 26 20:52:23 volumio volumio[2780]: info: Shairport-Sync Started Aug 26 20:52:23 volumio volumio[2780]: info: Shairport-Sync Started Aug 26 20:52:23 volumio volumio[2780]: info: CoreCommandRouter::volumioGetState Aug 26 20:52:23 volumio volumio[2780]: info: CorePlayQueue::getTrack 0 Aug 26 20:52:23 volumio volumio[2780]: SPOTIFY: User informations: {"account_id":"Dp60g7c0rV","country":"CA","display_name":"tmstooke","email":"thomas+spotify@mnemonist.ca","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/tmstooke"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/tmstooke","id":"tmstooke","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee856fb3e930b1992dd5dd69271d","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b826fb3e930b1992dd5dd69271d","width":64}],"product":"premium","type":"user","uri":"spotify:user:tmstooke"} Aug 26 20:52:23 volumio volumio[2780]: info: Spotify Successfully logged in Aug 26 20:52:23 volumio volumio[2780]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 26 20:52:23 volumio volumio[2780]: info: [1787799143894] CoreMusicLibrary::Adding element Spotify Aug 26 20:52:23 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 20:52:23 volumio volumio[2780]: Cannot find translation for source Spotify Aug 26 20:52:25 volumio volumio[2780]: info: go-librespot daemon successfully initialized Aug 26 20:52:25 volumio mpd[2991]: 2026-08-26T20:52:25 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 26 20:52:25 volumio systemd[1]: Started mpd.service - Music Player Daemon. Aug 26 20:52:25 volumio sudo[2963]: pam_unix(sudo:session): session closed for user root Aug 26 20:52:25 volumio sudo[2948]: pam_unix(sudo:session): session closed for user root Aug 26 20:52:25 volumio volumio[2780]: info: Completed starting Core Plugins Aug 26 20:52:25 volumio volumio[2780]: info: ------------------------------------------- Aug 26 20:52:25 volumio volumio[2780]: info: ----- MyVolumio plugins startup ---- Aug 26 20:52:25 volumio volumio[2780]: info: ------------------------------------------- Aug 26 20:52:25 volumio volumio[2780]: info: [MyVolumio PluginManager] Fetching plans data.... Aug 26 20:52:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Aug 26 20:52:26 volumio volumio[2780]: error: MPD error: The expression evaluated to a falsy value: Aug 26 20:52:26 volumio volumio[2780]: assert.ok(self.idling) Aug 26 20:52:26 volumio volumio[2780]: error: The expression evaluated to a falsy value: Aug 26 20:52:26 volumio volumio[2780]: assert.ok(self.idling) Aug 26 20:52:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:52:26 volumio volumio[2780]: info: MPD running with PID2991 Aug 26 20:52:26 volumio volumio[2780]: ,establishing connection Aug 26 20:52:26 volumio volumio[2780]: error: updateQueue error: null Aug 26 20:52:26 volumio volumio[2780]: error: updateQueue error: null Aug 26 20:52:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:52:26 volumio go-librespot[3095]: go-librespot daemon starting... Aug 26 20:52:26 volumio go-librespot[3096]: time="2026-08-26T20:52:26-06:00" level=info msg="running go-librespot 0.7.1" Aug 26 20:52:26 volumio go-librespot[3096]: time="2026-08-26T20:52:26-06:00" level=debug msg="app state loaded" Aug 26 20:52:26 volumio go-librespot[3096]: time="2026-08-26T20:52:26-06:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 20:52:26 volumio go-librespot[3096]: time="2026-08-26T20:52:26-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 26 20:52:26 volumio go-librespot[3096]: time="2026-08-26T20:52:26-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 26 20:52:26 volumio go-librespot[3096]: time="2026-08-26T20:52:26-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 26 20:52:26 volumio go-librespot[3096]: time="2026-08-26T20:52:26-06:00" level=info msg="zeroconf server listening on port 34169" Aug 26 20:52:26 volumio go-librespot[3096]: time="2026-08-26T20:52:26-06:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 20:52:26 volumio go-librespot[3096]: time="2026-08-26T20:52:26-06:00" level=debug msg="obtained new client token: AAHh42pYm+TW8JoCICo1fi3meV830Jr9NBcg4kZACy1tEBvKIkNN8PFmIumJOVn2zOOgs9Ah20XSIZD3mwHhZRF7DvphPzmzqO+nMeWAjrqaJx2WEcFJmOhSllNcKFH6B4v4sJr8zP8UEl2EMfQ0KCd5XipDDxo/AEnqbK9sEcQUXT1MAjuCb+EAKKPRM3hUVyXWVUpmw/FH025sRBBZOq+Uabq5N3UqHWw2pJsPCKnOaWTZ3p64vZTP" Aug 26 20:52:26 volumio go-librespot[3096]: time="2026-08-26T20:52:26-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 26 20:52:27 volumio go-librespot[3096]: time="2026-08-26T20:52:27-06:00" level=debug msg="completed keyexchange" Aug 26 20:52:27 volumio go-librespot[3096]: time="2026-08-26T20:52:27-06:00" level=debug msg="completed challenge" Aug 26 20:52:27 volumio go-librespot[3096]: time="2026-08-26T20:52:27-06:00" level=info msg="authenticated AP" username="tm****ke" Aug 26 20:52:27 volumio go-librespot[3096]: time="2026-08-26T20:52:27-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 20:52:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 20:52:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 20:52:28 volumio volumio[2780]: info: Initializing connection to go-librespot Websocket Aug 26 20:52:28 volumio volumio[2780]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 26 20:52:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Aug 26 20:52:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:52:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:52:30 volumio go-librespot[3121]: go-librespot daemon starting... Aug 26 20:52:30 volumio go-librespot[3122]: time="2026-08-26T20:52:30-06:00" level=info msg="running go-librespot 0.7.1" Aug 26 20:52:30 volumio go-librespot[3122]: time="2026-08-26T20:52:30-06:00" level=debug msg="app state loaded" Aug 26 20:52:30 volumio go-librespot[3122]: time="2026-08-26T20:52:30-06:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 20:52:30 volumio go-librespot[3122]: time="2026-08-26T20:52:30-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 26 20:52:30 volumio go-librespot[3122]: time="2026-08-26T20:52:30-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 26 20:52:30 volumio go-librespot[3122]: time="2026-08-26T20:52:30-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 26 20:52:30 volumio go-librespot[3122]: time="2026-08-26T20:52:30-06:00" level=info msg="zeroconf server listening on port 33327" Aug 26 20:52:30 volumio go-librespot[3122]: time="2026-08-26T20:52:30-06:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 20:52:30 volumio volumio[2780]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Aug 26 20:52:31 volumio go-librespot[3122]: time="2026-08-26T20:52:31-06:00" level=debug msg="obtained new client token: AAFi1abnY007wjooba2GhGEs+jgmNgVACbjq7D5Pd0OxtZsVhpQNJ2ZvS3VA98P4YeTweyyyRv8rnXQWN4tD4oXbi5yOc4RE15wTYbtuUigNrui/c9y0r/IgktM9Aon1yee0OBG9PgXf//dyKpWkPiICNTK5dX08Tx2NAEeK5kULFuTGm+2Fz9C7ebo3jSnlUCa2YTWGTFfLfqpgKr7DCsVXuBQruWpCTsuCCrY9E7NxYkUbB3g/8A==" Aug 26 20:52:31 volumio go-librespot[3122]: time="2026-08-26T20:52:31-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 26 20:52:31 volumio go-librespot[3122]: time="2026-08-26T20:52:31-06:00" level=debug msg="completed keyexchange" Aug 26 20:52:31 volumio go-librespot[3122]: time="2026-08-26T20:52:31-06:00" level=debug msg="completed challenge" Aug 26 20:52:31 volumio go-librespot[3122]: time="2026-08-26T20:52:31-06:00" level=info msg="authenticated AP" username="tm****ke" Aug 26 20:52:31 volumio go-librespot[3122]: time="2026-08-26T20:52:31-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 20:52:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 20:52:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 20:52:31 volumio volumio[2780]: info: Initializing connection to go-librespot Websocket Aug 26 20:52:31 volumio volumio[2780]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 26 20:52:34 volumio volumio[2780]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Aug 26 20:52:34 volumio volumio[2780]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Aug 26 20:52:34 volumio volumio[2780]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Aug 26 20:52:34 volumio volumio[2780]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Aug 26 20:52:34 volumio volumio[2780]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Aug 26 20:52:34 volumio volumio[2780]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Aug 26 20:52:34 volumio volumio[2780]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Aug 26 20:52:34 volumio volumio[2780]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Aug 26 20:52:34 volumio volumio[2780]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Aug 26 20:52:34 volumio volumio[2780]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Aug 26 20:52:34 volumio volumio[2780]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Aug 26 20:52:34 volumio volumio[2780]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Aug 26 20:52:34 volumio volumio[2780]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Aug 26 20:52:34 volumio volumio[2780]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Aug 26 20:52:34 volumio volumio[2780]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Aug 26 20:52:34 volumio volumio[2780]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Aug 26 20:52:34 volumio volumio[2780]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Aug 26 20:52:34 volumio volumio[2780]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Aug 26 20:52:34 volumio volumio[2780]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Aug 26 20:52:34 volumio volumio[2780]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Aug 26 20:52:34 volumio volumio[2780]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Aug 26 20:52:34 volumio volumio[2780]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Aug 26 20:52:34 volumio volumio[2780]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Aug 26 20:52:34 volumio volumio[2780]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Aug 26 20:52:34 volumio volumio[2780]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Aug 26 20:52:34 volumio volumio[2780]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Aug 26 20:52:34 volumio volumio[2780]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Aug 26 20:52:34 volumio volumio[2780]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Aug 26 20:52:34 volumio volumio[2780]: info: Adding plugin bluetooth to MyMusic Plugins Aug 26 20:52:34 volumio volumio[2780]: info: Adding plugin multiroom to MyMusic Plugins Aug 26 20:52:34 volumio volumio[2780]: info: Adding plugin metavolumio to MyMusic Plugins Aug 26 20:52:34 volumio volumio[2780]: info: Adding plugin cd_controller to MyMusic Plugins Aug 26 20:52:34 volumio volumio[2780]: info: Adding plugin qobuzconnect to MyMusic Plugins Aug 26 20:52:34 volumio volumio[2780]: info: Adding plugin smart_inputs to MyMusic Plugins Aug 26 20:52:34 volumio volumio[2780]: info: Adding plugin tidalconnect to MyMusic Plugins Aug 26 20:52:34 volumio volumio[2780]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Aug 26 20:52:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Aug 26 20:52:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:52:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:52:34 volumio go-librespot[3132]: go-librespot daemon starting... Aug 26 20:52:34 volumio go-librespot[3133]: time="2026-08-26T20:52:34-06:00" level=info msg="running go-librespot 0.7.1" Aug 26 20:52:34 volumio go-librespot[3133]: time="2026-08-26T20:52:34-06:00" level=debug msg="app state loaded" Aug 26 20:52:34 volumio go-librespot[3133]: time="2026-08-26T20:52:34-06:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 20:52:35 volumio go-librespot[3133]: time="2026-08-26T20:52:35-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 26 20:52:35 volumio go-librespot[3133]: time="2026-08-26T20:52:35-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 26 20:52:35 volumio go-librespot[3133]: time="2026-08-26T20:52:35-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 26 20:52:35 volumio go-librespot[3133]: time="2026-08-26T20:52:35-06:00" level=info msg="zeroconf server listening on port 42971" Aug 26 20:52:35 volumio go-librespot[3133]: time="2026-08-26T20:52:35-06:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 20:52:35 volumio go-librespot[3133]: time="2026-08-26T20:52:35-06:00" level=debug msg="obtained new client token: AAFs5vhDFHb7wj0hXLm/eUCTe/CKtDkmPmCVDNiTBA9aowVZu5NoLmVktBqZNh5xGnEdGl1nRGSbm4gvZ6Sw7ogRO3I1BP5Cdu8YqE9MIIqAnRvqF/PZZ7qW5fVe8BdggTyj6PdkZSKGs321rIYD+WErluAW5cGdW+TfrV65dMdejHS3YxnEMkkwp7OTQoVJhE8ulMYKh9SCLFOnt5nV1X0GSZupwUtBjOFkseUlazgkrox2lfv8+DqS" Aug 26 20:52:35 volumio go-librespot[3133]: time="2026-08-26T20:52:35-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 26 20:52:35 volumio go-librespot[3133]: time="2026-08-26T20:52:35-06:00" level=debug msg="completed keyexchange" Aug 26 20:52:35 volumio go-librespot[3133]: time="2026-08-26T20:52:35-06:00" level=debug msg="completed challenge" Aug 26 20:52:35 volumio go-librespot[3133]: time="2026-08-26T20:52:35-06:00" level=info msg="authenticated AP" username="tm****ke" Aug 26 20:52:35 volumio go-librespot[3133]: time="2026-08-26T20:52:35-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 20:52:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 20:52:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 20:52:36 volumio volumio[2780]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Aug 26 20:52:36 volumio volumio[2780]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Aug 26 20:52:36 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 20:52:36 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 20:52:36 volumio volumio[2780]: info: Starting MyVolumio Remote Streaming Endpoints Aug 26 20:52:36 volumio volumio[2780]: info: MyVolumio login type: Token Aug 26 20:52:36 volumio volumio[2780]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Aug 26 20:52:36 volumio volumio[2780]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Aug 26 20:52:37 volumio volumio[2780]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Aug 26 20:52:37 volumio volumio[2780]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Aug 26 20:52:37 volumio volumio[2780]: info: Streaming services startup Aug 26 20:52:37 volumio volumio[2780]: info: Starting Streaming Daemon Aug 26 20:52:37 volumio sudo[3143]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/systemctl restart volumio-streaming-daemon.service Aug 26 20:52:37 volumio sudo[3143]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 20:52:37 volumio volumio[2780]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Aug 26 20:52:38 volumio sudo[3143]: pam_unix(sudo:session): session closed for user root Aug 26 20:52:38 volumio volumio[2780]: info: Initializing connection to go-librespot Websocket Aug 26 20:52:38 volumio volumio[2780]: error: Cannot start Volumio Streaming Daemon Aug 26 20:52:38 volumio volumio[2780]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 26 20:52:38 volumio volumio[2780]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 26 20:52:38 volumio volumio[2780]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 26 20:52:38 volumio volumio[2780]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Aug 26 20:52:39 volumio volumio[2780]: info: MyVolumio token set successfully Aug 26 20:52:39 volumio volumio[2780]: info: MYVOLUMIO: Adding device Aug 26 20:52:39 volumio volumio[2780]: info: MYVOLUMIO: Evaluating Server Aug 26 20:52:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Aug 26 20:52:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:52:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:52:39 volumio go-librespot[3152]: go-librespot daemon starting... Aug 26 20:52:39 volumio go-librespot[3154]: time="2026-08-26T20:52:39-06:00" level=info msg="running go-librespot 0.7.1" Aug 26 20:52:39 volumio go-librespot[3154]: time="2026-08-26T20:52:39-06:00" level=debug msg="app state loaded" Aug 26 20:52:39 volumio go-librespot[3154]: time="2026-08-26T20:52:39-06:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 20:52:39 volumio volumio[2780]: info: MyVolumio status changed Aug 26 20:52:39 volumio volumio[2780]: info: Streaming services startup Aug 26 20:52:39 volumio volumio[2780]: info: Starting Streaming Daemon Aug 26 20:52:39 volumio volumio[2780]: info: Removing browser output: myVolumio user plan is not superstar Aug 26 20:52:39 volumio volumio[2780]: info: Removing audio output: Aug 26 20:52:39 volumio volumio[2780]: info: Stoppping Tunnel 1 Aug 26 20:52:39 volumio sudo[3181]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/systemctl restart volumio-streaming-daemon.service Aug 26 20:52:39 volumio sudo[3181]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 20:52:39 volumio sudo[3183]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Aug 26 20:52:39 volumio sudo[3183]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 20:52:39 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 26 20:52:39 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 26 20:52:39 volumio sudo[3181]: pam_unix(sudo:session): session closed for user root Aug 26 20:52:39 volumio volumio[2780]: error: Cannot start Volumio Streaming Daemon Aug 26 20:52:39 volumio volumio[2780]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 26 20:52:39 volumio volumio[2780]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 26 20:52:39 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 26 20:52:39 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 26 20:52:39 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 26 20:52:39 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 26 20:52:39 volumio go-librespot[3154]: time="2026-08-26T20:52:39-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 26 20:52:39 volumio go-librespot[3154]: time="2026-08-26T20:52:39-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 26 20:52:39 volumio go-librespot[3154]: time="2026-08-26T20:52:39-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 26 20:52:39 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 26 20:52:39 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 26 20:52:39 volumio sudo[3183]: pam_unix(sudo:session): session closed for user root Aug 26 20:52:39 volumio go-librespot[3154]: time="2026-08-26T20:52:39-06:00" level=info msg="zeroconf server listening on port 45623" Aug 26 20:52:39 volumio volumio[2780]: info: Remote SSH Stopped Aug 26 20:52:39 volumio go-librespot[3154]: time="2026-08-26T20:52:39-06:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 20:52:40 volumio go-librespot[3154]: time="2026-08-26T20:52:40-06:00" level=debug msg="obtained new client token: AAEwFxC8cacWVqP+2vtQkxbinhcuDNaUO2sTPYJjKtpJtrHa5C1jl4i2AjxxankSfYBaZ2OFPX7fl9HRGEUITd852qsYoTWVM2SZ68hB2JpR0HS8zusQ2foDjcnTTwj3IELEllEM9gZT40K89hJWINi0NOVHipTxXw/1WSoT3LNtV4HY34ie8rdXjm+DHYT9a48pRbIuY6zDdIR4fqMx0ElRIb2j3uiP2qNDfKLn1+o9KDqbfjiHYQ==" Aug 26 20:52:40 volumio go-librespot[3154]: time="2026-08-26T20:52:40-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 26 20:52:40 volumio go-librespot[3154]: time="2026-08-26T20:52:40-06:00" level=debug msg="completed keyexchange" Aug 26 20:52:40 volumio go-librespot[3154]: time="2026-08-26T20:52:40-06:00" level=debug msg="completed challenge" Aug 26 20:52:40 volumio go-librespot[3154]: time="2026-08-26T20:52:40-06:00" level=info msg="authenticated AP" username="tm****ke" Aug 26 20:52:40 volumio go-librespot[3154]: time="2026-08-26T20:52:40-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 20:52:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 20:52:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 20:52:40 volumio volumio[2780]: info: Setting Geolocation for MyVolumio to us3 Aug 26 20:52:40 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 20:52:40 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 20:52:40 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 20:52:41 volumio volumio[2780]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Aug 26 20:52:41 volumio volumio[2780]: info: Initializing connection to go-librespot Websocket Aug 26 20:52:41 volumio volumio[2780]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 26 20:52:41 volumio volumio[2780]: info: Updating MyVolumio device info Aug 26 20:52:41 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 20:52:41 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 20:52:41 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 20:52:41 volumio volumio[2780]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Aug 26 20:52:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Aug 26 20:52:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:52:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:52:43 volumio go-librespot[3200]: go-librespot daemon starting... Aug 26 20:52:43 volumio go-librespot[3201]: time="2026-08-26T20:52:43-06:00" level=info msg="running go-librespot 0.7.1" Aug 26 20:52:43 volumio go-librespot[3201]: time="2026-08-26T20:52:43-06:00" level=debug msg="app state loaded" Aug 26 20:52:43 volumio go-librespot[3201]: time="2026-08-26T20:52:43-06:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 20:52:44 volumio volumio[2780]: info: Initializing connection to go-librespot Websocket Aug 26 20:52:44 volumio go-librespot[3201]: time="2026-08-26T20:52:44-06:00" level=debug msg="new websocket client" Aug 26 20:52:44 volumio volumio[2780]: info: Connection to go-librespot Websocket established Aug 26 20:52:44 volumio go-librespot[3201]: time="2026-08-26T20:52:44-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 26 20:52:44 volumio go-librespot[3201]: time="2026-08-26T20:52:44-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 26 20:52:44 volumio go-librespot[3201]: time="2026-08-26T20:52:44-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 26 20:52:44 volumio go-librespot[3201]: time="2026-08-26T20:52:44-06:00" level=info msg="zeroconf server listening on port 43257" Aug 26 20:52:44 volumio go-librespot[3201]: time="2026-08-26T20:52:44-06:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 20:52:44 volumio go-librespot[3201]: time="2026-08-26T20:52:44-06:00" level=debug msg="obtained new client token: AAHdm8Lnqaghtu7RltYWdry4b0uiPM8HGdCcnWW3YwkcaRZDbetGQMrzC0wbmjz0MYIDOYiwcTc3toKU42LPNjBL8f748TU2Eh9sqxIdy0ehMuZhgkk/sUjWWGB7f+8X1TqCwu5lb0JWC7yHRjF2YXkFn45t7s9+vVVk9vG+RRhJWbJ9BLV7GUONcVfH3ZSlMPh+Vt5WDBYEGcig8nvxXx5/As9OJ5G/3P4B3bfCv67GSUud0qejJih+" Aug 26 20:52:44 volumio go-librespot[3201]: time="2026-08-26T20:52:44-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 26 20:52:44 volumio go-librespot[3201]: time="2026-08-26T20:52:44-06:00" level=debug msg="completed keyexchange" Aug 26 20:52:44 volumio go-librespot[3201]: time="2026-08-26T20:52:44-06:00" level=debug msg="completed challenge" Aug 26 20:52:44 volumio go-librespot[3201]: time="2026-08-26T20:52:44-06:00" level=info msg="authenticated AP" username="tm****ke" Aug 26 20:52:44 volumio go-librespot[3201]: time="2026-08-26T20:52:44-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 20:52:44 volumio volumio[2780]: info: Connection to go-librespot Websocket closed Aug 26 20:52:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 20:52:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 20:52:45 volumio volumio[2780]: info: MYVOLUMIO: Adding device Aug 26 20:52:45 volumio volumio[2780]: info: MYVOLUMIO: Evaluating Server Aug 26 20:52:46 volumio volumio[2780]: info: Setting Geolocation for MyVolumio to us3 Aug 26 20:52:46 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 20:52:46 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 20:52:46 volumio volumio[2780]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 20:52:46 volumio volumio[2780]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Aug 26 20:52:47 volumio volumio[2780]: info: Getting Spotify volume Aug 26 20:52:47 volumio volumio[2780]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 26 20:52:47 volumio volumio[2780]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 26 20:52:47 volumio volumio[2780]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 26 20:52:47 volumio volumio[2780]: errno: -111, Aug 26 20:52:47 volumio volumio[2780]: code: 'ECONNREFUSED', Aug 26 20:52:47 volumio volumio[2780]: syscall: 'connect', Aug 26 20:52:47 volumio volumio[2780]: address: '127.0.0.1', Aug 26 20:52:47 volumio volumio[2780]: port: 9879, Aug 26 20:52:47 volumio volumio[2780]: response: undefined Aug 26 20:52:47 volumio volumio[2780]: } Aug 26 20:52:47 volumio volumio[2780]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 26 20:52:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Aug 26 20:52:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:52:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 20:52:47 volumio go-librespot[3241]: go-librespot daemon starting... Aug 26 20:52:47 volumio go-librespot[3242]: time="2026-08-26T20:52:47-06:00" level=info msg="running go-librespot 0.7.1" Aug 26 20:52:47 volumio go-librespot[3242]: time="2026-08-26T20:52:47-06:00" level=debug msg="app state loaded" Aug 26 20:52:48 volumio go-librespot[3242]: time="2026-08-26T20:52:48-06:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 20:52:48 volumio go-librespot[3242]: time="2026-08-26T20:52:48-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 26 20:52:48 volumio go-librespot[3242]: time="2026-08-26T20:52:48-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 26 20:52:48 volumio go-librespot[3242]: time="2026-08-26T20:52:48-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 26 20:52:48 volumio go-librespot[3242]: time="2026-08-26T20:52:48-06:00" level=info msg="zeroconf server listening on port 45893" Aug 26 20:52:48 volumio go-librespot[3242]: time="2026-08-26T20:52:48-06:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 20:52:48 volumio sudo[3254]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-26 20:51' Aug 26 20:52:48 volumio sudo[3254]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 20:52:48 volumio go-librespot[3242]: time="2026-08-26T20:52:48-06:00" level=debug msg="obtained new client token: AAHY8JEphwLNE+2eTBfM584WCDAeqFAIG7Md48aWKbWt5KQ3B9wGcL+kM8LscA/y8dwE5j79Y4iW7dbuXW4jfgRmG+wEXYuDrRSwFUsyaLY/wvrYxpJ57xYHvmtpZQGxxTyAbwSIDQM7D1PiRU1swJ82BjjaVHH0rYR8aTkJYbducaRQXigDf5mye+rKNhsRoS276FdNrnCK1+Ra1siGnxz0niT9OjSC27/2A/vBYb5ZeBbbjlK9KxFs" Aug 26 20:52:48 volumio go-librespot[3242]: time="2026-08-26T20:52:48-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 26 20:52:48 volumio go-librespot[3242]: time="2026-08-26T20:52:48-06:00" level=debug msg="completed keyexchange" Aug 26 20:52:48 volumio go-librespot[3242]: time="2026-08-26T20:52:48-06:00" level=debug msg="completed challenge" Aug 26 20:52:48 volumio go-librespot[3242]: time="2026-08-26T20:52:48-06:00" level=info msg="authenticated AP" username="tm****ke" 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"