-- Logs begin at Wed 2025-07-16 01:24:02 AWST, end at Thu 2025-07-17 17:41:29 AWST. -- Jul 17 17:40:02 volumio volumio[814]: info: Initializing connection to go-librespot Websocket Jul 17 17:40:02 volumio go-librespot[15393]: time="2025-07-17T17:40:02+08:00" level=debug msg="new websocket client" Jul 17 17:40:02 volumio volumio[814]: info: Connection to go-librespot Websocket established Jul 17 17:40:05 volumio volumio[814]: info: Getting Spotify volume Jul 17 17:40:05 volumio volumio[814]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Jul 17 17:40:05 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Jul 17 17:40:05 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 17 17:40:05 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Jul 17 17:40:19 volumio go-librespot[15393]: time="2025-07-17T17:40:19+08:00" level=debug msg="obtained new client token: AABLwCL9xjuC4JN8cW58nnrHI1Qs7/7i+rT5/24eCANTG2kv0ctCT2K8gjwA+gDqpuOT/edBDzQsFmip5xMqQfpH3Lmepivd+BJqUCAJu5TVpxapQP03zO4nsXIhlfbenS314zN/aNQNFtEj/ZvDbL+cwN/ra3ph7D4QaD/6JFMKgUkXXv/WdP+p0ey3gkpSMfUk/eTDoOO/t8SuM/upS2aYHn/09YMqs2DUF9CW8cU0/N199Gx9C4saYw==" Jul 17 17:40:19 volumio go-librespot[15393]: time="2025-07-17T17:40:19+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 17 17:40:20 volumio go-librespot[15393]: time="2025-07-17T17:40:20+08:00" level=debug msg="completed keyexchange" Jul 17 17:40:20 volumio go-librespot[15393]: time="2025-07-17T17:40:20+08:00" level=debug msg="completed challenge" Jul 17 17:40:20 volumio go-librespot[15393]: time="2025-07-17T17:40:20+08:00" level=debug msg="authenticated as clark_tv" Jul 17 17:40:21 volumio go-librespot[15393]: time="2025-07-17T17:40:21+08:00" level=debug msg="authenticated as clark_tv" Jul 17 17:40:21 volumio go-librespot[15393]: time="2025-07-17T17:40:21+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jul 17 17:40:21 volumio go-librespot[15393]: time="2025-07-17T17:40:21+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jul 17 17:40:21 volumio go-librespot[15393]: time="2025-07-17T17:40:21+08:00" level=debug msg="dealer connection opened" Jul 17 17:40:21 volumio go-librespot[15393]: time="2025-07-17T17:40:21+08:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jul 17 17:40:21 volumio go-librespot[15393]: time="2025-07-17T17:40:21+08:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jul 17 17:40:21 volumio go-librespot[15393]: time="2025-07-17T17:40:21+08:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jul 17 17:40:21 volumio go-librespot[15393]: time="2025-07-17T17:40:21+08:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jul 17 17:40:21 volumio go-librespot[15393]: time="2025-07-17T17:40:21+08:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jul 17 17:40:21 volumio volumio[814]: info: Spotify volume: 100 Jul 17 17:40:21 volumio go-librespot[15393]: time="2025-07-17T17:40:21+08:00" level=debug msg="received connection id: M2I3NDY3NzYtMzc0My00OTc2LThhNGYtYTAyODVhZDY1ODFiK2RlYWxlcit0Y3A6Ly8wYWIxNTgwNi5pcC5nYWUyLnNwb3RpZnkubmV0OjU3MDArMzQ3RjBBN0E5QTk0MzlEMDUyMDM1QzUzNzNDMjUyQUI0MzUxQzVDMzEyODEwMUI3RUMwRjdFMDU3QUFGQTNEOA==" Jul 17 17:40:22 volumio go-librespot[15393]: time="2025-07-17T17:40:22+08:00" level=debug msg="put connect state because NEW_DEVICE" Jul 17 17:41:10 volumio ntpd[612]: 220.158.215.20 local addr 192.168.1.169 -> Jul 17 17:41:21 volumio go-librespot[15393]: time="2025-07-17T17:41:21+08:00" level=error msg="did not receive last pong from dealer, 30s passed" Jul 17 17:41:26 volumio go-librespot[15393]: time="2025-07-17T17:41:26+08:00" level=error msg="failed receiving dealer message" error="failed to get reader: WebSocket closed: sent close frame: status = StatusServiceRestart and reason = \"\"" Jul 17 17:41:29 volumio volumio[814]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 17 17:41:29 volumio volumio[814]: [t [Error]: A network error (such as timeout, interrupted connection or unreachable host) has occurred.] { Jul 17 17:41:29 volumio volumio[814]: code: 'auth/network-request-failed', Jul 17 17:41:29 volumio volumio[814]: a: null Jul 17 17:41:29 volumio volumio[814]: } Jul 17 17:41:29 volumio volumio[814]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 17 17:41:29 volumio sudo[15458]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-07-17 17:40 Jul 17 17:41:29 volumio sudo[15458]: pam_unix(sudo:session): session opened for user root by (uid=0) 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="f8baf7ad070f376535a93fcc6590774528ddb153" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="0e3cf2fcfe1906c5090fab62b4cc2a5ff0069fd8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 30 Jan 2024 03:58:37 PM CET" VOLUMIO_VERSION="3.611" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="1d6379ebb89c40061afa8aee78176887"