Aug 30 20:41:22 volumio-ammi ntpd[1044]: CLOCK: time stepped by 10635169.205861 Aug 30 20:41:22 volumio-ammi ntpd[1044]: CLOCK: time changed from 2026-04-29 to 2026-08-30 Aug 30 20:41:22 volumio-ammi ntpd[1044]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Aug 30 20:41:22 volumio-ammi wpa_supplicant[1224]: wlan0: CTRL-EVENT-DISCONNECTED bssid=72:b5:3c:78:cf:07 reason=14 Aug 30 20:41:22 volumio-ammi wpa_supplicant[1224]: wlan0: WPA: 4-Way Handshake failed - pre-shared key may be incorrect Aug 30 20:41:22 volumio-ammi wpa_supplicant[1224]: wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="Bbox-E8DAF387" auth_failures=3 duration=57 reason=WRONG_KEY Aug 30 20:41:22 volumio-ammi wpa_supplicant[1224]: BSSID 72:b5:3c:78:cf:07 ignore list count incremented to 3, ignoring for 60 seconds Aug 30 20:41:22 volumio-ammi wpa_supplicant[1224]: wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="Bbox-E8DAF387" auth_failures=4 duration=94 reason=CONN_FAILED Aug 30 20:41:22 volumio-ammi dhcpcd[853]: wlan0: carrier lost Aug 30 20:41:22 volumio-ammi wpa_supplicant[1224]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Aug 30 20:41:22 volumio-ammi wpa_supplicant[1224]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=FR Aug 30 20:41:22 volumio-ammi volumio[1243]: info: Discovery: A device disappeared from network Aug 30 20:41:22 volumio-ammi volumio[1243]: info: Discovery: A device disappeared from network Aug 30 20:41:22 volumio-ammi systemd[1]: Starting dpkg-db-backup.service - Daily dpkg database backup service... Aug 30 20:41:22 volumio-ammi systemd[1]: Starting e2scrub_all.service - Online ext4 Metadata Check for All Filesystems... Aug 30 20:41:22 volumio-ammi systemd[1]: Started ntpsec-rotate-stats.service - Rotate ntpd stats. Aug 30 20:41:22 volumio-ammi systemd[1]: e2scrub_all.service: Deactivated successfully. Aug 30 20:41:22 volumio-ammi systemd[1]: Finished e2scrub_all.service - Online ext4 Metadata Check for All Filesystems. Aug 30 20:41:22 volumio-ammi systemd[1]: ntpsec-rotate-stats.service: Deactivated successfully. Aug 30 20:41:22 volumio-ammi systemd[1]: dpkg-db-backup.service: Deactivated successfully. Aug 30 20:41:22 volumio-ammi systemd[1]: Finished dpkg-db-backup.service - Daily dpkg database backup service. Aug 30 20:41:22 volumio-ammi volumio[1243]: info: Discovery: adding 59e8711f-264e-4f8d-8348-f02b49365ce0 Aug 30 20:41:22 volumio-ammi volumio[1243]: info: Discovery: Found device Volumio Ammi Aug 30 20:41:22 volumio-ammi volumio[1243]: info: CoreCommandRouter::volumioGetState Aug 30 20:41:22 volumio-ammi volumio[1243]: info: CorePlayQueue::getTrack 0 Aug 30 20:41:22 volumio-ammi volumio[1243]: info: Discovery: this is already registered, 59e8711f-264e-4f8d-8348-f02b49365ce0 Aug 30 20:41:22 volumio-ammi volumio[1243]: info: Discovery: Found device Volumio Ammi Aug 30 20:41:22 volumio-ammi volumio[1243]: info: CoreCommandRouter::volumioGetState Aug 30 20:41:22 volumio-ammi volumio[1243]: info: CorePlayQueue::getTrack 0 Aug 30 20:41:22 volumio-ammi volumio5-onboarding[1394]: time=2026-08-30T20:41:22.997+02:00 level=INFO msg="emitting wifi info changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.185:40914 @ 0x287da70" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Aug 30 20:41:22 volumio-ammi volumio5-onboarding[1394]: time=2026-08-30T20:41:22.997+02:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.1.185:40914 @ 0x24a0240" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Aug 30 20:41:23 volumio-ammi volumio[1243]: info: Received Get System Info Aug 30 20:41:23 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 30 20:41:23 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 30 20:41:23 volumio-ammi volumio[1243]: info: Discovery: Getting this device information Aug 30 20:41:23 volumio-ammi volumio[1243]: info: CoreCommandRouter::volumioGetState Aug 30 20:41:23 volumio-ammi volumio[1243]: info: CorePlayQueue::getTrack 0 Aug 30 20:41:23 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 30 20:41:23 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 30 20:41:23 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 30 20:41:24 volumio-ammi volumio5-onboarding[1394]: time=2026-08-30T20:41:24.027+02:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 30 20:41:24 volumio-ammi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 58. Aug 30 20:41:24 volumio-ammi systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 20:41:24 volumio-ammi systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 20:41:24 volumio-ammi go-librespot[2615]: go-librespot daemon starting... Aug 30 20:41:24 volumio-ammi go-librespot[2616]: time="2026-08-30T20:41:24+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 20:41:24 volumio-ammi go-librespot[2616]: time="2026-08-30T20:41:24+02:00" level=debug msg="app state loaded" Aug 30 20:41:24 volumio-ammi volumio[1243]: info: Initializing connection to go-librespot Websocket Aug 30 20:41:24 volumio-ammi volumio[1243]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 20:41:24 volumio-ammi go-librespot[2616]: time="2026-08-30T20:41:24+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 20:41:24 volumio-ammi go-librespot[2616]: time="2026-08-30T20:41:24+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 30 20:41:24 volumio-ammi go-librespot[2616]: time="2026-08-30T20:41:24+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 30 20:41:24 volumio-ammi go-librespot[2616]: time="2026-08-30T20:41:24+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 30 20:41:24 volumio-ammi go-librespot[2616]: time="2026-08-30T20:41:24+02:00" level=info msg="zeroconf server listening on port 41787" Aug 30 20:41:24 volumio-ammi go-librespot[2616]: time="2026-08-30T20:41:24+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 20:41:25 volumio-ammi go-librespot[2616]: time="2026-08-30T20:41:25+02:00" level=debug msg="obtained new client token: AAGP6E8lcmx8DwPjkxOEbvuZCdY2x0SQVLur4EGUoj2rzs8AcQHOiWWpW1x+8PVuY+nYrb6V1dBYbLLc5Lklw2ltYa08oblPw9N83yPtTNWJRKg1Z7dzqLwiaJsPWNDOSYM8R/aRWZ2autuXm5EAVrQVmYRmEmNJPLb6O5kESp6BGRz0mmikDvf9SC6rrHacJoXO9fsID10mYcMrdZrd0+kZTIr/gBmrcAtISm9Sm1o0x+P6ObevpkRs" Aug 30 20:41:25 volumio-ammi go-librespot[2616]: time="2026-08-30T20:41:25+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 20:41:25 volumio-ammi go-librespot[2616]: time="2026-08-30T20:41:25+02:00" level=debug msg="completed keyexchange" Aug 30 20:41:25 volumio-ammi go-librespot[2616]: time="2026-08-30T20:41:25+02:00" level=debug msg="completed challenge" Aug 30 20:41:25 volumio-ammi go-librespot[2616]: time="2026-08-30T20:41:25+02:00" level=info msg="authenticated AP" username="am**ni" Aug 30 20:41:25 volumio-ammi go-librespot[2616]: time="2026-08-30T20:41:25+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 20:41:25 volumio-ammi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 20:41:25 volumio-ammi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 20:41:25 volumio-ammi volumio[1243]: info: Volumio Network Manager: Network status updated: 1 Aug 30 20:41:25 volumio-ammi volumio5-onboarding[1394]: time=2026-08-30T20:41:25.640+02:00 level=INFO msg="emitting wifi info changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.185:40914 @ 0x287da70" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Aug 30 20:41:25 volumio-ammi volumio5-onboarding[1394]: time=2026-08-30T20:41:25.641+02:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.1.185:40914 @ 0x24a0240" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Aug 30 20:41:25 volumio-ammi volumio[1243]: info: Received Get System Info Aug 30 20:41:25 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 30 20:41:25 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 30 20:41:25 volumio-ammi volumio[1243]: info: Discovery: Getting this device information Aug 30 20:41:25 volumio-ammi volumio[1243]: info: CoreCommandRouter::volumioGetState Aug 30 20:41:25 volumio-ammi volumio[1243]: info: CorePlayQueue::getTrack 0 Aug 30 20:41:25 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 30 20:41:25 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 30 20:41:25 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 30 20:41:26 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Aug 30 20:41:26 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Aug 30 20:41:26 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Aug 30 20:41:26 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Aug 30 20:41:26 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Aug 30 20:41:26 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Aug 30 20:41:26 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Aug 30 20:41:26 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Aug 30 20:41:26 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Aug 30 20:41:26 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Aug 30 20:41:26 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Aug 30 20:41:26 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Aug 30 20:41:26 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Aug 30 20:41:26 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Aug 30 20:41:26 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Aug 30 20:41:26 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Aug 30 20:41:26 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Aug 30 20:41:26 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Aug 30 20:41:26 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Aug 30 20:41:26 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Aug 30 20:41:26 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Aug 30 20:41:26 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Aug 30 20:41:26 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Aug 30 20:41:26 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Aug 30 20:41:26 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Aug 30 20:41:26 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Aug 30 20:41:26 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Aug 30 20:41:26 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Aug 30 20:41:26 volumio-ammi volumio5-onboarding[1394]: time=2026-08-30T20:41:26.651+02:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 30 20:41:26 volumio-ammi volumio[1243]: info: Adding plugin bluetooth to MyMusic Plugins Aug 30 20:41:26 volumio-ammi volumio[1243]: info: Adding plugin multiroom to MyMusic Plugins Aug 30 20:41:26 volumio-ammi volumio[1243]: info: Adding plugin metavolumio to MyMusic Plugins Aug 30 20:41:26 volumio-ammi volumio[1243]: info: Adding plugin cd_controller to MyMusic Plugins Aug 30 20:41:26 volumio-ammi volumio[1243]: info: Adding plugin qobuzconnect to MyMusic Plugins Aug 30 20:41:26 volumio-ammi volumio[1243]: info: Adding plugin smart_inputs to MyMusic Plugins Aug 30 20:41:26 volumio-ammi volumio[1243]: info: Adding plugin tidalconnect to MyMusic Plugins Aug 30 20:41:26 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Aug 30 20:41:28 volumio-ammi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 59. Aug 30 20:41:28 volumio-ammi systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 20:41:28 volumio-ammi systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 20:41:28 volumio-ammi go-librespot[2640]: go-librespot daemon starting... Aug 30 20:41:28 volumio-ammi go-librespot[2641]: time="2026-08-30T20:41:28+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 20:41:28 volumio-ammi go-librespot[2641]: time="2026-08-30T20:41:28+02:00" level=debug msg="app state loaded" Aug 30 20:41:28 volumio-ammi go-librespot[2641]: time="2026-08-30T20:41:28+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 20:41:28 volumio-ammi go-librespot[2641]: time="2026-08-30T20:41:28+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 30 20:41:28 volumio-ammi go-librespot[2641]: time="2026-08-30T20:41:28+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 30 20:41:28 volumio-ammi go-librespot[2641]: time="2026-08-30T20:41:28+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 30 20:41:28 volumio-ammi go-librespot[2641]: time="2026-08-30T20:41:28+02:00" level=info msg="zeroconf server listening on port 35055" Aug 30 20:41:28 volumio-ammi go-librespot[2641]: time="2026-08-30T20:41:28+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 20:41:28 volumio-ammi go-librespot[2641]: time="2026-08-30T20:41:28+02:00" level=debug msg="obtained new client token: AAG1eiVZZgLT9yX+PZ6WFP5ktECbpn2QTyGkXFwt4DoJKHqtxqKKvkcsKXdpbfl69if6vzZY2YXf8InIeSz3nHocRWn+9Hde1foOhEgn4VKQ5PY8xWF2SPUuL4AaRIMFzTWgTQknMDOOLS3iCrrGJVQd+R5YR9/RHKf0fOj6T0dUYmK7b1IVyXyIujEwEapQcykaipPagIk+ieROSxX/6EovVPbkx6NthmEWQo5pM0YWzOLz2I2t5A0+" Aug 30 20:41:29 volumio-ammi go-librespot[2641]: time="2026-08-30T20:41:29+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 20:41:29 volumio-ammi go-librespot[2641]: time="2026-08-30T20:41:29+02:00" level=debug msg="completed keyexchange" Aug 30 20:41:29 volumio-ammi go-librespot[2641]: time="2026-08-30T20:41:29+02:00" level=debug msg="completed challenge" Aug 30 20:41:29 volumio-ammi go-librespot[2641]: time="2026-08-30T20:41:29+02:00" level=info msg="authenticated AP" username="am**ni" Aug 30 20:41:29 volumio-ammi go-librespot[2641]: time="2026-08-30T20:41:29+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 20:41:29 volumio-ammi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 20:41:29 volumio-ammi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 20:41:32 volumio-ammi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 60. Aug 30 20:41:32 volumio-ammi systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 20:41:32 volumio-ammi systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 20:41:32 volumio-ammi go-librespot[2650]: go-librespot daemon starting... Aug 30 20:41:32 volumio-ammi go-librespot[2651]: time="2026-08-30T20:41:32+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 20:41:32 volumio-ammi go-librespot[2651]: time="2026-08-30T20:41:32+02:00" level=debug msg="app state loaded" Aug 30 20:41:32 volumio-ammi go-librespot[2651]: time="2026-08-30T20:41:32+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 20:41:32 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Aug 30 20:41:32 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Aug 30 20:41:32 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 20:41:32 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 20:41:32 volumio-ammi volumio[1243]: info: Starting MyVolumio Remote Streaming Endpoints Aug 30 20:41:32 volumio-ammi go-librespot[2651]: time="2026-08-30T20:41:32+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 30 20:41:32 volumio-ammi go-librespot[2651]: time="2026-08-30T20:41:32+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 30 20:41:32 volumio-ammi go-librespot[2651]: time="2026-08-30T20:41:32+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 30 20:41:32 volumio-ammi go-librespot[2651]: time="2026-08-30T20:41:32+02:00" level=info msg="zeroconf server listening on port 41861" Aug 30 20:41:32 volumio-ammi go-librespot[2651]: time="2026-08-30T20:41:32+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 20:41:32 volumio-ammi volumio[1243]: info: MyVolumio login type: Token Aug 30 20:41:32 volumio-ammi go-librespot[2651]: time="2026-08-30T20:41:32+02:00" level=debug msg="obtained new client token: AAGziCDcYZ0m1OiWdnHbuLZzI55nXLciuGMZibdTUsd5CJdf9xfGJkNoLIsqohCg3VZ6AE3oQ5uVJQslhlTFp5jQ5YwP+yzK60/y73NlMksgjpErexzzuv5tH7OYxfcRcbWSCb7T/JRnBRVtzEsXs7KmfnV4qx0/K033qFFhHQvZiRr80D6Y5DLfodqB+3feXshjHSpaL/ucz6qdVBrgQdLb1Gu4eoGSq47gSt6s8ce4xn0UGihQW4MJ" Aug 30 20:41:32 volumio-ammi go-librespot[2651]: time="2026-08-30T20:41:32+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 20:41:32 volumio-ammi go-librespot[2651]: time="2026-08-30T20:41:32+02:00" level=debug msg="completed keyexchange" Aug 30 20:41:32 volumio-ammi go-librespot[2651]: time="2026-08-30T20:41:32+02:00" level=debug msg="completed challenge" Aug 30 20:41:33 volumio-ammi go-librespot[2651]: time="2026-08-30T20:41:33+02:00" level=info msg="authenticated AP" username="am**ni" Aug 30 20:41:33 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Aug 30 20:41:33 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Aug 30 20:41:33 volumio-ammi go-librespot[2651]: time="2026-08-30T20:41:33+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 20:41:33 volumio-ammi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 20:41:33 volumio-ammi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 20:41:33 volumio-ammi upmpdcli[2660]: writing RSA key Aug 30 20:41:34 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Aug 30 20:41:34 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Aug 30 20:41:34 volumio-ammi volumio[1243]: info: Streaming services startup Aug 30 20:41:34 volumio-ammi volumio[1243]: info: Starting Streaming Daemon Aug 30 20:41:34 volumio-ammi sudo[2668]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 30 20:41:34 volumio-ammi sudo[2668]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 20:41:34 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Aug 30 20:41:34 volumio-ammi volumio[1243]: info: Initializing connection to go-librespot Websocket Aug 30 20:41:34 volumio-ammi sudo[2668]: pam_unix(sudo:session): session closed for user root Aug 30 20:41:34 volumio-ammi volumio[1243]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 20:41:34 volumio-ammi volumio[1243]: error: Cannot start Volumio Streaming Daemon Aug 30 20:41:34 volumio-ammi volumio[1243]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 30 20:41:34 volumio-ammi volumio[1243]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 30 20:41:35 volumio-ammi volumio[1243]: error: MyVolumio Custom Token format not valid, refreshing it Aug 30 20:41:36 volumio-ammi volumio[1243]: info: MyVolumio login type: Token Aug 30 20:41:36 volumio-ammi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 61. Aug 30 20:41:36 volumio-ammi systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 20:41:36 volumio-ammi systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 20:41:36 volumio-ammi go-librespot[2687]: go-librespot daemon starting... Aug 30 20:41:36 volumio-ammi go-librespot[2688]: time="2026-08-30T20:41:36+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 20:41:36 volumio-ammi go-librespot[2688]: time="2026-08-30T20:41:36+02:00" level=debug msg="app state loaded" Aug 30 20:41:36 volumio-ammi go-librespot[2688]: time="2026-08-30T20:41:36+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 20:41:36 volumio-ammi go-librespot[2688]: time="2026-08-30T20:41:36+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 30 20:41:36 volumio-ammi go-librespot[2688]: time="2026-08-30T20:41:36+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 30 20:41:36 volumio-ammi go-librespot[2688]: time="2026-08-30T20:41:36+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 30 20:41:36 volumio-ammi go-librespot[2688]: time="2026-08-30T20:41:36+02:00" level=info msg="zeroconf server listening on port 34351" Aug 30 20:41:36 volumio-ammi go-librespot[2688]: time="2026-08-30T20:41:36+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 20:41:36 volumio-ammi volumio[1243]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Aug 30 20:41:36 volumio-ammi go-librespot[2688]: time="2026-08-30T20:41:36+02:00" level=debug msg="obtained new client token: AAGng4RE5NJBgMEEwP2Os8exl9kPbIid0Lpy7AoTNd9KldPqyAKdNO33sONUQgBl7DBe38SMb99CZ4j5SpTqf36j6S0VEM42m1ZlF/kxCtliQWa7dChCXVG+diiKuz+trD9tIaL/kTO6a4MddA5ooY+c8VHjVTgbLVBlQorFAfbwS+eze1+SICFqo+t/FdQ1qjWNJ9NsO/BqAiGGCVCFYCpyXGUuEUNLMIod6Vt7/x4C5DsFsLYcihGV" Aug 30 20:41:36 volumio-ammi go-librespot[2688]: time="2026-08-30T20:41:36+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 20:41:36 volumio-ammi go-librespot[2688]: time="2026-08-30T20:41:36+02:00" level=debug msg="completed keyexchange" Aug 30 20:41:36 volumio-ammi go-librespot[2688]: time="2026-08-30T20:41:36+02:00" level=debug msg="completed challenge" Aug 30 20:41:37 volumio-ammi go-librespot[2688]: time="2026-08-30T20:41:37+02:00" level=info msg="authenticated AP" username="am**ni" Aug 30 20:41:37 volumio-ammi go-librespot[2688]: time="2026-08-30T20:41:37+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 20:41:37 volumio-ammi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 20:41:37 volumio-ammi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 20:41:37 volumio-ammi volumio[1243]: info: MyVolumio token set successfully Aug 30 20:41:37 volumio-ammi volumio[1243]: info: MYVOLUMIO: Adding device Aug 30 20:41:37 volumio-ammi volumio[1243]: info: MYVOLUMIO: Evaluating Server Aug 30 20:41:37 volumio-ammi volumio[1243]: info: MyVolumio Plan changed: premium Aug 30 20:41:37 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Aug 30 20:41:37 volumio-ammi volumio[1243]: info: Removing browser output: myVolumio user plan is not superstar Aug 30 20:41:37 volumio-ammi volumio[1243]: info: Removing audio output: Aug 30 20:41:37 volumio-ammi volumio[1243]: info: MYVOLUMIO: Adding device Aug 30 20:41:37 volumio-ammi volumio[1243]: info: MYVOLUMIO: Evaluating Server Aug 30 20:41:37 volumio-ammi volumio[1243]: info: Initializing connection to go-librespot Websocket Aug 30 20:41:38 volumio-ammi volumio[1243]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 20:41:38 volumio-ammi volumio[1243]: info: Remote config written successfully Aug 30 20:41:38 volumio-ammi volumio[1243]: info: Starting Tunnel 1 Aug 30 20:41:38 volumio-ammi volumio[1243]: info: Starting Tunnel Connection Checker Aug 30 20:41:38 volumio-ammi volumio[1243]: info: Setting Geolocation for MyVolumio to eu4 Aug 30 20:41:38 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 20:41:38 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 20:41:38 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 20:41:38 volumio-ammi volumio[1243]: info: MYVolumio Device enabled Aug 30 20:41:38 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Aug 30 20:41:38 volumio-ammi volumio[1243]: info: MyVolumio status changed Aug 30 20:41:38 volumio-ammi volumio[1243]: info: Streaming services startup Aug 30 20:41:38 volumio-ammi volumio[1243]: info: Starting Streaming Daemon Aug 30 20:41:38 volumio-ammi sudo[2736]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 30 20:41:38 volumio-ammi volumio[1243]: info: Setting Geolocation for MyVolumio to eu11 Aug 30 20:41:38 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 20:41:38 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 20:41:38 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 20:41:38 volumio-ammi sudo[2736]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 20:41:38 volumio-ammi volumio[1243]: info: Successfully Added MyVolumio device Aug 30 20:41:38 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Aug 30 20:41:38 volumio-ammi volumio[1243]: error: [MyVolumio PluginManager] Cache data is invalid! Aug 30 20:41:38 volumio-ammi sudo[2736]: pam_unix(sudo:session): session closed for user root Aug 30 20:41:38 volumio-ammi volumio[1243]: error: Cannot start Volumio Streaming Daemon Aug 30 20:41:38 volumio-ammi volumio[1243]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 30 20:41:38 volumio-ammi volumio[1243]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 30 20:41:38 volumio-ammi volumio[1243]: info: Successfully Added MyVolumio device Aug 30 20:41:39 volumio-ammi volumio[1243]: info: Updating MyVolumio device info Aug 30 20:41:39 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 20:41:39 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 20:41:39 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 20:41:39 volumio-ammi volumio[1243]: info: Updating MyVolumio device info Aug 30 20:41:39 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 20:41:39 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 20:41:39 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 20:41:39 volumio-ammi volumio[1243]: info: Successfully Updated MyVolumio device Aug 30 20:41:39 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Aug 30 20:41:40 volumio-ammi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 62. Aug 30 20:41:40 volumio-ammi systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 20:41:40 volumio-ammi systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 20:41:40 volumio-ammi go-librespot[2738]: go-librespot daemon starting... Aug 30 20:41:40 volumio-ammi go-librespot[2739]: time="2026-08-30T20:41:40+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 20:41:40 volumio-ammi go-librespot[2739]: time="2026-08-30T20:41:40+02:00" level=debug msg="app state loaded" Aug 30 20:41:40 volumio-ammi go-librespot[2739]: time="2026-08-30T20:41:40+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 20:41:40 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin bluetooth Aug 30 20:41:40 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin bluetooth Aug 30 20:41:40 volumio-ammi volumio[1243]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Aug 30 20:41:40 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Aug 30 20:41:40 volumio-ammi go-librespot[2739]: time="2026-08-30T20:41:40+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 30 20:41:40 volumio-ammi go-librespot[2739]: time="2026-08-30T20:41:40+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 30 20:41:40 volumio-ammi go-librespot[2739]: time="2026-08-30T20:41:40+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 30 20:41:40 volumio-ammi go-librespot[2739]: time="2026-08-30T20:41:40+02:00" level=info msg="zeroconf server listening on port 39901" Aug 30 20:41:40 volumio-ammi go-librespot[2739]: time="2026-08-30T20:41:40+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 20:41:40 volumio-ammi go-librespot[2739]: time="2026-08-30T20:41:40+02:00" level=debug msg="obtained new client token: AAEbRjZu5iSW1BdE2ttGby7bRguvzfdsympQUOuwCGy1hgJuU4L8sAAl3JsotEqxiSiBLStgkuZ+ofo/5+OXOo29GSaQUDetvRcuZ1unSFjy5ZiCLcP6kWzwT4OasvilodikKVyaxyMDBSpFAw19jSU/8HY0KMZJaU0letJ2gMz+7+haB1G7hBs/OtvhKPa6xD8elA6bJJvqVJMLmjRLIQS+d9fVwDEUO7Rrmk34iFZJ4vLZ1B4f6LcT" Aug 30 20:41:40 volumio-ammi go-librespot[2739]: time="2026-08-30T20:41:40+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 20:41:41 volumio-ammi go-librespot[2739]: time="2026-08-30T20:41:41+02:00" level=debug msg="completed keyexchange" Aug 30 20:41:41 volumio-ammi go-librespot[2739]: time="2026-08-30T20:41:41+02:00" level=debug msg="completed challenge" Aug 30 20:41:41 volumio-ammi go-librespot[2739]: time="2026-08-30T20:41:41+02:00" level=info msg="authenticated AP" username="am**ni" Aug 30 20:41:41 volumio-ammi go-librespot[2739]: time="2026-08-30T20:41:41+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 20:41:41 volumio-ammi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 20:41:41 volumio-ammi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 20:41:44 volumio-ammi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 63. Aug 30 20:41:44 volumio-ammi systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 20:41:44 volumio-ammi systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 20:41:44 volumio-ammi go-librespot[2748]: go-librespot daemon starting... Aug 30 20:41:44 volumio-ammi go-librespot[2749]: time="2026-08-30T20:41:44+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 20:41:44 volumio-ammi go-librespot[2749]: time="2026-08-30T20:41:44+02:00" level=debug msg="app state loaded" Aug 30 20:41:44 volumio-ammi go-librespot[2749]: time="2026-08-30T20:41:44+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 20:41:44 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Aug 30 20:41:44 volumio-ammi sudo[2760]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Aug 30 20:41:44 volumio-ammi sudo[2760]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 20:41:44 volumio-ammi sudo[2760]: pam_unix(sudo:session): session closed for user root Aug 30 20:41:44 volumio-ammi go-librespot[2749]: time="2026-08-30T20:41:44+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 30 20:41:44 volumio-ammi go-librespot[2749]: time="2026-08-30T20:41:44+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 30 20:41:44 volumio-ammi go-librespot[2749]: time="2026-08-30T20:41:44+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 30 20:41:44 volumio-ammi go-librespot[2749]: time="2026-08-30T20:41:44+02:00" level=info msg="zeroconf server listening on port 42105" Aug 30 20:41:44 volumio-ammi go-librespot[2749]: time="2026-08-30T20:41:44+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 20:41:44 volumio-ammi go-librespot[2749]: time="2026-08-30T20:41:44+02:00" level=debug msg="obtained new client token: AAGJEKgRUWmEwTwz5Qw1gomYErmLJJmhcemPQr6+RA1ydbGIigBBj5dewQ85QsgtCbzH+nyIACuGKjKpfw+MrvUIGZ7MmByK/rBNOIL+C8cqG73gJuALvkP8iwHV8YfrQrvqFeEGCEXC4PVHyip4C72MpDTahNbabqrEBdSIRpeXrvhx+XIuDt+wTIdVqi5xQ+bnD8fA7kbntusyTRS8HmlxEzBStBS5oynkaf91TKKpMO27TJ+c2kg6" Aug 30 20:41:44 volumio-ammi go-librespot[2749]: time="2026-08-30T20:41:44+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 20:41:44 volumio-ammi volumio[1243]: info: MRS: MultiRoom plugin initialized Aug 30 20:41:44 volumio-ammi volumio[1243]: info: MRS: STOPPING SNAPCLIENT Aug 30 20:41:44 volumio-ammi volumio[1243]: info: MRS: Snap server stop Aug 30 20:41:44 volumio-ammi volumio[1243]: info: MRS: STOPPING volumioStreaming Aug 30 20:41:44 volumio-ammi sudo[2777]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Aug 30 20:41:44 volumio-ammi sudo[2777]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 20:41:44 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Aug 30 20:41:44 volumio-ammi sudo[2783]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Aug 30 20:41:44 volumio-ammi sudo[2783]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 20:41:45 volumio-ammi sudo[2779]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Aug 30 20:41:45 volumio-ammi sudo[2779]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 20:41:45 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Aug 30 20:41:45 volumio-ammi sudo[2784]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Aug 30 20:41:45 volumio-ammi sudo[2784]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 20:41:45 volumio-ammi sudo[2784]: pam_unix(sudo:session): session closed for user root Aug 30 20:41:45 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Aug 30 20:41:45 volumio-ammi sudo[2783]: pam_unix(sudo:session): session closed for user root Aug 30 20:41:45 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Aug 30 20:41:45 volumio-ammi sudo[2777]: pam_unix(sudo:session): session closed for user root Aug 30 20:41:45 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Aug 30 20:41:45 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Aug 30 20:41:45 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Aug 30 20:41:45 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Aug 30 20:41:45 volumio-ammi sudo[2779]: pam_unix(sudo:session): session closed for user root Aug 30 20:41:45 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Aug 30 20:41:45 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Aug 30 20:41:45 volumio-ammi volumio[1243]: info: Preparing to generate the ALSA configuration file Aug 30 20:41:45 volumio-ammi volumio[1243]: info: Initializing connection to go-librespot Websocket Aug 30 20:41:45 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Aug 30 20:41:45 volumio-ammi volumio[1243]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Aug 30 20:41:45 volumio-ammi volumio[1243]: info: Reading ALSA contributions from plugins. Aug 30 20:41:45 volumio-ammi volumio[1243]: info: MRS: Removed streaming files Aug 30 20:41:45 volumio-ammi volumio[1243]: info: MRS: volumioStreaming STOPPED Aug 30 20:41:45 volumio-ammi volumio[1243]: info: MRS: SNAPSERVER STOPPED Aug 30 20:41:45 volumio-ammi volumio[1243]: info: MRS: SNAPCLIENT STOPPED Aug 30 20:41:45 volumio-ammi go-librespot[2749]: time="2026-08-30T20:41:45+02:00" level=debug msg="new websocket client" Aug 30 20:41:45 volumio-ammi go-librespot[2749]: time="2026-08-30T20:41:45+02:00" level=debug msg="completed keyexchange" Aug 30 20:41:45 volumio-ammi go-librespot[2749]: time="2026-08-30T20:41:45+02:00" level=debug msg="completed challenge" Aug 30 20:41:45 volumio-ammi volumio[1243]: info: Connection to go-librespot Websocket established Aug 30 20:41:45 volumio-ammi go-librespot[2749]: time="2026-08-30T20:41:45+02:00" level=info msg="authenticated AP" username="am**ni" Aug 30 20:41:45 volumio-ammi sudo[2808]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Aug 30 20:41:45 volumio-ammi sudo[2808]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 20:41:45 volumio-ammi go-librespot[2749]: time="2026-08-30T20:41:45+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 20:41:45 volumio-ammi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 20:41:45 volumio-ammi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 20:41:45 volumio-ammi 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 30 20:41:45 volumio-ammi 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 30 20:41:45 volumio-ammi volumio[1243]: info: Connection to go-librespot Websocket closed Aug 30 20:41:46 volumio-ammi volumio[1243]: info: Successfully Updated MyVolumio device Aug 30 20:41:46 volumio-ammi systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Aug 30 20:41:46 volumio-ammi sudo[2808]: pam_unix(sudo:session): session closed for user root Aug 30 20:41:46 volumio-ammi autossh[2812]: port set to 0, monitoring disabled Aug 30 20:41:46 volumio-ammi autossh[2812]: starting ssh (count 1) Aug 30 20:41:46 volumio-ammi autossh[2812]: ssh child pid is 2815 Aug 30 20:41:46 volumio-ammi volumio[1243]: info: Remote SSH Started Aug 30 20:41:46 volumio-ammi volumiossh-tunnel[2815]: Warning: Permanently added '[eu11.myvolumio.org]:2222' (ED25519) to the list of known hosts. Aug 30 20:41:46 volumio-ammi volumio[1243]: 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 30 20:41:46 volumio-ammi volumio[1243]: info: Asound.conf file written Aug 30 20:41:46 volumio-ammi sudo[2818]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Aug 30 20:41:46 volumio-ammi sudo[2818]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 20:41:46 volumio-ammi sudo[2818]: pam_unix(sudo:session): session closed for user root Aug 30 20:41:46 volumio-ammi volumio[1243]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Aug 30 20:41:46 volumio-ammi volumio[1243]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Aug 30 20:41:46 volumio-ammi volumio[1243]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Aug 30 20:41:46 volumio-ammi volumio[1243]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:3 use case configuration -2 Aug 30 20:41:46 volumio-ammi volumio[1243]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:4 use case configuration -2 Aug 30 20:41:46 volumio-ammi volumio[1243]: info: Output device has changed, restarting MPD Aug 30 20:41:46 volumio-ammi volumio[1243]: info: Output device has changed, restarting Shairport Sync Aug 30 20:41:46 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 20:41:46 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 20:41:46 volumio-ammi volumio[1243]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 30 20:41:46 volumio-ammi volumio[1243]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Aug 30 20:41:46 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 20:41:46 volumio-ammi sudo[2824]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 30 20:41:46 volumio-ammi sudo[2824]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 20:41:46 volumio-ammi sudo[2826]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 30 20:41:46 volumio-ammi sudo[2826]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 20:41:46 volumio-ammi sudo[2824]: pam_unix(sudo:session): session closed for user root Aug 30 20:41:46 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Aug 30 20:41:46 volumio-ammi volumio[1243]: ------------------------------------ BT MESSAGE: [FUNC] onStart Aug 30 20:41:46 volumio-ammi volumio[1243]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Aug 30 20:41:46 volumio-ammi volumio[1243]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Aug 30 20:41:46 volumio-ammi volumio[1243]: ------------------------------------ BT MESSAGE: [metaCache] Created directory: /tmp/bluetooth-cache/ Aug 30 20:41:46 volumio-ammi volumio[1243]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Aug 30 20:41:46 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Aug 30 20:41:46 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Aug 30 20:41:47 volumio-ammi volumio[1243]: info: MRS: Pushing multiroomSync output for this device Aug 30 20:41:47 volumio-ammi volumio[1243]: info: MRS: Pushing multiroomSync output Aug 30 20:41:47 volumio-ammi systemd[1]: Stopping mpd.service - Music Player Daemon... Aug 30 20:41:47 volumio-ammi volumio[1243]: info: Adding audio output: Aug 30 20:41:47 volumio-ammi volumio[1243]: info: Adding audio output: Aug 30 20:41:47 volumio-ammi volumio[1243]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Aug 30 20:41:47 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 20:41:47 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Aug 30 20:41:47 volumio-ammi volumio[1243]: info: Adding METAVOLUMIO REST API Endpoints Aug 30 20:41:47 volumio-ammi volumio[1243]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Aug 30 20:41:47 volumio-ammi volumio[1243]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Aug 30 20:41:47 volumio-ammi volumio[1243]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Aug 30 20:41:47 volumio-ammi volumio[1243]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Aug 30 20:41:47 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Aug 30 20:41:47 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Aug 30 20:41:47 volumio-ammi volumio[1243]: info: Preparing CD Folders Aug 30 20:41:47 volumio-ammi bluetoothd[809]: Path / reserved for Adv Monitor app :1.28 Aug 30 20:41:47 volumio-ammi volumio[1243]: info: Adding CD REST API Endpoints Aug 30 20:41:47 volumio-ammi volumio[1243]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Aug 30 20:41:47 volumio-ammi volumio[1243]: info: Starting UDEV Watcher for CD Aug 30 20:41:47 volumio-ammi volumio[1243]: info: Detecting CD presence with UDEV Aug 30 20:41:47 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Aug 30 20:41:47 volumio-ammi bluetoothd[809]: Adv Monitor app :1.28 disconnected from D-Bus Aug 30 20:41:47 volumio-ammi systemd[1]: mpd.service: Deactivated successfully. Aug 30 20:41:47 volumio-ammi systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 30 20:41:47 volumio-ammi systemd[1]: mpd.service: Consumed 3.026s CPU time. Aug 30 20:41:47 volumio-ammi systemd[1]: mpd.socket: Deactivated successfully. Aug 30 20:41:47 volumio-ammi systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 30 20:41:47 volumio-ammi systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 30 20:41:47 volumio-ammi systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 30 20:41:47 volumio-ammi systemd[1]: Starting mpd.service - Music Player Daemon... Aug 30 20:41:47 volumio-ammi sudo[2842]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 30 20:41:47 volumio-ammi sudo[2842]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 30 20:41:47 volumio-ammi sudo[2842]: pam_unix(sudo:session): session closed for user root Aug 30 20:41:48 volumio-ammi mpd[2846]: 2026-08-30T20:41:48 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 30 20:41:48 volumio-ammi systemd[1]: Started mpd.service - Music Player Daemon. Aug 30 20:41:48 volumio-ammi sudo[2826]: pam_unix(sudo:session): session closed for user root Aug 30 20:41:49 volumio-ammi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 64. Aug 30 20:41:49 volumio-ammi systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 20:41:49 volumio-ammi systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 20:41:49 volumio-ammi go-librespot[2850]: go-librespot daemon starting... Aug 30 20:41:49 volumio-ammi go-librespot[2851]: time="2026-08-30T20:41:49+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 20:41:49 volumio-ammi go-librespot[2851]: time="2026-08-30T20:41:49+02:00" level=debug msg="app state loaded" Aug 30 20:41:49 volumio-ammi go-librespot[2851]: time="2026-08-30T20:41:49+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 20:41:49 volumio-ammi go-librespot[2851]: time="2026-08-30T20:41:49+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 30 20:41:49 volumio-ammi go-librespot[2851]: time="2026-08-30T20:41:49+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 30 20:41:49 volumio-ammi go-librespot[2851]: time="2026-08-30T20:41:49+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 30 20:41:49 volumio-ammi go-librespot[2851]: time="2026-08-30T20:41:49+02:00" level=info msg="zeroconf server listening on port 35463" Aug 30 20:41:49 volumio-ammi go-librespot[2851]: time="2026-08-30T20:41:49+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 20:41:49 volumio-ammi go-librespot[2851]: time="2026-08-30T20:41:49+02:00" level=debug msg="obtained new client token: AAFwkFyAozanlJa0IMeXRRr7sAUMlPPrzwlQgBSQrJaedvV0CQMpKuDz35AtAQseZXUX7874WhvrdL8LX2DTTDfJskMWiOvG4Azo2zqOiOIV43nyVPNItHv8it+mtWHocqf+3IMTQQU5kQ2o0J1X4RQSmIfYnmmGrVmGkrHHxy6ZvI4BRvjUN//x2o8Smpxtv/TEVsOuAoSJXxLnYmSFvQSmX04okWB0cRdBNgCr3enhWr6SdVhOppXA" Aug 30 20:41:49 volumio-ammi go-librespot[2851]: time="2026-08-30T20:41:49+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 20:41:49 volumio-ammi go-librespot[2851]: time="2026-08-30T20:41:49+02:00" level=debug msg="completed keyexchange" Aug 30 20:41:49 volumio-ammi go-librespot[2851]: time="2026-08-30T20:41:49+02:00" level=debug msg="completed challenge" Aug 30 20:41:49 volumio-ammi go-librespot[2851]: time="2026-08-30T20:41:49+02:00" level=info msg="authenticated AP" username="am**ni" Aug 30 20:41:49 volumio-ammi go-librespot[2851]: time="2026-08-30T20:41:49+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 20:41:49 volumio-ammi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 20:41:49 volumio-ammi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 20:41:52 volumio-ammi volumio[1243]: warn: [cd-plugin] cdspeedctl: device or media not ready Aug 30 20:41:52 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Aug 30 20:41:52 volumio-ammi volumio[1243]: info: Adding inputs REST Endpoints Aug 30 20:41:52 volumio-ammi volumio[1243]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Aug 30 20:41:52 volumio-ammi volumio[1243]: info: Scanning Audio Inputs Aug 30 20:41:52 volumio-ammi volumio[1243]: info: Checking against Known Cards name Aug 30 20:41:52 volumio-ammi volumio[1243]: info: Adding Server instance for streaming Aug 30 20:41:52 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Aug 30 20:41:52 volumio-ammi volumio[1243]: error: Hi Res Audio Failed Login: Missing Login Data Aug 30 20:41:52 volumio-ammi volumio[1243]: info: Adding HIGHRESAUDIO REST API Endpoints Aug 30 20:41:52 volumio-ammi volumio[1243]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Aug 30 20:41:52 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Aug 30 20:41:52 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Aug 30 20:41:52 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Aug 30 20:41:52 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Plugin tidalconnect disabled by user. Not starting Aug 30 20:41:52 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Aug 30 20:41:52 volumio-ammi volumio[1243]: info: [MyVolumio PluginManager] Plugin qobuzconnect disabled by user. Not starting Aug 30 20:41:52 volumio-ammi volumio[1243]: info: Adding TIDAL REST API Endpoints Aug 30 20:41:52 volumio-ammi volumio[1243]: info: Stopping AccessToken refresher cron for QOBUZ Aug 30 20:41:52 volumio-ammi volumio[1243]: info: AccessToken refresher cron started for QOBUZ Aug 30 20:41:52 volumio-ammi volumio[1243]: info: Adding QOBUZ REST API Endpoints Aug 30 20:41:52 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 30 20:41:53 volumio-ammi volumio[1243]: info: Getting Spotify volume Aug 30 20:41:53 volumio-ammi volumio[1243]: info: Initializing connection to go-librespot Websocket Aug 30 20:41:53 volumio-ammi volumio[1243]: info: MRS: Getting audio outputs on start Aug 30 20:41:53 volumio-ammi volumio[1243]: info: MRS: Requesting all other devices output Aug 30 20:41:53 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 20:41:53 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 20:41:53 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Aug 30 20:41:53 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Aug 30 20:41:53 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Aug 30 20:41:53 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Aug 30 20:41:53 volumio-ammi volumio[1243]: info: CoreCommandRouter::volumioGetBrowseSources Aug 30 20:41:53 volumio-ammi volumio[1243]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 30 20:41:53 volumio-ammi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 65. Aug 30 20:41:53 volumio-ammi systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 20:41:53 volumio-ammi systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 20:41:53 volumio-ammi go-librespot[2863]: go-librespot daemon starting... Aug 30 20:41:53 volumio-ammi go-librespot[2864]: time="2026-08-30T20:41:53+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 20:41:53 volumio-ammi go-librespot[2864]: time="2026-08-30T20:41:53+02:00" level=debug msg="app state loaded" Aug 30 20:41:53 volumio-ammi go-librespot[2864]: time="2026-08-30T20:41:53+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 20:41:53 volumio-ammi volumio[1243]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 30 20:41:53 volumio-ammi volumio[1243]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 20:41:53 volumio-ammi volumio[1243]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 30 20:41:53 volumio-ammi volumio[1243]: errno: -111, Aug 30 20:41:53 volumio-ammi volumio[1243]: code: 'ECONNREFUSED', Aug 30 20:41:53 volumio-ammi volumio[1243]: syscall: 'connect', Aug 30 20:41:53 volumio-ammi volumio[1243]: address: '127.0.0.1', Aug 30 20:41:53 volumio-ammi volumio[1243]: port: 9879, Aug 30 20:41:53 volumio-ammi volumio[1243]: response: undefined Aug 30 20:41:53 volumio-ammi volumio[1243]: } Aug 30 20:41:53 volumio-ammi volumio[1243]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 30 20:41:53 volumio-ammi go-librespot[2864]: time="2026-08-30T20:41:53+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 30 20:41:53 volumio-ammi go-librespot[2864]: time="2026-08-30T20:41:53+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 30 20:41:53 volumio-ammi go-librespot[2864]: time="2026-08-30T20:41:53+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 30 20:41:53 volumio-ammi go-librespot[2864]: time="2026-08-30T20:41:53+02:00" level=info msg="zeroconf server listening on port 33893" Aug 30 20:41:53 volumio-ammi go-librespot[2864]: time="2026-08-30T20:41:53+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 20:41:53 volumio-ammi go-librespot[2864]: time="2026-08-30T20:41:53+02:00" level=debug msg="obtained new client token: AAEB2qwqEZ7NoK1fxBL1yIP6rTyajg6uohIetm/2HB03LkgrLSAi03DAEn4mphCJ6xCC7C0R1lvhp690o0qFFheYQW/pcM4JK2t6TCIzMfiaqOe/oAeHzU3x7KcPrucSvkIFKI++jGF5mlR7OI6F+I+u6PN7OMEydGzJw77x2b+/P0St4/07sEpCClYtpKQsVc9pwPWMu+YtmJBLBjL5B5WcvXjjgaYfyXY0It8f53EII1lltof4nL/t" Aug 30 20:41:53 volumio-ammi go-librespot[2864]: time="2026-08-30T20:41:53+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 20:41:53 volumio-ammi go-librespot[2864]: time="2026-08-30T20:41:53+02:00" level=debug msg="completed keyexchange" Aug 30 20:41:53 volumio-ammi go-librespot[2864]: time="2026-08-30T20:41:53+02:00" level=debug msg="completed challenge" Aug 30 20:41:53 volumio-ammi go-librespot[2864]: time="2026-08-30T20:41:53+02:00" level=info msg="authenticated AP" username="am**ni" Aug 30 20:41:53 volumio-ammi go-librespot[2864]: time="2026-08-30T20:41:53+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 20:41:53 volumio-ammi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 20:41:53 volumio-ammi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 20:41:56 volumio-ammi volumio5-onboarding[1394]: time=2026-08-30T20:41:56.055+02:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="00:00:00:00:00:00%01,192.168.1.185:40914 @ 0x287da70" latency=-342.892932ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Aug 30 20:41:56 volumio-ammi volumio5-onboarding[1394]: time=2026-08-30T20:41:56.080+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.185:40914 @ 0x287da70" latency=-343.410227ms timeout=10s Aug 30 20:41:56 volumio-ammi volumio5-onboarding[1394]: time=2026-08-30T20:41:56.190+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.185:40914 @ 0x287da70" latency=-343.410227ms timeout=10s endpoint=http://pushupdates.volumio.org duration=108.174513ms Aug 30 20:41:56 volumio-ammi volumio5-onboarding[1394]: time=2026-08-30T20:41:56.388+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.185:40914 @ 0x287da70" latency=-343.410227ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=307.005407ms Aug 30 20:41:56 volumio-ammi volumio5-onboarding[1394]: time=2026-08-30T20:41:56.546+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.185:40914 @ 0x287da70" latency=-343.410227ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=462.714151ms Aug 30 20:41:56 volumio-ammi volumio5-onboarding[1394]: time=2026-08-30T20:41:56.554+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.185:40914 @ 0x287da70" latency=-343.410227ms timeout=10s endpoint=https://www.googleapis.com duration=471.058005ms Aug 30 20:41:56 volumio-ammi volumio5-onboarding[1394]: time=2026-08-30T20:41:56.572+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.185:40914 @ 0x287da70" latency=-343.410227ms timeout=10s endpoint=https://securetoken.googleapis.com duration=488.474783ms Aug 30 20:41:56 volumio-ammi volumio5-onboarding[1394]: time=2026-08-30T20:41:56.586+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.185:40914 @ 0x287da70" latency=-343.410227ms timeout=10s endpoint=http://cddb.volumio.org duration=504.597478ms Aug 30 20:41:56 volumio-ammi volumio5-onboarding[1394]: time=2026-08-30T20:41:56.752+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.185:40914 @ 0x287da70" latency=-343.410227ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=670.801957ms Aug 30 20:41:56 volumio-ammi volumio5-onboarding[1394]: time=2026-08-30T20:41:56.776+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.185:40914 @ 0x287da70" latency=-343.410227ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=694.699862ms Aug 30 20:41:56 volumio-ammi sudo[2910]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-30 20:40' Aug 30 20:41:56 volumio-ammi sudo[2910]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 20:41:56 volumio-ammi volumio5-onboarding[1394]: time=2026-08-30T20:41:56.795+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.185:40914 @ 0x287da70" latency=-343.410227ms timeout=10s endpoint=https://functions.volumio.cloud duration=714.280615ms Aug 30 20:41:56 volumio-ammi volumio5-onboarding[1394]: time=2026-08-30T20:41:56.796+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.185:40914 @ 0x287da70" latency=-343.410227ms timeout=10s endpoint=https://database.volumio.cloud duration=712.557928ms Aug 30 20:41:56 volumio-ammi volumio5-onboarding[1394]: time=2026-08-30T20:41:56.799+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.185:40914 @ 0x287da70" latency=-343.410227ms timeout=10s endpoint=https://functions.volumio.cloud duration=715.174931ms Aug 30 20:41:56 volumio-ammi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 66. Aug 30 20:41:56 volumio-ammi systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 20:41:56 volumio-ammi volumio5-onboarding[1394]: time=2026-08-30T20:41:56.868+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.185:40914 @ 0x287da70" latency=-343.410227ms timeout=10s endpoint=http://plugins.volumio.org duration=785.371188ms Aug 30 20:41:56 volumio-ammi systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 20:41:56 volumio-ammi go-librespot[2912]: go-librespot daemon starting... Aug 30 20:41:57 volumio-ammi go-librespot[2913]: time="2026-08-30T20:41:56+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 20:41:57 volumio-ammi go-librespot[2913]: time="2026-08-30T20:41:56+02:00" level=debug msg="app state loaded" Aug 30 20:41:57 volumio-ammi go-librespot[2913]: time="2026-08-30T20:41:57+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 20:41:57 volumio-ammi volumio5-onboarding[1394]: time=2026-08-30T20:41:57.059+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.185:40914 @ 0x287da70" latency=-343.410227ms timeout=10s endpoint=https://google.com duration=977.081502ms Aug 30 20:41:57 volumio-ammi go-librespot[2913]: time="2026-08-30T20:41:57+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 30 20:41:57 volumio-ammi go-librespot[2913]: time="2026-08-30T20:41:57+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 30 20:41:57 volumio-ammi go-librespot[2913]: time="2026-08-30T20:41:57+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 30 20:41:57 volumio-ammi go-librespot[2913]: time="2026-08-30T20:41:57+02:00" level=info msg="zeroconf server listening on port 37381" Aug 30 20:41:57 volumio-ammi go-librespot[2913]: time="2026-08-30T20:41:57+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" 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"