-- Logs begin at Wed 2026-08-26 15:03:41 CEST, end at Wed 2026-08-26 17:04:21 CEST. -- Aug 26 17:03:00 11erkasten go-librespot[6122]: time="2026-08-26T17:03:00+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 17:03:00 11erkasten go-librespot[6122]: time="2026-08-26T17:03:00+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 17:03:00 11erkasten go-librespot[6122]: time="2026-08-26T17:03:00+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 17:03:00 11erkasten go-librespot[6122]: time="2026-08-26T17:03:00+02:00" level=info msg="zeroconf server listening on port 36099" Aug 26 17:03:00 11erkasten go-librespot[6122]: time="2026-08-26T17:03:01+02:00" level=info msg="using avahi-daemon avahi 0.7 for mDNS service registration" Aug 26 17:03:02 11erkasten volumio5-onboarding[1264]: time=2026-08-26T17:03:02.367+02:00 level=WARN msg="reconnection attempt failed" error="read tcp 127.0.0.1:45656->127.0.0.1:3000: i/o timeout" Aug 26 17:03:05 11erkasten go-librespot[6122]: time="2026-08-26T17:03:05+02:00" level=debug msg="obtained new client token: AAFXP1Jx2sZDuX0oLqd7OZTmMDUL7Ki/+8+M9CEjZqPZC3Z4o1sI+djEe6vebQztIZEDId41fIc5IMAcykjqgnJq0PoGU6cCJZHKZL9nwocd8chqJZXU+XKT54Jq2CL26T8z5ZQjlScB1nJ1QDpiFs75aoYr/1/R9gDLy2TS1QW7cwxqDjvEWSqID6Xq6uieorR7gEK0+C6SY288BJs2IRbtx1AYAkscYq+uz9QuQFMCws5s8nIa9ZCS" Aug 26 17:03:06 11erkasten go-librespot[6122]: time="2026-08-26T17:03:06+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 26 17:03:06 11erkasten volumio-remote-updater[3584]: [2026-08-26 17:03:05] [connect] Successful connection Aug 26 17:03:06 11erkasten go-librespot[6122]: time="2026-08-26T17:03:06+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 17:03:08 11erkasten go-librespot[6122]: time="2026-08-26T17:03:08+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 26 17:03:08 11erkasten go-librespot[6122]: time="2026-08-26T17:03:08+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 17:03:12 11erkasten go-librespot[6122]: time="2026-08-26T17:03:11+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 17:03:12 11erkasten go-librespot[6122]: time="2026-08-26T17:03:12+02:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 26 17:03:13 11erkasten go-librespot[6122]: time="2026-08-26T17:03:13+02:00" level=debug msg="completed keyexchange" Aug 26 17:03:13 11erkasten go-librespot[6122]: time="2026-08-26T17:03:13+02:00" level=debug msg="completed challenge" Aug 26 17:03:13 11erkasten go-librespot[6122]: time="2026-08-26T17:03:13+02:00" level=info msg="authenticated AP" username="31************************ta" Aug 26 17:03:17 11erkasten go-librespot[6122]: time="2026-08-26T17:03:17+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 17:03:18 11erkasten systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 17:03:18 11erkasten systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 17:03:18 11erkasten nmbd[780]: [2026/08/26 17:03:18.728236, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Aug 26 17:03:18 11erkasten nmbd[780]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.178.103 for name WORKGROUP<1d>. Aug 26 17:03:18 11erkasten nmbd[780]: This response was from IP 192.168.178.100, reporting an IP address of 192.168.178.100. Aug 26 17:03:18 11erkasten nmbd[780]: [2026/08/26 17:03:18.817474, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Aug 26 17:03:18 11erkasten nmbd[780]: query_name_response: Multiple (3) responses received for a query on subnet 192.168.178.103 for name WORKGROUP<1d>. Aug 26 17:03:18 11erkasten nmbd[780]: This response was from IP 192.168.178.84, reporting an IP address of 192.168.178.100. Aug 26 17:03:18 11erkasten nmbd[780]: [2026/08/26 17:03:18.817720, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Aug 26 17:03:18 11erkasten nmbd[780]: query_name_response: Multiple (4) responses received for a query on subnet 192.168.178.103 for name WORKGROUP<1d>. Aug 26 17:03:18 11erkasten nmbd[780]: This response was from IP 192.168.178.100, reporting an IP address of 192.168.178.100. Aug 26 17:03:18 11erkasten nmbd[780]: [2026/08/26 17:03:18.818002, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Aug 26 17:03:18 11erkasten nmbd[780]: query_name_response: Multiple (5) responses received for a query on subnet 192.168.178.103 for name WORKGROUP<1d>. Aug 26 17:03:18 11erkasten nmbd[780]: This response was from IP 192.168.178.100, reporting an IP address of 192.168.178.100. Aug 26 17:03:18 11erkasten nmbd[780]: [2026/08/26 17:03:18.818193, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Aug 26 17:03:18 11erkasten nmbd[780]: query_name_response: Multiple (6) responses received for a query on subnet 192.168.178.103 for name WORKGROUP<1d>. Aug 26 17:03:18 11erkasten nmbd[780]: This response was from IP 192.168.178.84, reporting an IP address of 192.168.178.100. Aug 26 17:03:20 11erkasten volumio5-onboarding[1264]: time=2026-08-26T17:03:19.883+02:00 level=WARN msg="reconnection attempt failed" error="read tcp 127.0.0.1:57556->127.0.0.1:3000: i/o timeout" Aug 26 17:03:22 11erkasten systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 26 17:03:22 11erkasten systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 190274. Aug 26 17:03:22 11erkasten volumio-remote-updater[3584]: [2026-08-26 17:03:22] [connect] Successful connection Aug 26 17:03:22 11erkasten systemd[1]: Stopped go-librespot Daemon. Aug 26 17:03:22 11erkasten systemd[1]: Started go-librespot Daemon. Aug 26 17:03:23 11erkasten go-librespot[6167]: go-librespot daemon starting... Aug 26 17:03:25 11erkasten go-librespot[6167]: time="2026-08-26T17:03:25+02:00" level=info msg="running go-librespot 0.7.1" Aug 26 17:03:31 11erkasten go-librespot[6167]: time="2026-08-26T17:03:25+02:00" level=debug msg="app state loaded" Aug 26 17:03:33 11erkasten go-librespot[6167]: time="2026-08-26T17:03:33+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 17:03:35 11erkasten volumio5-onboarding[1264]: time=2026-08-26T17:03:35.206+02:00 level=WARN msg="reconnection attempt failed" error="write tcp 127.0.0.1:35260->127.0.0.1:3000: i/o timeout" Aug 26 17:03:37 11erkasten go-librespot[6167]: time="2026-08-26T17:03:37+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 17:03:37 11erkasten go-librespot[6167]: time="2026-08-26T17:03:37+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 17:03:45 11erkasten go-librespot[6167]: time="2026-08-26T17:03:37+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 17:03:45 11erkasten go-librespot[6167]: time="2026-08-26T17:03:37+02:00" level=info msg="zeroconf server listening on port 33015" Aug 26 17:03:45 11erkasten go-librespot[6167]: time="2026-08-26T17:03:41+02:00" level=info msg="using avahi-daemon avahi 0.7 for mDNS service registration" Aug 26 17:03:45 11erkasten volumio-remote-updater[3584]: [2026-08-26 17:03:44] [connect] Successful connection Aug 26 17:03:49 11erkasten go-librespot[6167]: time="2026-08-26T17:03:49+02:00" level=debug msg="obtained new client token: AAGh/pAvl4gRKsmzqisP6GTb6KIw9C8bTBEnqDgYxI1N7gspoKDGmYLszIUffmRKqeT6RJfMiCK+IyHdlBvjFptUvnXiwNyxCCQggrwVROE0o1bnEfbMW3owMmOHItZsuwuOea2+6JQ7ncquDEE4vH/utqb75KGcIyzl9sH6/g2EN+c++L/uMioa2pkQph+at6LNCvK8O+SF54N0vsOpVTzPBuCevlZ5kfnuCMSngFbVHc4gVBh1lixB" Aug 26 17:03:50 11erkasten go-librespot[6167]: time="2026-08-26T17:03:50+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 17:03:51 11erkasten go-librespot[6167]: time="2026-08-26T17:03:51+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 26 17:03:52 11erkasten go-librespot[6167]: time="2026-08-26T17:03:52+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 17:03:56 11erkasten go-librespot[6167]: time="2026-08-26T17:03:56+02:00" level=debug msg="connected to ap-gew4.spotify.com:80" Aug 26 17:03:56 11erkasten go-librespot[6167]: time="2026-08-26T17:03:56+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 17:03:57 11erkasten go-librespot[6167]: time="2026-08-26T17:03:57+02:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 26 17:03:58 11erkasten go-librespot[6167]: time="2026-08-26T17:03:58+02:00" level=debug msg="completed keyexchange" Aug 26 17:03:59 11erkasten go-librespot[6167]: time="2026-08-26T17:03:58+02:00" level=debug msg="completed challenge" Aug 26 17:03:59 11erkasten go-librespot[6167]: time="2026-08-26T17:03:59+02:00" level=info msg="authenticated AP" username="31************************ta" Aug 26 17:04:00 11erkasten volumio5-onboarding[1264]: time=2026-08-26T17:03:59.724+02:00 level=WARN msg="reconnection attempt failed" error="read tcp 127.0.0.1:44880->127.0.0.1:3000: i/o timeout" Aug 26 17:04:00 11erkasten volumio-remote-updater[3584]: [2026-08-26 17:04:00] [connect] Successful connection Aug 26 17:04:02 11erkasten go-librespot[6167]: time="2026-08-26T17:04:02+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 17:04:07 11erkasten systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 17:04:07 11erkasten systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 17:04:10 11erkasten systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 26 17:04:10 11erkasten systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 190275. Aug 26 17:04:10 11erkasten systemd[1]: Stopped go-librespot Daemon. Aug 26 17:04:11 11erkasten systemd[1]: Started go-librespot Daemon. Aug 26 17:04:11 11erkasten go-librespot[6292]: go-librespot daemon starting... Aug 26 17:04:12 11erkasten sudo[6295]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-08-26 17:03 Aug 26 17:04:12 11erkasten sudo[6295]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 26 17:04:14 11erkasten go-librespot[6292]: time="2026-08-26T17:04:13+02:00" level=info msg="running go-librespot 0.7.1" Aug 26 17:04:14 11erkasten go-librespot[6292]: time="2026-08-26T17:04:13+02:00" level=debug msg="app state loaded" Aug 26 17:04:19 11erkasten volumio-remote-updater[3584]: [2026-08-26 17:04:19] [connect] Successful connection Aug 26 17:04:20 11erkasten go-librespot[6292]: time="2026-08-26T17:04:19+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 17:04:21 11erkasten volumio5-onboarding[1264]: time=2026-08-26T17:04:20.257+02:00 level=WARN msg="reconnection attempt failed" error="read tcp 127.0.0.1:41266->127.0.0.1:3000: i/o timeout" PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="e9612ec5034fb2e958508aaefbca2962fd6f6654" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="464fc672d77d3df6ee72b331d36cdf1fa936e1ec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 27 Feb 2026 10:59:40 AM CET" VOLUMIO_VERSION="3.912" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="37c6ab864cb114e1344d540995c69f86"