Aug 26 15:11:38 volumio ntpd[942]: CLOCK: time stepped by 2174719.501061 Aug 26 15:11:38 volumio ntpd[942]: CLOCK: time changed from 2026-08-01 to 2026-08-26 Aug 26 15:11:38 volumio ntpd[942]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Aug 26 15:11:38 volumio go-librespot[15502]: time="2026-08-26T15:11:38+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Aug 26 15:11:38 volumio volumio[15227]: info: Discovery: A device disappeared from network Aug 26 15:11:38 volumio go-librespot[15502]: time="2026-08-26T15:11:38+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 26 15:11:38 volumio volumio[15227]: info: Discovery: A device disappeared from network Aug 26 15:11:38 volumio go-librespot[15502]: time="2026-08-26T15:11:38+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Aug 26 15:11:38 volumio systemd[1]: Starting apt-daily.service - Daily apt download activities... Aug 26 15:11:38 volumio systemd[1]: Starting dpkg-db-backup.service - Daily dpkg database backup service... Aug 26 15:11:38 volumio systemd[1]: Starting e2scrub_all.service - Online ext4 Metadata Check for All Filesystems... Aug 26 15:11:38 volumio systemd[1]: Starting fstrim.service - Discard unused blocks on filesystems from /etc/fstab... Aug 26 15:11:38 volumio systemd[1]: Started ntpsec-rotate-stats.service - Rotate ntpd stats. Aug 26 15:11:39 volumio systemd[1]: e2scrub_all.service: Deactivated successfully. Aug 26 15:11:39 volumio systemd[1]: Finished e2scrub_all.service - Online ext4 Metadata Check for All Filesystems. Aug 26 15:11:39 volumio systemd[1]: ntpsec-rotate-stats.service: Deactivated successfully. Aug 26 15:11:39 volumio systemd[1]: dpkg-db-backup.service: Deactivated successfully. Aug 26 15:11:39 volumio systemd[1]: Finished dpkg-db-backup.service - Daily dpkg database backup service. Aug 26 15:11:39 volumio volumio[15227]: info: Discovery: adding c4f852fe-4754-423c-8776-551343cd80f1 Aug 26 15:11:39 volumio volumio[15227]: info: Discovery: Found device Volumio Aug 26 15:11:39 volumio volumio[15227]: info: CoreCommandRouter::volumioGetState Aug 26 15:11:39 volumio volumio[15227]: info: CorePlayQueue::getTrack 0 Aug 26 15:11:39 volumio volumio[15227]: info: Discovery: this is already registered, c4f852fe-4754-423c-8776-551343cd80f1 Aug 26 15:11:39 volumio volumio[15227]: info: Discovery: Found device Volumio Aug 26 15:11:39 volumio volumio[15227]: info: CoreCommandRouter::volumioGetState Aug 26 15:11:39 volumio volumio[15227]: info: CorePlayQueue::getTrack 0 Aug 26 15:11:39 volumio go-librespot[15502]: time="2026-08-26T15:11:39+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:80, retrying with a different AP" error="dial tcp 34.158.1.133:80: connect: connection refused" Aug 26 15:11:39 volumio fstrim[15569]: /boot: 273.3 MiB (286572544 bytes) trimmed on /dev/mmcblk0p1 Aug 26 15:11:39 volumio systemd[1]: fstrim.service: Deactivated successfully. Aug 26 15:11:39 volumio systemd[1]: Finished fstrim.service - Discard unused blocks on filesystems from /etc/fstab. Aug 26 15:11:39 volumio go-librespot[15502]: time="2026-08-26T15:11:39+02:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 26 15:11:39 volumio volumio[15227]: info: Volumio Network Manager: Network status updated: 1 Aug 26 15:11:39 volumio volumio[15227]: info: go-librespot daemon successfully initialized Aug 26 15:11:39 volumio go-librespot[15502]: time="2026-08-26T15:11:39+02:00" level=debug msg="completed keyexchange" Aug 26 15:11:39 volumio go-librespot[15502]: time="2026-08-26T15:11:39+02:00" level=debug msg="completed challenge" Aug 26 15:11:39 volumio go-librespot[15502]: time="2026-08-26T15:11:39+02:00" level=info msg="authenticated AP" username="p.*********en" Aug 26 15:11:40 volumio go-librespot[15502]: time="2026-08-26T15:11:40+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 15:11:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 15:11:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 15:11:40 volumio systemd[1]: go-librespot-daemon.service: Consumed 1.042s CPU time. Aug 26 15:11:40 volumio systemd[1]: apt-daily.service: Deactivated successfully. Aug 26 15:11:40 volumio systemd[1]: Finished apt-daily.service - Daily apt download activities. Aug 26 15:11:40 volumio systemd[1]: apt-daily.service: Consumed 1.278s CPU time. Aug 26 15:11:40 volumio systemd[1]: Starting apt-daily-upgrade.service - Daily apt upgrade and clean activities... Aug 26 15:11:40 volumio mpd[15473]: 2026-08-26T15:11:40 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 26 15:11:41 volumio systemd[1]: Started mpd.service - Music Player Daemon. Aug 26 15:11:41 volumio sudo[15433]: pam_unix(sudo:session): session closed for user root Aug 26 15:11:41 volumio sudo[15420]: pam_unix(sudo:session): session closed for user root Aug 26 15:11:41 volumio volumio[15227]: info: Completed starting Core Plugins Aug 26 15:11:41 volumio volumio[15227]: info: ------------------------------------------- Aug 26 15:11:41 volumio volumio[15227]: info: ----- MyVolumio plugins startup ---- Aug 26 15:11:41 volumio volumio[15227]: info: ------------------------------------------- Aug 26 15:11:41 volumio volumio[15227]: info: [MyVolumio PluginManager] Fetching plans data.... Aug 26 15:11:41 volumio volumio[15227]: error: MPD error: The expression evaluated to a falsy value: Aug 26 15:11:41 volumio volumio[15227]: assert.ok(self.idling) Aug 26 15:11:41 volumio volumio[15227]: error: The expression evaluated to a falsy value: Aug 26 15:11:41 volumio volumio[15227]: assert.ok(self.idling) Aug 26 15:11:41 volumio volumio[15227]: info: MPD running with PID15473 Aug 26 15:11:41 volumio volumio[15227]: ,establishing connection Aug 26 15:11:41 volumio volumio[15227]: error: updateQueue error: null Aug 26 15:11:41 volumio volumio[15227]: error: updateQueue error: null Aug 26 15:11:42 volumio systemd[1]: apt-daily-upgrade.service: Deactivated successfully. Aug 26 15:11:42 volumio systemd[1]: Finished apt-daily-upgrade.service - Daily apt upgrade and clean activities. Aug 26 15:11:42 volumio systemd[1]: apt-daily-upgrade.service: Consumed 1.206s CPU time. Aug 26 15:11:42 volumio volumio[15227]: info: Initializing connection to go-librespot Websocket Aug 26 15:11:42 volumio volumio[15227]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 26 15:11:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 26 15:11:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 15:11:43 volumio systemd[1]: go-librespot-daemon.service: Consumed 1.042s CPU time. Aug 26 15:11:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 15:11:43 volumio go-librespot[15698]: go-librespot daemon starting... Aug 26 15:11:43 volumio go-librespot[15699]: time="2026-08-26T15:11:43+02:00" level=info msg="running go-librespot 0.7.1" Aug 26 15:11:43 volumio go-librespot[15699]: time="2026-08-26T15:11:43+02:00" level=debug msg="app state loaded" Aug 26 15:11:43 volumio go-librespot[15699]: time="2026-08-26T15:11:43+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 15:11:43 volumio go-librespot[15699]: time="2026-08-26T15:11:43+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 26 15:11:43 volumio go-librespot[15699]: time="2026-08-26T15:11:43+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 26 15:11:43 volumio go-librespot[15699]: time="2026-08-26T15:11:43+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 26 15:11:43 volumio go-librespot[15699]: time="2026-08-26T15:11:43+02:00" level=info msg="zeroconf server listening on port 44021" Aug 26 15:11:43 volumio go-librespot[15699]: time="2026-08-26T15:11:43+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 15:11:44 volumio go-librespot[15699]: time="2026-08-26T15:11:44+02:00" level=debug msg="obtained new client token: AAEaTx1xdVxkWPDv+aGwjJyfNswAEucw2FRAkX1bsNBH4wr/XPSXKqvJW+cpUPfKk5RxXc3uhy19/dZZK5ntbV+aDE7mE+QHnVGZxLDuuN3OIuvtBVjMkDrblJ76fio2rcnie9zQ6GvnPxYgBXOBFyJuXDwDuWDq0Tmgb5GPsBrrNREWM5yzJp7njHsKhNgvVjvt3nHDYU+WpLxDL++e3k9PFU1gXAhuKiWhr7I8cXRkCSeGyNeITw==" Aug 26 15:11:44 volumio go-librespot[15699]: time="2026-08-26T15:11:44+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 26 15:11:44 volumio go-librespot[15699]: time="2026-08-26T15:11:44+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Aug 26 15:11:44 volumio go-librespot[15699]: time="2026-08-26T15:11:44+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 26 15:11:44 volumio go-librespot[15699]: time="2026-08-26T15:11:44+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.178.17:46642->34.158.1.133:443: read: connection reset by peer" Aug 26 15:11:45 volumio go-librespot[15699]: time="2026-08-26T15:11:45+02:00" level=debug msg="connected to ap-gew4.spotify.com:80" Aug 26 15:11:45 volumio go-librespot[15699]: time="2026-08-26T15:11:45+02:00" level=debug msg="completed keyexchange" Aug 26 15:11:45 volumio go-librespot[15699]: time="2026-08-26T15:11:45+02:00" level=debug msg="completed challenge" Aug 26 15:11:45 volumio go-librespot[15699]: time="2026-08-26T15:11:45+02:00" level=info msg="authenticated AP" username="p.*********en" Aug 26 15:11:45 volumio volumio[15227]: info: Initializing connection to go-librespot Websocket Aug 26 15:11:45 volumio go-librespot[15699]: time="2026-08-26T15:11:45+02:00" level=debug msg="new websocket client" Aug 26 15:11:45 volumio volumio[15227]: info: Connection to go-librespot Websocket established Aug 26 15:11:45 volumio go-librespot[15699]: time="2026-08-26T15:11: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 26 15:11:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 15:11:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 15:11:45 volumio volumio[15227]: info: Connection to go-librespot Websocket closed Aug 26 15:11:46 volumio volumio[15227]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Aug 26 15:11:48 volumio volumio[15227]: info: Getting Spotify volume Aug 26 15:11:48 volumio volumio[15227]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 26 15:11:48 volumio volumio[15227]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 26 15:11:48 volumio volumio[15227]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 26 15:11:48 volumio volumio[15227]: errno: -111, Aug 26 15:11:48 volumio volumio[15227]: code: 'ECONNREFUSED', Aug 26 15:11:48 volumio volumio[15227]: syscall: 'connect', Aug 26 15:11:48 volumio volumio[15227]: address: '127.0.0.1', Aug 26 15:11:48 volumio volumio[15227]: port: 9879, Aug 26 15:11:48 volumio volumio[15227]: response: undefined Aug 26 15:11:48 volumio volumio[15227]: } Aug 26 15:11:48 volumio volumio[15227]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 26 15:11:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 26 15:11:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 15:11:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 15:11:48 volumio go-librespot[15712]: go-librespot daemon starting... Aug 26 15:11:48 volumio go-librespot[15721]: time="2026-08-26T15:11:48+02:00" level=info msg="running go-librespot 0.7.1" Aug 26 15:11:48 volumio go-librespot[15721]: time="2026-08-26T15:11:48+02:00" level=debug msg="app state loaded" Aug 26 15:11:49 volumio go-librespot[15721]: time="2026-08-26T15:11:49+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 15:11:49 volumio go-librespot[15721]: time="2026-08-26T15:11:49+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-gae2.spotify.com:80]" Aug 26 15:11:49 volumio go-librespot[15721]: time="2026-08-26T15:11:49+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 26 15:11:49 volumio go-librespot[15721]: time="2026-08-26T15:11:49+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 26 15:11:49 volumio go-librespot[15721]: time="2026-08-26T15:11:49+02:00" level=info msg="zeroconf server listening on port 43889" Aug 26 15:11:49 volumio go-librespot[15721]: time="2026-08-26T15:11:49+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 15:11:49 volumio go-librespot[15721]: time="2026-08-26T15:11:49+02:00" level=debug msg="obtained new client token: AAEmIp/yP2jBSEmgCQRl2iCPd86SSSxPwmMRIHxNAcI2a/r1cENCT5oEvTppTN490NUifKRzUenIf4h8bZ56nNg9ev17iVdkMmYh3J1Y8v9tPUvFUcXMpWVRu5A9xW+IZF4wAlYv4g67tZQgMzFS5idfTdJLE9f/F0HS/B1mYImIPZ0HcjTgp+NgqLAkeXf77CZhKD4JtpC5US6qn3BGG3BGN+tqmUKST+/vBiP17d3pCzvILfO37PcT" Aug 26 15:11:49 volumio go-librespot[15721]: time="2026-08-26T15:11:49+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Aug 26 15:11:49 volumio go-librespot[15721]: time="2026-08-26T15:11:49+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 26 15:11:49 volumio go-librespot[15721]: time="2026-08-26T15:11:49+02:00" level=debug msg="completed keyexchange" Aug 26 15:11:49 volumio go-librespot[15721]: time="2026-08-26T15:11:49+02:00" level=debug msg="completed challenge" Aug 26 15:11:50 volumio go-librespot[15721]: time="2026-08-26T15:11:50+02:00" level=info msg="authenticated AP" username="p.*********en" Aug 26 15:11:50 volumio go-librespot[15721]: time="2026-08-26T15:11:50+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 15:11:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 15:11:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 15:11:50 volumio sudo[15747]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-26 15:10' Aug 26 15:11:50 volumio sudo[15747]: 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"