Aug 28 09:05:05 player-parter ntpd[1147]: CLOCK: time stepped by 13236873.351095 Aug 28 09:05:05 player-parter ntpd[1147]: CLOCK: time changed from 2026-03-28 to 2026-08-28 Aug 28 09:05:05 player-parter ntpd[1147]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Aug 28 09:05:05 player-parter systemd[1]: Starting dpkg-db-backup.service - Daily dpkg database backup service... Aug 28 09:05:05 player-parter systemd[1]: Starting e2scrub_all.service - Online ext4 Metadata Check for All Filesystems... Aug 28 09:05:05 player-parter systemd[1]: Started ntpsec-rotate-stats.service - Rotate ntpd stats. Aug 28 09:05:05 player-parter systemd[1]: e2scrub_all.service: Deactivated successfully. Aug 28 09:05:05 player-parter systemd[1]: Finished e2scrub_all.service - Online ext4 Metadata Check for All Filesystems. Aug 28 09:05:05 player-parter systemd[1]: ntpsec-rotate-stats.service: Deactivated successfully. Aug 28 09:05:05 player-parter systemd[1]: dpkg-db-backup.service: Deactivated successfully. Aug 28 09:05:05 player-parter systemd[1]: Finished dpkg-db-backup.service - Daily dpkg database backup service. Aug 28 09:05:05 player-parter systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Aug 28 09:05:05 player-parter systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 28 09:05:05 player-parter systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 28 09:05:05 player-parter go-librespot[1779]: go-librespot daemon starting... Aug 28 09:05:05 player-parter go-librespot[1780]: time="2026-08-28T09:05:05+03:00" level=info msg="running go-librespot 0.7.1" Aug 28 09:05:05 player-parter go-librespot[1780]: time="2026-08-28T09:05:05+03:00" level=debug msg="app state loaded" Aug 28 09:05:05 player-parter go-librespot[1780]: time="2026-08-28T09:05:05+03:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 09:05:05 player-parter go-librespot[1780]: time="2026-08-28T09:05:05+03: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 28 09:05:05 player-parter go-librespot[1780]: time="2026-08-28T09:05:05+03: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 28 09:05:05 player-parter go-librespot[1780]: time="2026-08-28T09:05:05+03: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 28 09:05:05 player-parter go-librespot[1780]: time="2026-08-28T09:05:05+03:00" level=info msg="zeroconf server listening on port 40329" Aug 28 09:05:05 player-parter go-librespot[1780]: time="2026-08-28T09:05:05+03:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 28 09:05:05 player-parter go-librespot[1780]: time="2026-08-28T09:05:05+03:00" level=debug msg="obtained new client token: AAGZUgTu7xsbsqMcaqcLACWyB/N+3+Sjut+Fz4TeGCtLia5RahDDwOssC1Ca51pEKy2B+h+FaRRtMLZ3IH8emJVUNcl8sfxZ1QILcEHc6beqX3Z20vCNZOKZT1LpsI6QxReWqDODgIqA02I5F360OT8RwFeHETw7666ubwIQNPQJX3SwldTKGfbh/DkexjRxSYXvnb+Q8XtOVx/i/WdWDwl3G/aSsC8MVF4fI3ws/yA1JaYRExxXZwY=" Aug 28 09:05:06 player-parter go-librespot[1780]: time="2026-08-28T09:05:06+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 28 09:05:06 player-parter go-librespot[1780]: time="2026-08-28T09:05:06+03:00" level=debug msg="completed keyexchange" Aug 28 09:05:06 player-parter go-librespot[1780]: time="2026-08-28T09:05:06+03:00" level=debug msg="completed challenge" Aug 28 09:05:06 player-parter go-librespot[1780]: time="2026-08-28T09:05:06+03:00" level=info msg="authenticated AP" username="31************************ry" Aug 28 09:05:06 player-parter go-librespot[1780]: time="2026-08-28T09:05:06+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 28 09:05:06 player-parter systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 09:05:06 player-parter systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 09:05:08 player-parter upmpdcli[1812]: writing RSA key Aug 28 09:05:09 player-parter systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Aug 28 09:05:09 player-parter systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 28 09:05:09 player-parter systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 28 09:05:09 player-parter go-librespot[1858]: go-librespot daemon starting... Aug 28 09:05:09 player-parter go-librespot[1859]: time="2026-08-28T09:05:09+03:00" level=info msg="running go-librespot 0.7.1" Aug 28 09:05:09 player-parter go-librespot[1859]: time="2026-08-28T09:05:09+03:00" level=debug msg="app state loaded" Aug 28 09:05:09 player-parter go-librespot[1859]: time="2026-08-28T09:05:09+03:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 09:05:09 player-parter go-librespot[1859]: time="2026-08-28T09:05:09+03: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 28 09:05:09 player-parter go-librespot[1859]: time="2026-08-28T09:05:09+03: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 28 09:05:09 player-parter go-librespot[1859]: time="2026-08-28T09:05:09+03: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 28 09:05:09 player-parter go-librespot[1859]: time="2026-08-28T09:05:09+03:00" level=info msg="zeroconf server listening on port 43515" Aug 28 09:05:09 player-parter go-librespot[1859]: time="2026-08-28T09:05:09+03:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 28 09:05:09 player-parter go-librespot[1859]: time="2026-08-28T09:05:09+03:00" level=debug msg="obtained new client token: AAFlRUxlRUmaudgkwR2p+jpr0bozUNEerGcsCyAUr0IckXmx4DMggEKVNdit5cJtgwgOr7FHOxXDx8Ab5AHT2NTgJ1UBEMxqx2tbvgQgx97fiYxW3a61z5h4pVcEn+EuA+cpnJzDnlFYyGcRIiTCkKD36hrE/SVCi9nxlNff3stxOwnqvO7vVcO6JtWt/V78EJc9JA7rYrLdIi+KBLZDp2TXa/Fv/NZDLVNC0+B9nLS8F267UOJUE6Y=" Aug 28 09:05:09 player-parter go-librespot[1859]: time="2026-08-28T09:05:09+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 28 09:05:10 player-parter go-librespot[1859]: time="2026-08-28T09:05:10+03:00" level=debug msg="completed keyexchange" Aug 28 09:05:10 player-parter go-librespot[1859]: time="2026-08-28T09:05:10+03:00" level=debug msg="completed challenge" Aug 28 09:05:10 player-parter go-librespot[1859]: time="2026-08-28T09:05:10+03:00" level=info msg="authenticated AP" username="31************************ry" Aug 28 09:05:10 player-parter go-librespot[1859]: time="2026-08-28T09:05:10+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 28 09:05:10 player-parter systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 09:05:10 player-parter systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 09:05:10 player-parter systemd[1]: Stopping mpd.service - Music Player Daemon... Aug 28 09:05:10 player-parter bluetoothd[946]: Path / reserved for Adv Monitor app :1.27 Aug 28 09:05:10 player-parter bluetoothd[946]: Adv Monitor app :1.27 disconnected from D-Bus Aug 28 09:05:10 player-parter systemd[1]: mpd.service: Deactivated successfully. Aug 28 09:05:10 player-parter systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 28 09:05:10 player-parter systemd[1]: mpd.service: Consumed 1.343s CPU time. Aug 28 09:05:10 player-parter systemd[1]: mpd.socket: Deactivated successfully. Aug 28 09:05:10 player-parter systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 28 09:05:10 player-parter systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 28 09:05:10 player-parter systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 28 09:05:10 player-parter systemd[1]: Starting mpd.service - Music Player Daemon... Aug 28 09:05:10 player-parter systemd[1]: Started volumiobt.service - Volumio Bluetooth Module. Aug 28 09:05:10 player-parter sudo[1927]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 28 09:05:10 player-parter volumiobt[1938]: INFO [BTSTART] Ensuring Bluetooth directory exists... Aug 28 09:05:10 player-parter sudo[1927]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 28 09:05:10 player-parter sudo[1927]: pam_unix(sudo:session): session closed for user root Aug 28 09:05:10 player-parter sudo[1940]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /var/lib/bluetooth Aug 28 09:05:10 player-parter sudo[1940]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 09:05:10 player-parter sudo[1940]: pam_unix(sudo:session): session closed for user root Aug 28 09:05:10 player-parter sudo[1944]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth Aug 28 09:05:10 player-parter sudo[1944]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 09:05:10 player-parter sudo[1944]: pam_unix(sudo:session): session closed for user root Aug 28 09:05:10 player-parter volumiobt[1948]: INFO [BTSTART] Powering on Bluetooth if needed... Aug 28 09:05:10 player-parter bluetoothd[946]: Adv Monitor app :1.29 disconnected from D-Bus Aug 28 09:05:10 player-parter volumiobt[1953]: INFO [BTSTART] Making Bluetooth discoverable and pairable... Aug 28 09:05:10 player-parter systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 28 09:05:10 player-parter volumiobt[1955]: [176B blob data] Aug 28 09:05:10 player-parter volumiobt[1955]: [157B blob data] Aug 28 09:05:10 player-parter volumiobt[1955]: [157B blob data] Aug 28 09:05:10 player-parter volumiobt[1955]: [157B blob data] Aug 28 09:05:10 player-parter volumiobt[1955]: [113B blob data] Aug 28 09:05:10 player-parter volumiobt[1955]: [bluetoothctl]> discoverable on Aug 28 09:05:10 player-parter volumiobt[1955]: Warning: setting discoverable while discoverable-timeout not set(0) is not recommended Aug 28 09:05:10 player-parter systemd[1]: shairport-sync.service: Deactivated successfully. Aug 28 09:05:10 player-parter volumiobt[1955]: [bluetoothctl]> pairable on Aug 28 09:05:10 player-parter bluetoothd[946]: Path / reserved for Adv Monitor app :1.30 Aug 28 09:05:10 player-parter systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 28 09:05:10 player-parter systemd[1]: shairport-sync.service: Consumed 1.446s CPU time. Aug 28 09:05:10 player-parter bluetoothd[946]: Adv Monitor app :1.30 disconnected from D-Bus Aug 28 09:05:10 player-parter volumiobt[1955]: [bluetoothctl]> Aug 28 09:05:10 player-parter volumiobt[1957]: INFO [BTSTART] Registering Bluetooth agent... Aug 28 09:05:10 player-parter volumiobt[1958]: [NEW] Media /org/bluez/hci0 Aug 28 09:05:10 player-parter volumiobt[1958]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb Aug 28 09:05:10 player-parter volumiobt[1958]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb Aug 28 09:05:10 player-parter volumiobt[1958]: SupportedUUIDs: 0000FDF0-0000-1000-8000-00805f9b34fb Aug 28 09:05:10 player-parter bluetoothd[946]: Adv Monitor app :1.31 disconnected from D-Bus Aug 28 09:05:10 player-parter systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 28 09:05:10 player-parter volumiobt[1959]: No agent is registered Aug 28 09:05:10 player-parter volumiobt[1959]: [NEW] Media /org/bluez/hci0 Aug 28 09:05:10 player-parter volumiobt[1959]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb Aug 28 09:05:10 player-parter volumiobt[1959]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb Aug 28 09:05:10 player-parter volumiobt[1959]: SupportedUUIDs: 0000FDF0-0000-1000-8000-00805f9b34fb Aug 28 09:05:10 player-parter bluetoothd[946]: Adv Monitor app :1.32 disconnected from D-Bus Aug 28 09:05:10 player-parter volumiobt[1961]: INFO [BTSTART] Agent registered successfully. Aug 28 09:05:10 player-parter volumiobt[1974]: INFO [BTSTART] Starting A2DP agent (a2dp-agent)... Aug 28 09:05:10 player-parter volumiobt[1975]: 2026-08-28 09:05:10 a2dp-agent [INFO] Connecting to system D-Bus Aug 28 09:05:10 player-parter volumiobt[1975]: 2026-08-28 09:05:10 a2dp-agent [INFO] Connected to system D-Bus Aug 28 09:05:10 player-parter volumiobt[1975]: 2026-08-28 09:05:10 bluezutils [INFO] Found adapter at: /org/bluez/hci0 Aug 28 09:05:10 player-parter volumiobt[1975]: 2026-08-28 09:05:10 a2dp-agent [INFO] Found Bluetooth adapter: /org/bluez/hci0 Aug 28 09:05:10 player-parter volumiobt[1975]: 2026-08-28 09:05:10 a2dp-agent [INFO] Set DiscoverableTimeout to infinite Aug 28 09:05:10 player-parter volumiobt[1975]: 2026-08-28 09:05:10 a2dp-agent [INFO] Enabled Discoverable mode Aug 28 09:05:10 player-parter volumiobt[1975]: 2026-08-28 09:05:10 a2dp-agent [INFO] Agent registered at /local/a2dpagent Aug 28 09:05:10 player-parter volumiobt[1975]: 2026-08-28 09:05:10 a2dp-agent [INFO] Agent set as default Aug 28 09:05:10 player-parter volumiobt[1975]: 2026-08-28 09:05:10 a2dp-agent [INFO] A2DP agent running, waiting for connections... Aug 28 09:05:10 player-parter mpd[1941]: 2026-08-28T09:05:10 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 28 09:05:10 player-parter systemd[1]: Started mpd.service - Music Player Daemon. Aug 28 09:05:12 player-parter systemd[1]: systemd-fsckd.service: Deactivated successfully. Aug 28 09:05:13 player-parter systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Aug 28 09:05:13 player-parter systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 28 09:05:13 player-parter systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 28 09:05:13 player-parter go-librespot[1980]: go-librespot daemon starting... Aug 28 09:05:13 player-parter go-librespot[1981]: time="2026-08-28T09:05:13+03:00" level=info msg="running go-librespot 0.7.1" Aug 28 09:05:13 player-parter go-librespot[1981]: time="2026-08-28T09:05:13+03:00" level=debug msg="app state loaded" Aug 28 09:05:13 player-parter go-librespot[1981]: time="2026-08-28T09:05:13+03:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 09:05:13 player-parter go-librespot[1981]: time="2026-08-28T09:05:13+03: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 28 09:05:13 player-parter go-librespot[1981]: time="2026-08-28T09:05:13+03: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 28 09:05:13 player-parter go-librespot[1981]: time="2026-08-28T09:05:13+03: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 28 09:05:13 player-parter go-librespot[1981]: time="2026-08-28T09:05:13+03:00" level=info msg="zeroconf server listening on port 35309" Aug 28 09:05:13 player-parter go-librespot[1981]: time="2026-08-28T09:05:13+03:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 28 09:05:13 player-parter go-librespot[1981]: time="2026-08-28T09:05:13+03:00" level=debug msg="obtained new client token: AAHiON72uuicX+davWbTYisJC8QR2RiKXGoBovNIJQgcb1p6yq2v8fBkZlr5dBfPcCQTQ4nQZK2QwWs1iY/+iJzKaaqp8eAlhcKt7/2jjek02xYvX+cx3ZjWZeZ6VzdqTXH07f70KUvpGvtj7rHA5RhTlwk4emFPPfFNSkXheh41lEUCou1xkPP8wwCugjXlqW4xWdrNCsqE8aY2x/C7UmVbeondUGsi0WBAP/M/ASokVVewqELI5Q0=" Aug 28 09:05:13 player-parter go-librespot[1981]: time="2026-08-28T09:05:13+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 28 09:05:13 player-parter go-librespot[1981]: time="2026-08-28T09:05:13+03:00" level=debug msg="completed keyexchange" Aug 28 09:05:13 player-parter go-librespot[1981]: time="2026-08-28T09:05:13+03:00" level=debug msg="completed challenge" Aug 28 09:05:13 player-parter 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 28 09:05:13 player-parter 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 28 09:05:13 player-parter go-librespot[1981]: time="2026-08-28T09:05:13+03:00" level=info msg="authenticated AP" username="31************************ry" Aug 28 09:05:14 player-parter systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Aug 28 09:05:14 player-parter autossh[1999]: port set to 0, monitoring disabled Aug 28 09:05:14 player-parter autossh[1999]: starting ssh (count 1) Aug 28 09:05:14 player-parter autossh[1999]: ssh child pid is 2002 Aug 28 09:05:14 player-parter systemd[1]: systemd-hostnamed.service: Deactivated successfully. Aug 28 09:05:14 player-parter go-librespot[1981]: time="2026-08-28T09:05:14+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 28 09:05:14 player-parter systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 09:05:14 player-parter systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 09:05:14 player-parter volumiossh-tunnel[2002]: Warning: Permanently added '[eu10.myvolumio.org]:2222' (RSA) to the list of known hosts. Aug 28 09:05:16 player-parter systemd-journald[526]: Suppressed 99657 messages from volumio.service Aug 28 09:05:16 player-parter volumio[1232]: info: Initializing connection to go-librespot Websocket Aug 28 09:05:16 player-parter volumio[1232]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 09:05:17 player-parter systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Aug 28 09:05:17 player-parter systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 28 09:05:17 player-parter systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 28 09:05:17 player-parter go-librespot[2020]: go-librespot daemon starting... Aug 28 09:05:17 player-parter go-librespot[2021]: time="2026-08-28T09:05:17+03:00" level=info msg="running go-librespot 0.7.1" Aug 28 09:05:17 player-parter go-librespot[2021]: time="2026-08-28T09:05:17+03:00" level=debug msg="app state loaded" Aug 28 09:05:17 player-parter go-librespot[2021]: time="2026-08-28T09:05:17+03:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 09:05:17 player-parter go-librespot[2021]: time="2026-08-28T09:05:17+03: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 28 09:05:17 player-parter go-librespot[2021]: time="2026-08-28T09:05:17+03: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 28 09:05:17 player-parter go-librespot[2021]: time="2026-08-28T09:05:17+03: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 28 09:05:17 player-parter go-librespot[2021]: time="2026-08-28T09:05:17+03:00" level=info msg="zeroconf server listening on port 46777" Aug 28 09:05:17 player-parter go-librespot[2021]: time="2026-08-28T09:05:17+03:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 28 09:05:17 player-parter volumio[1232]: info: BOOT COMPLETED Aug 28 09:05:17 player-parter go-librespot[2021]: time="2026-08-28T09:05:17+03:00" level=debug msg="obtained new client token: AAHvpy+kwYAr8yN/A3vEL/5N3Kr+Jy8REdn6g6pskB9XsbDpIXJAMDYFpV2ay5MmBsM1n7ZycsqWQ4LPdduCi+zbbqKjVEPVpWElNvh3rX2mnOOrZ98B6+PSo3iPz0s4l1H5WpaLEQRtyFPgT2USugpqkOHnZNvfS+d7enQwQPUkBa65YbzM2VR1OJX9a4TgEH7250CON1ZCoXZiu9WabOSKrQzNGqnKt+D1Szpo52+YgbsdTb0+tZw=" Aug 28 09:05:17 player-parter go-librespot[2021]: time="2026-08-28T09:05:17+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 28 09:05:17 player-parter go-librespot[2021]: time="2026-08-28T09:05:17+03:00" level=debug msg="completed keyexchange" Aug 28 09:05:17 player-parter go-librespot[2021]: time="2026-08-28T09:05:17+03:00" level=debug msg="completed challenge" Aug 28 09:05:17 player-parter go-librespot[2021]: time="2026-08-28T09:05:17+03:00" level=info msg="authenticated AP" username="31************************ry" Aug 28 09:05:17 player-parter go-librespot[2021]: time="2026-08-28T09:05:17+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 28 09:05:17 player-parter systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 09:05:17 player-parter systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 09:05:18 player-parter volumio[1232]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 28 09:05:18 player-parter volumio[1232]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 28 09:05:18 player-parter volumio[1232]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 28 09:05:18 player-parter volumio-remote-updater[961]: Test mode disabled Aug 28 09:05:18 player-parter volumio-remote-updater[961]: Alpha mode disabled Aug 28 09:05:18 player-parter volumio-remote-updater[961]: Alpha legacy test mode disabled Aug 28 09:05:18 player-parter volumio[1232]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Aug 28 09:05:19 player-parter volumio[1232]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Aug 28 09:05:19 player-parter volumio[1232]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Aug 28 09:05:19 player-parter volumio[1232]: info: Initializing connection to go-librespot Websocket Aug 28 09:05:19 player-parter volumio[1232]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 09:05:20 player-parter systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Aug 28 09:05:20 player-parter systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 28 09:05:21 player-parter systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 28 09:05:21 player-parter go-librespot[2035]: go-librespot daemon starting... Aug 28 09:05:21 player-parter go-librespot[2036]: time="2026-08-28T09:05:21+03:00" level=info msg="running go-librespot 0.7.1" Aug 28 09:05:21 player-parter go-librespot[2036]: time="2026-08-28T09:05:21+03:00" level=debug msg="app state loaded" Aug 28 09:05:21 player-parter go-librespot[2036]: time="2026-08-28T09:05:21+03:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 09:05:21 player-parter go-librespot[2036]: time="2026-08-28T09:05:21+03: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 28 09:05:21 player-parter go-librespot[2036]: time="2026-08-28T09:05:21+03: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 28 09:05:21 player-parter go-librespot[2036]: time="2026-08-28T09:05:21+03: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 28 09:05:21 player-parter go-librespot[2036]: time="2026-08-28T09:05:21+03:00" level=info msg="zeroconf server listening on port 36439" Aug 28 09:05:21 player-parter go-librespot[2036]: time="2026-08-28T09:05:21+03:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 28 09:05:21 player-parter go-librespot[2036]: time="2026-08-28T09:05:21+03:00" level=debug msg="obtained new client token: AAFhY8JwSf9DVpbmX0AhTIYwppr7N58MRkPmDEIguN6571gRb/nOlod64aQqT94oBtOfIVr7d8FWhGE/rzkp9QjgMZSVn3pSvV2RdLf6tR/j5zHpTXj5UbQJumq7YByzcd79rx8kR0WNPqUBsBVsoYYnV3ywh9b2eYU/A6TkzIgxCnWQoz3zWNbXgS57CdB8UjLqxrOMTDcaQQQwEcS/Dsx72CkvVgkwkaciO5cdynHUFPY7Zd7k4TQ=" Aug 28 09:05:21 player-parter volumio[1232]: info: Discovery: adding 9015dafa-a7e4-4c45-8775-8675a105e780 Aug 28 09:05:21 player-parter volumio[1232]: info: Discovery: Found device Player Etaj Aug 28 09:05:21 player-parter volumio[1232]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 28 09:05:21 player-parter volumio[1232]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Aug 28 09:05:21 player-parter volumio[1232]: info: CoreCommandRouter::volumioGetState Aug 28 09:05:21 player-parter volumio[1232]: info: CorePlayQueue::getTrack 0 Aug 28 09:05:22 player-parter volumio[1232]: info: Initializing connection to go-librespot Websocket Aug 28 09:05:22 player-parter go-librespot[2036]: time="2026-08-28T09:05:22+03:00" level=debug msg="new websocket client" Aug 28 09:05:22 player-parter volumio[1232]: info: Connection to go-librespot Websocket established Aug 28 09:05:22 player-parter go-librespot[2036]: time="2026-08-28T09:05:22+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 28 09:05:22 player-parter go-librespot[2036]: time="2026-08-28T09:05:22+03:00" level=debug msg="completed keyexchange" Aug 28 09:05:22 player-parter go-librespot[2036]: time="2026-08-28T09:05:22+03:00" level=debug msg="completed challenge" Aug 28 09:05:22 player-parter go-librespot[2036]: time="2026-08-28T09:05:22+03:00" level=info msg="authenticated AP" username="31************************ry" Aug 28 09:05:22 player-parter go-librespot[2036]: time="2026-08-28T09:05:22+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 28 09:05:22 player-parter systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 09:05:22 player-parter systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 09:05:22 player-parter volumio[1232]: info: Connection to go-librespot Websocket closed Aug 28 09:05:25 player-parter volumio[1232]: info: Getting Spotify volume Aug 28 09:05:25 player-parter volumio[1232]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 28 09:05:25 player-parter volumio[1232]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 09:05:25 player-parter volumio[1232]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 28 09:05:25 player-parter volumio[1232]: errno: -111, Aug 28 09:05:25 player-parter volumio[1232]: code: 'ECONNREFUSED', Aug 28 09:05:25 player-parter volumio[1232]: syscall: 'connect', Aug 28 09:05:25 player-parter volumio[1232]: address: '127.0.0.1', Aug 28 09:05:25 player-parter volumio[1232]: port: 9879, Aug 28 09:05:25 player-parter volumio[1232]: response: undefined Aug 28 09:05:25 player-parter volumio[1232]: } Aug 28 09:05:25 player-parter volumio[1232]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 28 09:05:25 player-parter sudo[2061]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-28 09:04' Aug 28 09:05:25 player-parter sudo[2061]: 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"