-- Logs begin at Tue 2025-12-16 12:36:00 CET, end at Tue 2025-12-16 15:38:52 CET. -- Dec 16 15:37:06 jukebox volumio[1080]: info: CoreCommandRouter::volumioGetState Dec 16 15:37:06 jukebox volumio[1080]: info: Listing playlists Dec 16 15:37:06 jukebox volumio[1080]: info: Listing playlists Dec 16 15:37:16 jukebox volumio[1080]: info: CoreCommandRouter::volumioGetState Dec 16 15:37:17 jukebox go-librespot[1873]: time="2025-12-16T15:37:17+01:00" level=error msg="did not receive last pong from dealer, 60s passed" Dec 16 15:37:22 jukebox go-librespot[1873]: time="2025-12-16T15:37:22+01:00" level=error msg="failed receiving dealer message" error="failed to get reader: WebSocket closed: sent close frame: status = StatusServiceRestart and reason = \"\"" Dec 16 15:37:26 jukebox volumio[1080]: info: CoreCommandRouter::volumioGetState Dec 16 15:37:26 jukebox volumio[1080]: info: Listing playlists Dec 16 15:37:26 jukebox volumio[1080]: info: Listing playlists Dec 16 15:37:36 jukebox volumio[1080]: info: CoreCommandRouter::volumioGetState Dec 16 15:37:46 jukebox volumio[1080]: info: CoreCommandRouter::volumioGetState Dec 16 15:37:46 jukebox volumio[1080]: info: Listing playlists Dec 16 15:37:46 jukebox volumio[1080]: info: Listing playlists Dec 16 15:37:47 jukebox go-librespot[1873]: time="2025-12-16T15:37:47+01:00" level=error msg="did not receive last pong from dealer, 90s passed" Dec 16 15:37:47 jukebox go-librespot[1873]: time="2025-12-16T15:37:47+01:00" level=error msg="did not receive last pong ack from accesspoint, 121s passed" Dec 16 15:37:47 jukebox go-librespot[1873]: time="2025-12-16T15:37:47+01:00" level=error msg="failed receiving packet" error="failed reading packet header: read tcp 192.168.23.50:48010->104.199.65.9:443: use of closed network connection" Dec 16 15:37:56 jukebox volumio[1080]: info: CoreCommandRouter::volumioGetState Dec 16 15:38:06 jukebox volumio[1080]: info: CoreCommandRouter::volumioGetState Dec 16 15:38:06 jukebox volumio[1080]: info: Listing playlists Dec 16 15:38:13 jukebox go-librespot[1873]: time="2025-12-16T15:38:13+01:00" level=warning msg="failed fetching new endpoint for dealer" error="failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=dealer\": context deadline exceeded (Client.Timeout exceeded while awaiting headers)" Dec 16 15:38:16 jukebox volumio[1080]: info: CoreCommandRouter::volumioGetState Dec 16 15:38:17 jukebox go-librespot[1873]: time="2025-12-16T15:38:17+01:00" level=error msg="did not receive last pong from dealer, 120s passed" Dec 16 15:38:17 jukebox go-librespot[1873]: time="2025-12-16T15:38:17+01:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:80, retrying with a different AP" error="dial tcp: lookup ap-gae2.spotify.com: i/o timeout" Dec 16 15:38:25 jukebox volumiossh-tunnel[2712]: Timeout, server eu4.myvolumio.org not responding. Dec 16 15:38:25 jukebox autossh[2714]: ssh exited with error status 255; restarting ssh Dec 16 15:38:25 jukebox autossh[2714]: starting ssh (count 2) Dec 16 15:38:25 jukebox autossh[2714]: ssh child pid is 4599 Dec 16 15:38:26 jukebox volumio[1080]: info: CoreCommandRouter::volumioGetState Dec 16 15:38:26 jukebox volumio[1080]: info: Listing playlists Dec 16 15:38:26 jukebox volumio[1080]: info: Listing playlists Dec 16 15:38:36 jukebox volumio[1080]: info: CoreCommandRouter::volumioGetState Dec 16 15:38:46 jukebox volumio[1080]: info: CoreCommandRouter::volumioGetState Dec 16 15:38:46 jukebox volumio[1080]: info: Listing playlists Dec 16 15:38:46 jukebox volumio[1080]: info: Listing playlists Dec 16 15:38:47 jukebox go-librespot[1873]: time="2025-12-16T15:38:47+01:00" level=error msg="did not receive last pong from dealer, 150s passed" Dec 16 15:38:47 jukebox go-librespot[1873]: time="2025-12-16T15:38:47+01:00" level=warning msg="failed fetching new endpoint for accesspoint" error="failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint\": context deadline exceeded" Dec 16 15:38:47 jukebox go-librespot[1873]: time="2025-12-16T15:38:47+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp: lookup ap-gew4.spotify.com: i/o timeout" Dec 16 15:38:50 jukebox go-librespot[1873]: time="2025-12-16T15:38:50+01:00" level=warning msg="failed fetching new endpoint for dealer" error="failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=dealer\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Dec 16 15:38:50 jukebox go-librespot[1873]: time="2025-12-16T15:38:50+01:00" level=warning msg="failed fetching new endpoint for accesspoint" error="failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Dec 16 15:38:50 jukebox go-librespot[1873]: time="2025-12-16T15:38:50+01: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" Dec 16 15:38:50 jukebox go-librespot[1873]: time="2025-12-16T15:38:50+01:00" level=debug msg="dealer connection opened" Dec 16 15:38:50 jukebox go-librespot[1873]: time="2025-12-16T15:38:50+01:00" level=debug msg="re-established dealer connection" Dec 16 15:38:50 jukebox go-librespot[1873]: time="2025-12-16T15:38:50+01:00" level=debug msg="received connection id: OWMzZGU1MDMtODQy...QUJFQTQxRDM2OQ==" Dec 16 15:38:50 jukebox go-librespot[1873]: time="2025-12-16T15:38:50+01: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]" Dec 16 15:38:50 jukebox go-librespot[1873]: time="2025-12-16T15:38:50+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 16 15:38:50 jukebox go-librespot[1873]: time="2025-12-16T15:38:50+01:00" level=debug msg="completed keyexchange" Dec 16 15:38:50 jukebox go-librespot[1873]: time="2025-12-16T15:38:50+01:00" level=debug msg="completed challenge" Dec 16 15:38:50 jukebox go-librespot[1873]: time="2025-12-16T15:38:50+01:00" level=info msg="authenticated AP" username="0c*********************x0" Dec 16 15:38:50 jukebox go-librespot[1873]: time="2025-12-16T15:38:50+01:00" level=debug msg="re-established accesspoint connection" Dec 16 15:38:50 jukebox go-librespot[1873]: time="2025-12-16T15:38:50+01:00" level=trace msg="received accesspoint ping" Dec 16 15:38:50 jukebox go-librespot[1873]: time="2025-12-16T15:38:50+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Dec 16 15:38:50 jukebox go-librespot[1873]: time="2025-12-16T15:38:50+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Dec 16 15:38:50 jukebox go-librespot[1873]: time="2025-12-16T15:38:50+01:00" level=debug msg="put connect state because NEW_DEVICE" Dec 16 15:38:50 jukebox go-librespot[1873]: time="2025-12-16T15:38:50+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Dec 16 15:38:50 jukebox go-librespot[1873]: time="2025-12-16T15:38:50+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Dec 16 15:38:50 jukebox go-librespot[1873]: time="2025-12-16T15:38:50+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Dec 16 15:38:50 jukebox go-librespot[1873]: time="2025-12-16T15:38:50+01:00" level=trace msg="received accesspoint pong ack" Dec 16 15:38:52 jukebox volumio[1080]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 16 15:38:52 jukebox volumio[1080]: RangeError: Maximum call stack size exceeded Dec 16 15:38:52 jukebox volumio[1080]: at MqttClient._shiftPingInterval (/volumio/node_modules/mqtt/lib/client.js:1014:52) Dec 16 15:38:52 jukebox volumio[1080]: at MqttClient._sendPacket (/volumio/node_modules/mqtt/lib/client.js:936:8) Dec 16 15:38:52 jukebox volumio[1080]: at deliver (/volumio/node_modules/mqtt/lib/client.js:217:12) Dec 16 15:38:52 jukebox volumio[1080]: at /volumio/node_modules/mqtt/lib/client.js:223:11 Dec 16 15:38:52 jukebox volumio[1080]: at sendPacket (/volumio/node_modules/mqtt/lib/client.js:86:5) Dec 16 15:38:52 jukebox volumio[1080]: at MqttClient._sendPacket (/volumio/node_modules/mqtt/lib/client.js:945:7) Dec 16 15:38:52 jukebox volumio[1080]: at deliver (/volumio/node_modules/mqtt/lib/client.js:217:12) Dec 16 15:38:52 jukebox volumio[1080]: at /volumio/node_modules/mqtt/lib/client.js:223:11 Dec 16 15:38:52 jukebox volumio[1080]: at sendPacket (/volumio/node_modules/mqtt/lib/client.js:86:5) Dec 16 15:38:52 jukebox volumio[1080]: at MqttClient._sendPacket (/volumio/node_modules/mqtt/lib/client.js:945:7) Dec 16 15:38:52 jukebox volumio[1080]: at deliver (/volumio/node_modules/mqtt/lib/client.js:217:12) Dec 16 15:38:52 jukebox volumio[1080]: at /volumio/node_modules/mqtt/lib/client.js:223:11 Dec 16 15:38:52 jukebox volumio[1080]: at sendPacket (/volumio/node_modules/mqtt/lib/client.js:86:5) Dec 16 15:38:52 jukebox volumio[1080]: at MqttClient._sendPacket (/volumio/node_modules/mqtt/lib/client.js:945:7) Dec 16 15:38:52 jukebox volumio[1080]: at deliver (/volumio/node_modules/mqtt/lib/client.js:217:12) Dec 16 15:38:52 jukebox volumio[1080]: at /volumio/node_modules/mqtt/lib/client.js:223:11 Dec 16 15:38:52 jukebox volumio[1080]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 16 15:38:52 jukebox sudo[4744]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-16 15:37 Dec 16 15:38:52 jukebox sudo[4744]: 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="a01a833dd28483f88cb390596f5090b7187992af" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 27 Feb 2025 11:42:54 AM CET" VOLUMIO_VERSION="3.795" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="4049a67f1c09d4a94e033ba35a80a144"