Aug 30 11:26:19 volumio ntpd[1173]: CLOCK: time stepped by 2900729.032126 Aug 30 11:26:19 volumio ntpd[1173]: CLOCK: time changed from 2026-07-27 to 2026-08-30 Aug 30 11:26:19 volumio ntpd[1173]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Aug 30 11:26:19 volumio volumio[1431]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Aug 30 11:26:19 volumio tailscaled[1004]: control: control server key from https://controlplane.tailscale.com: ts2021=[fSeS+], legacy=[nlFWp] Aug 30 11:26:19 volumio tailscaled[1004]: control: RegisterReq: onode= node=[7qR8w] fup=false nks=false Aug 30 11:26:19 volumio tailscaled[1004]: control: RegisterReq: got response; nodeKeyExpired=false, machineAuthorized=true; authURL=false Aug 30 11:26:19 volumio tailscaled[1004]: health(warnable=login-state): ok Aug 30 11:26:19 volumio tailscaled[1004]: health(warnable=not-in-map-poll): ok Aug 30 11:26:19 volumio tailscaled[1004]: control: netmap: got new dial plan from control Aug 30 11:26:19 volumio tailscaled[1004]: active login: antonio.facchin97@gmail.com Aug 30 11:26:19 volumio tailscaled[1004]: netmap: suggested exit node: no preferred DERP, try again later Aug 30 11:26:19 volumio tailscaled[1004]: offline auto-update: stopping update checks Aug 30 11:26:19 volumio tailscaled[1004]: Switching ipn state NoState -> Starting (WantRunning=true, nm=true) Aug 30 11:26:19 volumio tailscaled[1004]: magicsock: SetPrivateKey called (init) Aug 30 11:26:19 volumio tailscaled[1004]: wgengine: Reconfig: configuring userspace WireGuard config (with 3 peers) Aug 30 11:26:19 volumio tailscaled[1004]: wgengine: Reconfig: configuring router Aug 30 11:26:19 volumio tailscaled[1004]: router: enabling connmark-based rp_filter workaround Aug 30 11:26:19 volumio tailscaled[1004]: wgengine: Reconfig: user dialer Aug 30 11:26:19 volumio tailscaled[1004]: tsdial: bart table size: 6 Aug 30 11:26:19 volumio tailscaled[1004]: wgengine: Reconfig: configuring DNS Aug 30 11:26:19 volumio tailscaled[1004]: dns: Set: {DefaultResolvers:[] Routes:{tailb64147.ts.net.:[] ts.net.:[199.247.155.53 2620:111:8007::53]}+65arpa SearchDomains:[tailb64147.ts.net.] Hosts:7} Aug 30 11:26:19 volumio tailscaled[1004]: dns: Resolvercfg: {Routes:{.:[192.168.1.254 208.67.222.222 208.67.222.222 208.67.220.220] ts.net.:[199.247.155.53 2620:111:8007::53]} Hosts:7 LocalDomains:[tailb64147.ts.net.]+65arpa} Aug 30 11:26:19 volumio tailscaled[1004]: dns: OScfg: {Nameservers:[100.100.100.100 fd7a:115c:a1e0::53] SearchDomains:[tailb64147.ts.net.] } Aug 30 11:26:19 volumio systemd[1]: Starting dpkg-db-backup.service - Daily dpkg database backup service... Aug 30 11:26:19 volumio systemd[1]: Started ntpsec-rotate-stats.service - Rotate ntpd stats. Aug 30 11:26:19 volumio systemd[1]: ntpsec-rotate-stats.service: Deactivated successfully. Aug 30 11:26:19 volumio systemd[1]: Reached target ip-changed@tailscale0.target - IP Address changed on tailscale0. Aug 30 11:26:19 volumio tailscaled[1004]: peerapi: serving on http://100.104.80.53:56061 Aug 30 11:26:19 volumio tailscaled[1004]: peerapi: failed to do peerAPI listen, harmless (netstack available) but error was: listen tcp6 [fd7a:115c:a1e0::6135:5035]:0: bind: cannot assign requested address Aug 30 11:26:19 volumio tailscaled[1004]: peerapi: serving on http://[fd7a:115c:a1e0::6135:5035]:1 Aug 30 11:26:19 volumio systemd[1]: dpkg-db-backup.service: Deactivated successfully. Aug 30 11:26:19 volumio systemd[1]: Finished dpkg-db-backup.service - Daily dpkg database backup service. Aug 30 11:26:20 volumio tailscaled[1004]: portmapper: UPnP meta changed: [{Location:http://192.168.1.254:5678/desc/root Server:Linux/2.6 UPnP/1.0 fbxigdd/1.1 USN:uuid:igd73616d61-6a65-7374-650a-2066cf784b53::urn:schemas-upnp-org:device:InternetGatewayDevice:1}] Aug 30 11:26:20 volumio tailscaled[1004]: magicsock: home DERP changing from derp-0 [0ms] to derp-4 [19ms] (forced=false) Aug 30 11:26:20 volumio tailscaled[1004]: magicsock: home is now derp-4 (fra) Aug 30 11:26:20 volumio tailscaled[1004]: magicsock: adding connection to derp-4 for home-keep-alive Aug 30 11:26:20 volumio tailscaled[1004]: magicsock: 1 active derp conns: derp-4=cr0s,wr0s Aug 30 11:26:20 volumio tailscaled[1004]: derphttp.Client.Connect: connecting to derp-4 (fra) Aug 30 11:26:20 volumio tailscaled[1004]: magicsock: endpoints changed: 81.56.102.128:7633 (stun), 192.168.1.40:41641 (local) Aug 30 11:26:20 volumio tailscaled[1004]: Switching ipn state Starting -> Running (WantRunning=true, nm=true) Aug 30 11:26:20 volumio tailscaled[1004]: control: NetInfo: NetInfo{varies=false ipv6=false ipv6os=false udp=true icmpv4=false derp=#4 portmap=U link="" firewallmode="ipt-default"} Aug 30 11:26:20 volumio tailscaled[1004]: health(warnable=no-derp-home): ok Aug 30 11:26:20 volumio tailscaled[1004]: writing netmap to disk cache Aug 30 11:26:20 volumio tailscaled[1004]: portmapper: saw UPnP type WANIPConnection1 at http://192.168.1.254:5678/desc/root; iliadbox Server (Freebox), method=single Aug 30 11:26:20 volumio tailscaled[1004]: magicsock: derp-4 connected; connGen=1 Aug 30 11:26:20 volumio tailscaled[1004]: health(warnable=no-derp-connection): ok Aug 30 11:26:20 volumio volumio[1431]: info: Volumio Network Manager: Network status updated: 2 Aug 30 11:26:20 volumio sudo[1951]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 30 11:26:20 volumio sudo[1953]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 30 11:26:20 volumio sudo[1953]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 11:26:20 volumio sudo[1951]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 11:26:20 volumio sudo[1951]: pam_unix(sudo:session): session closed for user root Aug 30 11:26:20 volumio sudo[1953]: pam_unix(sudo:session): session closed for user root Aug 30 11:26:20 volumio sudo[1957]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Aug 30 11:26:20 volumio sudo[1957]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 11:26:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 30 11:26:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 11:26:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 11:26:20 volumio go-librespot[1959]: go-librespot daemon starting... Aug 30 11:26:20 volumio go-librespot[1960]: time="2026-08-30T11:26:20+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 11:26:20 volumio go-librespot[1960]: time="2026-08-30T11:26:20+02:00" level=debug msg="app state loaded" Aug 30 11:26:20 volumio go-librespot[1960]: time="2026-08-30T11:26:20+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 11:26:20 volumio go-librespot[1960]: time="2026-08-30T11:26:20+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 30 11:26:20 volumio go-librespot[1960]: time="2026-08-30T11:26:20+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 30 11:26:20 volumio go-librespot[1960]: time="2026-08-30T11:26:20+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 30 11:26:20 volumio go-librespot[1960]: time="2026-08-30T11:26:20+02:00" level=info msg="zeroconf server listening on port 39001" Aug 30 11:26:20 volumio go-librespot[1960]: time="2026-08-30T11:26:20+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 11:26:20 volumio go-librespot[1960]: time="2026-08-30T11:26:20+02:00" level=debug msg="obtained new client token: AAGkQytah7TzIvOj9evqkgaEgRjkKueZJtyBPx3tbTLm3yP6kAFS/tphkOSuMFmWd8Urn8+m1CiUcmqPQlU3IGnWlqCuG3ZN/gaEUfUoiqHAzDXuozzbXXHGt4li3gN7xroih+ZhYggaav45YzTnOCoLeVpMdn4m/O280qF5BuTzYPSB+S1BaslxdODlme4h8sLqWH87ztja3mdapvWb/5+cStop6m4Coj0AJavghbZmUyxkhdeswdX8" Aug 30 11:26:20 volumio go-librespot[1960]: time="2026-08-30T11:26:20+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 30 11:26:20 volumio go-librespot[1960]: time="2026-08-30T11:26:20+02:00" level=debug msg="completed keyexchange" Aug 30 11:26:20 volumio go-librespot[1960]: time="2026-08-30T11:26:20+02:00" level=debug msg="completed challenge" Aug 30 11:26:20 volumio go-librespot[1960]: time="2026-08-30T11:26:20+02:00" level=info msg="authenticated AP" username="be*****el" Aug 30 11:26:21 volumio go-librespot[1960]: time="2026-08-30T11:26:21+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 11:26:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 11:26:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 11:26:21 volumio ntpd[1173]: IO: Listen normally on 4 tailscale0 100.104.80.53:123 Aug 30 11:26:21 volumio ntpd[1173]: IO: new interface(s) found: waking up resolver Aug 30 11:26:21 volumio ntpd[1173]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Aug 30 11:26:21 volumio ntpd[1173]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Aug 30 11:26:21 volumio ntpd[1173]: DNS: Pool skipping: 212.45.144.3 Aug 30 11:26:21 volumio ntpd[1173]: DNS: Pool skipping: 162.159.200.1 Aug 30 11:26:21 volumio ntpd[1173]: DNS: Pool skipping: 81.56.230.156 Aug 30 11:26:21 volumio ntpd[1173]: DNS: Pool skipping: 172.232.209.103 Aug 30 11:26:21 volumio ntpd[1173]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 Aug 30 11:26:21 volumio volumio[1431]: info: Initializing connection to go-librespot Websocket Aug 30 11:26:21 volumio volumio[1431]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 11:26:22 volumio ntpd[1173]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Aug 30 11:26:22 volumio ntpd[1173]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Aug 30 11:26:22 volumio ntpd[1173]: DNS: Pool skipping: 204.216.214.76 Aug 30 11:26:22 volumio ntpd[1173]: DNS: Pool skipping: 93.94.88.50 Aug 30 11:26:22 volumio ntpd[1173]: DNS: Pool skipping: 217.61.62.224 Aug 30 11:26:22 volumio ntpd[1173]: DNS: Pool skipping: 172.232.208.229 Aug 30 11:26:22 volumio ntpd[1173]: DNS: Pool skipping: 2603:c027:2:c801:1979::1 Aug 30 11:26:22 volumio ntpd[1173]: DNS: Pool skipping: 2a03:b020:0:404::50 Aug 30 11:26:22 volumio ntpd[1173]: DNS: Pool skipping: 2a00:6d41:200:2::13 Aug 30 11:26:22 volumio ntpd[1173]: DNS: Pool skipping: 2600:3c0b::f03c:94ff:fee2:cbb9 Aug 30 11:26:22 volumio ntpd[1173]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 Aug 30 11:26:22 volumio volumio[1431]: info: Discovery: Started advertising with name: Volumio Aug 30 11:26:23 volumio volumio[1431]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Aug 30 11:26:23 volumio volumio[1431]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Aug 30 11:26:23 volumio volumio[1431]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Aug 30 11:26:23 volumio volumio[1431]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Aug 30 11:26:23 volumio volumio[1431]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Aug 30 11:26:23 volumio volumio[1431]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Aug 30 11:26:23 volumio volumio[1431]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Aug 30 11:26:23 volumio volumio[1431]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Aug 30 11:26:23 volumio volumio[1431]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Aug 30 11:26:23 volumio volumio[1431]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Aug 30 11:26:23 volumio volumio[1431]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Aug 30 11:26:23 volumio volumio[1431]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Aug 30 11:26:23 volumio volumio[1431]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Aug 30 11:26:23 volumio volumio[1431]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Aug 30 11:26:23 volumio volumio[1431]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Aug 30 11:26:23 volumio volumio[1431]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Aug 30 11:26:23 volumio volumio[1431]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Aug 30 11:26:23 volumio volumio[1431]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Aug 30 11:26:23 volumio volumio[1431]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Aug 30 11:26:23 volumio volumio[1431]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Aug 30 11:26:23 volumio volumio[1431]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Aug 30 11:26:23 volumio volumio[1431]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Aug 30 11:26:23 volumio volumio[1431]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Aug 30 11:26:23 volumio volumio[1431]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Aug 30 11:26:23 volumio volumio[1431]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Aug 30 11:26:23 volumio volumio[1431]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Aug 30 11:26:23 volumio volumio[1431]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Aug 30 11:26:23 volumio volumio[1431]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Aug 30 11:26:23 volumio volumio[1431]: info: Adding plugin bluetooth to MyMusic Plugins Aug 30 11:26:23 volumio volumio[1431]: info: Adding plugin multiroom to MyMusic Plugins Aug 30 11:26:23 volumio volumio[1431]: info: Adding plugin metavolumio to MyMusic Plugins Aug 30 11:26:23 volumio volumio[1431]: info: Adding plugin cd_controller to MyMusic Plugins Aug 30 11:26:23 volumio volumio[1431]: info: Adding plugin qobuzconnect to MyMusic Plugins Aug 30 11:26:23 volumio volumio[1431]: info: Adding plugin smart_inputs to MyMusic Plugins Aug 30 11:26:23 volumio volumio[1431]: info: Adding plugin tidalconnect to MyMusic Plugins Aug 30 11:26:23 volumio volumio[1431]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Aug 30 11:26:23 volumio ntpd[1173]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Aug 30 11:26:23 volumio ntpd[1173]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Aug 30 11:26:23 volumio ntpd[1173]: DNS: Pool skipping: 195.32.70.195 Aug 30 11:26:23 volumio ntpd[1173]: DNS: Pool skipping: 81.56.230.156 Aug 30 11:26:23 volumio ntpd[1173]: DNS: Pool skipping: 95.110.135.141 Aug 30 11:26:23 volumio ntpd[1173]: DNS: Pool skipping: 162.159.200.123 Aug 30 11:26:23 volumio ntpd[1173]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 Aug 30 11:26:23 volumio volumio[1431]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Aug 30 11:26:23 volumio volumio[1431]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Aug 30 11:26:23 volumio volumio[1431]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 11:26:23 volumio volumio[1431]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 11:26:23 volumio volumio[1431]: info: Starting MyVolumio Remote Streaming Endpoints Aug 30 11:26:23 volumio volumio[1431]: info: MyVolumio login type: Token Aug 30 11:26:23 volumio volumio[1431]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Aug 30 11:26:23 volumio volumio[1431]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Aug 30 11:26:23 volumio volumio[1431]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Aug 30 11:26:23 volumio volumio[1431]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Aug 30 11:26:23 volumio volumio[1431]: info: Streaming services startup Aug 30 11:26:23 volumio volumio[1431]: info: Starting Streaming Daemon Aug 30 11:26:23 volumio sudo[1986]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 30 11:26:23 volumio sudo[1986]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 11:26:23 volumio volumio[1431]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Aug 30 11:26:23 volumio systemd[1]: Starting e2scrub_all.service - Online ext4 Metadata Check for All Filesystems... Aug 30 11:26:23 volumio sudo[1986]: pam_unix(sudo:session): session closed for user root Aug 30 11:26:23 volumio volumio[1431]: info: Discovery: adding 1faa2c16-d428-4333-88d7-85789e57ee57 Aug 30 11:26:23 volumio systemd[1]: e2scrub_all.service: Deactivated successfully. Aug 30 11:26:23 volumio systemd[1]: Finished e2scrub_all.service - Online ext4 Metadata Check for All Filesystems. Aug 30 11:26:23 volumio volumio[1431]: info: Discovery: Found device Volumio Aug 30 11:26:23 volumio volumio[1431]: info: CoreCommandRouter::volumioGetState Aug 30 11:26:23 volumio volumio[1431]: info: CorePlayQueue::getTrack 0 Aug 30 11:26:23 volumio volumio[1431]: info: Discovery: this is already registered, 1faa2c16-d428-4333-88d7-85789e57ee57 Aug 30 11:26:23 volumio volumio[1431]: info: Discovery: Found device Volumio Aug 30 11:26:23 volumio volumio[1431]: info: CoreCommandRouter::volumioGetState Aug 30 11:26:23 volumio volumio[1431]: info: CorePlayQueue::getTrack 0 Aug 30 11:26:23 volumio volumio[1431]: error: Cannot start Volumio Streaming Daemon Aug 30 11:26:23 volumio volumio[1431]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 30 11:26:23 volumio volumio[1431]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 30 11:26:23 volumio volumio[1431]: error: MyVolumio Custom Token format not valid, refreshing it Aug 30 11:26:24 volumio sudo[1848]: pam_unix(sudo:session): session closed for user root Aug 30 11:26:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Aug 30 11:26:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 11:26:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 11:26:24 volumio go-librespot[1996]: go-librespot daemon starting... Aug 30 11:26:24 volumio go-librespot[1997]: time="2026-08-30T11:26:24+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 11:26:24 volumio go-librespot[1997]: time="2026-08-30T11:26:24+02:00" level=debug msg="app state loaded" Aug 30 11:26:24 volumio go-librespot[1997]: time="2026-08-30T11:26:24+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 11:26:24 volumio ntpd[1173]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Aug 30 11:26:24 volumio ntpd[1173]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Aug 30 11:26:24 volumio ntpd[1173]: DNS: Pool skipping: 37.247.53.178 Aug 30 11:26:24 volumio ntpd[1173]: DNS: Pool skipping: 172.232.209.103 Aug 30 11:26:24 volumio ntpd[1173]: DNS: Pool skipping: 89.46.74.148 Aug 30 11:26:24 volumio ntpd[1173]: DNS: Pool skipping: 185.157.229.254 Aug 30 11:26:24 volumio ntpd[1173]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 Aug 30 11:26:24 volumio go-librespot[1997]: time="2026-08-30T11:26:24+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 30 11:26:24 volumio go-librespot[1997]: time="2026-08-30T11:26:24+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 30 11:26:24 volumio go-librespot[1997]: time="2026-08-30T11:26:24+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 30 11:26:24 volumio go-librespot[1997]: time="2026-08-30T11:26:24+02:00" level=info msg="zeroconf server listening on port 40741" Aug 30 11:26:24 volumio go-librespot[1997]: time="2026-08-30T11:26:24+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 11:26:24 volumio go-librespot[1997]: time="2026-08-30T11:26:24+02:00" level=debug msg="obtained new client token: AAGuL6eA8fGMG8WxCfC2Y21+r4Jmnjy0cZrVRHVlYy85FmMOOAw3Mb1zzwOS2XuyM3BeaxnpTQLou5u8i1us7WDQjj9FwVAsY2jtNpTqWJnHibNuGSxgiggx5NFZwo5fPuhlkORXR7fzYXDrfWDDbilSmA6AimiJENgqG8U/6TVpYU0hwg/Kr0RbIObEmJQ3u4wHbEJwDnmUTvPg/L6QcsVjyrlgVi8N3yRAtDVYbu2yow2h93JiPqfi" Aug 30 11:26:24 volumio go-librespot[1997]: time="2026-08-30T11:26:24+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 30 11:26:24 volumio go-librespot[1997]: time="2026-08-30T11:26:24+02:00" level=debug msg="completed keyexchange" Aug 30 11:26:24 volumio go-librespot[1997]: time="2026-08-30T11:26:24+02:00" level=debug msg="completed challenge" Aug 30 11:26:24 volumio go-librespot[1997]: time="2026-08-30T11:26:24+02:00" level=info msg="authenticated AP" username="be*****el" Aug 30 11:26:24 volumio volumio[1431]: info: MyVolumio login type: Token Aug 30 11:26:24 volumio go-librespot[1997]: time="2026-08-30T11:26:24+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 11:26:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 11:26:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 11:26:24 volumio volumio[1431]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Aug 30 11:26:24 volumio volumio[1431]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Aug 30 11:26:24 volumio volumio[1431]: info: Initializing connection to go-librespot Websocket Aug 30 11:26:24 volumio volumio[1431]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 11:26:25 volumio volumio[1431]: info: MyVolumio token set successfully Aug 30 11:26:25 volumio volumio[1431]: info: MYVOLUMIO: Adding device Aug 30 11:26:25 volumio volumio[1431]: info: MYVOLUMIO: Evaluating Server Aug 30 11:26:25 volumio tailscaled[1004]: open-conn-track: timeout opening (TCP 192.168.1.40:54442 => 100.91.133.23:445) to node [RIu8/]; online=yes, lastRecv=5s Aug 30 11:26:25 volumio volumio[1431]: info: MyVolumio status changed Aug 30 11:26:25 volumio volumio[1431]: info: Streaming services startup Aug 30 11:26:25 volumio volumio[1431]: info: Starting Streaming Daemon Aug 30 11:26:25 volumio volumio[1431]: info: Removing browser output: myVolumio user plan is not superstar Aug 30 11:26:25 volumio volumio[1431]: info: Removing audio output: Aug 30 11:26:25 volumio volumio[1431]: info: Stoppping Tunnel 1 Aug 30 11:26:25 volumio sudo[2029]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 30 11:26:25 volumio sudo[2029]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 11:26:25 volumio sudo[2031]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Aug 30 11:26:25 volumio sudo[2031]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 11:26:25 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 30 11:26:25 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 30 11:26:25 volumio sudo[2029]: pam_unix(sudo:session): session closed for user root Aug 30 11:26:25 volumio volumio[1431]: error: Cannot start Volumio Streaming Daemon Aug 30 11:26:25 volumio volumio[1431]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 30 11:26:25 volumio volumio[1431]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 30 11:26:25 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 30 11:26:25 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 30 11:26:25 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 30 11:26:25 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 30 11:26:25 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 30 11:26:25 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 30 11:26:25 volumio sudo[2031]: pam_unix(sudo:session): session closed for user root Aug 30 11:26:25 volumio volumio[1431]: info: Remote SSH Stopped Aug 30 11:26:25 volumio systemd[1]: systemd-fsckd.service: Deactivated successfully. Aug 30 11:26:25 volumio volumio[1431]: info: Setting Geolocation for MyVolumio to eu10 Aug 30 11:26:25 volumio volumio[1431]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 11:26:25 volumio volumio[1431]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 11:26:25 volumio volumio[1431]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 11:26:25 volumio volumio[1431]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Aug 30 11:26:26 volumio dhcpcd[905]: timed out Aug 30 11:26:26 volumio sh[887]: timed out Aug 30 11:26:26 volumio sh[827]: ifup: failed to bring up eth0 Aug 30 11:26:26 volumio systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Aug 30 11:26:26 volumio systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Aug 30 11:26:26 volumio tailscaled[1004]: magicsock: disco: node [RIu8/] d:b4ad8aa1fad23adc now using 87.0.244.87:41641 mtu=1360 tx=ef39d785d426 Aug 30 11:26:26 volumio volumio[1431]: info: Updating MyVolumio device info Aug 30 11:26:26 volumio volumio[1431]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 11:26:26 volumio volumio[1431]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 11:26:26 volumio volumio[1431]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 11:26:26 volumio volumio[1431]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Aug 30 11:26:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Aug 30 11:26:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 11:26:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 11:26:27 volumio go-librespot[2036]: go-librespot daemon starting... Aug 30 11:26:27 volumio go-librespot[2037]: time="2026-08-30T11:26:27+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 11:26:27 volumio go-librespot[2037]: time="2026-08-30T11:26:27+02:00" level=debug msg="app state loaded" Aug 30 11:26:27 volumio go-librespot[2037]: time="2026-08-30T11:26:27+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 11:26:27 volumio go-librespot[2037]: time="2026-08-30T11:26:27+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 30 11:26:27 volumio go-librespot[2037]: time="2026-08-30T11:26:27+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 30 11:26:27 volumio go-librespot[2037]: time="2026-08-30T11:26:27+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 30 11:26:27 volumio go-librespot[2037]: time="2026-08-30T11:26:27+02:00" level=info msg="zeroconf server listening on port 42193" Aug 30 11:26:27 volumio go-librespot[2037]: time="2026-08-30T11:26:27+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 11:26:27 volumio go-librespot[2037]: time="2026-08-30T11:26:27+02:00" level=debug msg="obtained new client token: AAGA82h2a9YuyDRY6/DZ77yk/QxPhrh6hPsRIbGqUTc0D6A/a1hvCDGT/T6e7SuDf55GmtJih44E+0Yl6JDslZfFXJ8cj+X25PyIR4Pcj9hYmnUV90tOqm+I9T+b7NA814hBGbBFCSzC+YD5QX6+jJ2mTLczH4M5Y2Pv6RXCvioDUcUZZr6teKPHFBR0QFie6OLiHNUED3Udd9seEWz+aLKCK2TOAAO68SNLrUql+mUyhujTyhNIWldr" Aug 30 11:26:27 volumio go-librespot[2037]: time="2026-08-30T11:26:27+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 30 11:26:27 volumio systemd[1]: systemd-hostnamed.service: Deactivated successfully. Aug 30 11:26:27 volumio volumio[1431]: info: Initializing connection to go-librespot Websocket Aug 30 11:26:27 volumio go-librespot[2037]: time="2026-08-30T11:26:27+02:00" level=debug msg="new websocket client" Aug 30 11:26:27 volumio volumio[1431]: info: Connection to go-librespot Websocket established Aug 30 11:26:27 volumio go-librespot[2037]: time="2026-08-30T11:26:27+02:00" level=debug msg="completed keyexchange" Aug 30 11:26:27 volumio go-librespot[2037]: time="2026-08-30T11:26:27+02:00" level=debug msg="completed challenge" Aug 30 11:26:27 volumio go-librespot[2037]: time="2026-08-30T11:26:27+02:00" level=info msg="authenticated AP" username="be*****el" Aug 30 11:26:28 volumio go-librespot[2037]: time="2026-08-30T11:26:28+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 11:26:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 11:26:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 11:26:28 volumio volumio[1431]: info: Connection to go-librespot Websocket closed Aug 30 11:26:28 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2. Aug 30 11:26:28 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 30 11:26:28 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 30 11:26:28 volumio sudo[1957]: pam_unix(sudo:session): session closed for user root Aug 30 11:26:28 volumio volumio[1431]: info: Upmpdcli Daemon Started Aug 30 11:26:28 volumio tailscaled[1004]: monitor: time jump detected (slept 805h45m44s), probably wake from sleep Aug 30 11:26:28 volumio tailscaled[1004]: LinkChange: major, rebinding: old: interfaces.State{defaultRoute=wlan0 ifs={wlan0:[192.168.1.40/24]} v4=true v6=false} new: interfaces.State{defaultRoute=wlan0 ifs={tailscale0:[100.104.80.53/32] wlan0:[192.168.1.40/24]} v4=true v6=false} diff: ips tailscale0: []->[100.104.80.53/32] rebind-reason=[time-jumped(805h45m44s),ips-changed] Aug 30 11:26:28 volumio tailscaled[1004]: dns: Set: {DefaultResolvers:[] Routes:{tailb64147.ts.net.:[] ts.net.:[199.247.155.53 2620:111:8007::53]}+65arpa SearchDomains:[tailb64147.ts.net.] Hosts:7} Aug 30 11:26:28 volumio tailscaled[1004]: dns: Resolvercfg: {Routes:{.:[192.168.1.254 208.67.222.222 208.67.222.222 208.67.220.220] ts.net.:[199.247.155.53 2620:111:8007::53]} Hosts:7 LocalDomains:[tailb64147.ts.net.]+65arpa} Aug 30 11:26:28 volumio tailscaled[1004]: dns: OScfg: {Nameservers:[100.100.100.100 fd7a:115c:a1e0::53] SearchDomains:[tailb64147.ts.net.] } Aug 30 11:26:28 volumio tailscaled[1004]: wgengine: set DNS config again after major link change Aug 30 11:26:28 volumio tailscaled[1004]: router: portUpdate(port=41641, network=udp6) Aug 30 11:26:28 volumio tailscaled[1004]: router: portUpdate(port=41641, network=udp4) Aug 30 11:26:28 volumio tailscaled[1004]: Rebind; defIf="wlan0", ips=[192.168.1.40/24] Aug 30 11:26:28 volumio tailscaled[1004]: magicsock: 1 active derp conns: derp-4=cr8s,wr2s Aug 30 11:26:28 volumio tailscaled[1004]: post-rebind ping of DERP region 4 okay Aug 30 11:26:29 volumio tailscaled[1004]: magicsock: disco: node [RIu8/] d:b4ad8aa1fad23adc now using 87.0.244.87:41641 mtu=1360 tx=43eb2b18640f Aug 30 11:26:29 volumio volumio[1431]: info: MYVOLUMIO: Adding device Aug 30 11:26:29 volumio volumio[1431]: info: MYVOLUMIO: Evaluating Server Aug 30 11:26:30 volumio volumio[1431]: info: Setting Geolocation for MyVolumio to eu11 Aug 30 11:26:30 volumio volumio[1431]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 11:26:30 volumio volumio[1431]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 11:26:30 volumio volumio[1431]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 11:26:30 volumio volumio[1431]: info: Getting Spotify volume Aug 30 11:26:30 volumio volumio[1431]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 30 11:26:30 volumio volumio[1431]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 11:26:30 volumio volumio[1431]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 30 11:26:30 volumio volumio[1431]: errno: -111, Aug 30 11:26:30 volumio volumio[1431]: code: 'ECONNREFUSED', Aug 30 11:26:30 volumio volumio[1431]: syscall: 'connect', Aug 30 11:26:30 volumio volumio[1431]: address: '127.0.0.1', Aug 30 11:26:30 volumio volumio[1431]: port: 9879, Aug 30 11:26:30 volumio volumio[1431]: response: undefined Aug 30 11:26:30 volumio volumio[1431]: } Aug 30 11:26:30 volumio volumio[1431]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 30 11:26:31 volumio sudo[2112]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-30 11:25' Aug 30 11:26:31 volumio sudo[2112]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="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"