Oct 11 12:01:10 parus go-librespot[8298]: time="2026-10-11T12:01:10+02:00" level=debug msg="fetched chunk 14/26, size: 524288" uri="spotify:track:72kmSs7G3aPNnLa86qfxrm" Oct 11 12:01:23 parus go-librespot[8298]: time="2026-10-11T12:01:23+02:00" level=debug msg="fetched chunk 15/26, size: 524288" uri="spotify:track:72kmSs7G3aPNnLa86qfxrm" Oct 11 12:01:36 parus go-librespot[8298]: time="2026-10-11T12:01:36+02:00" level=debug msg="fetched chunk 16/26, size: 524288" uri="spotify:track:72kmSs7G3aPNnLa86qfxrm" Oct 11 12:01:49 parus go-librespot[8298]: time="2026-10-11T12:01:49+02:00" level=debug msg="fetched chunk 17/26, size: 524288" uri="spotify:track:72kmSs7G3aPNnLa86qfxrm" Oct 11 12:02:02 parus go-librespot[8298]: time="2026-10-11T12:02:02+02:00" level=debug msg="fetched chunk 18/26, size: 524288" uri="spotify:track:72kmSs7G3aPNnLa86qfxrm" Oct 11 12:02:07 parus go-librespot[8298]: time="2026-10-11T12:02:07+02:00" level=error msg="did not receive last pong ack from accesspoint, 120s passed" Oct 11 12:02:07 parus go-librespot[8298]: time="2026-10-11T12:02:07+02:00" level=error msg="failed receiving packet" error="failed reading packet header: read tcp 192.168.178.69:53658->34.158.1.133:4070: use of closed network connection" Oct 11 12:02:07 parus go-librespot[8298]: time="2026-10-11T12:02:07+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Oct 11 12:02:07 parus go-librespot[8298]: time="2026-10-11T12:02:07+02:00" level=debug msg="completed keyexchange" Oct 11 12:02:07 parus go-librespot[8298]: time="2026-10-11T12:02:07+02:00" level=debug msg="completed challenge" Oct 11 12:02:07 parus go-librespot[8298]: time="2026-10-11T12:02:07+02:00" level=info msg="authenticated AP" username="11******78" Oct 11 12:02:07 parus go-librespot[8298]: time="2026-10-11T12:02:07+02:00" level=debug msg="re-established accesspoint connection" Oct 11 12:02:07 parus go-librespot[8298]: time="2026-10-11T12:02:07+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Oct 11 12:02:07 parus go-librespot[8298]: time="2026-10-11T12:02:07+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Oct 11 12:02:07 parus go-librespot[8298]: time="2026-10-11T12:02:07+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Oct 11 12:02:07 parus go-librespot[8298]: time="2026-10-11T12:02:07+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Oct 11 12:02:08 parus go-librespot[8298]: time="2026-10-11T12:02:08+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Oct 11 12:02:15 parus go-librespot[8298]: time="2026-10-11T12:02:15+02:00" level=debug msg="fetched chunk 19/26, size: 524288" uri="spotify:track:72kmSs7G3aPNnLa86qfxrm" Oct 11 12:02:15 parus volumio[8126]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Oct 11 12:02:15 parus volumio[8126]: info: In handleBrowseUri, curUri=spotify Oct 11 12:02:16 parus volumio[8126]: info: Preload queue cleared Oct 11 12:02:16 parus volumio[8126]: info: Preload queue cleared Oct 11 12:02:16 parus volumio[8126]: info: Preload queue cleared Oct 11 12:02:16 parus volumio[8126]: info: Preload queue cleared Oct 11 12:02:20 parus volumio[8126]: Searching plugin music_service/spop Oct 11 12:02:20 parus volumio[8126]: info: CoreCommandRouter::executeOnPlugin: spop , search Oct 11 12:02:22 parus volumio[8126]: info: All search sources collected, pushing search results Oct 11 12:02:27 parus volumio[8126]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Oct 11 12:02:27 parus volumio[8126]: info: In handleBrowseUri, curUri=spotify:artist:0El0JIQ4awidp165j3gvej Oct 11 12:02:28 parus go-librespot[8298]: time="2026-10-11T12:02:28+02:00" level=debug msg="fetched chunk 20/26, size: 524288" uri="spotify:track:72kmSs7G3aPNnLa86qfxrm" Oct 11 12:02:30 parus volumio[8126]: info: Preload queue cleared Oct 11 12:02:30 parus volumio[8126]: info: Preloading song: spotify:track:5Bk65iVbipaaQwOTi0pVpT Oct 11 12:02:30 parus volumio[8126]: info: Preloading song: spotify:track:2BAs1tRhIVhoeMk3zGDOYe Oct 11 12:02:30 parus volumio[8126]: info: Preloading song: spotify:track:7tsg2QDJKNmEt6pL5pQuUm Oct 11 12:02:30 parus volumio[8126]: info: Preloading song: spotify:track:49Q4zf1YuVJzyhR1EXjOaZ Oct 11 12:02:30 parus volumio[8126]: info: Preloading song: spotify:track:370hWbLc0GRWXfUf7ekqRl Oct 11 12:02:30 parus volumio[8126]: info: Preloading song: spotify:track:6NvxSUr39EAf08pfyZKWE8 Oct 11 12:02:30 parus volumio[8126]: info: Preloading song: spotify:track:3SYcKdznbdr1d6AqT3bwOr Oct 11 12:02:30 parus volumio[8126]: info: Preloading song: spotify:track:70lVGUWeDxNOEcsWGJ4ueI Oct 11 12:02:30 parus volumio[8126]: info: Preloading song: spotify:track:6DTv0vIJGmbwZlHEGYpo7x Oct 11 12:02:30 parus volumio[8126]: info: Preloading song: spotify:track:4j5eKOK7XFkgDbmSZaXAYR Oct 11 12:02:30 parus volumio[8126]: info: Preload queue cleared Oct 11 12:02:30 parus volumio[8126]: info: Preload queue cleared Oct 11 12:02:32 parus volumio[8126]: info: No valid Plugin REST Endpoint Oct 11 12:02:32 parus volumio[8126]: info: No valid Plugin REST Endpoint Oct 11 12:02:40 parus go-librespot[8298]: time="2026-10-11T12:02:40+02:00" level=debug msg="fetched chunk 21/26, size: 524288" uri="spotify:track:72kmSs7G3aPNnLa86qfxrm" Oct 11 12:02:41 parus volumio[8126]: Searching plugin music_service/spop Oct 11 12:02:41 parus volumio[8126]: info: CoreCommandRouter::executeOnPlugin: spop , search Oct 11 12:02:42 parus volumio[8126]: info: All search sources collected, pushing search results Oct 11 12:02:45 parus volumio[8126]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Oct 11 12:02:45 parus volumio[8126]: info: In handleBrowseUri, curUri=spotify:artist:1BBs6I5zGXAtmvcAw6fXLA Oct 11 12:02:46 parus volumio[8126]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 11 12:02:46 parus volumio[8126]: TypeError: Cannot read properties of undefined (reading 'url') Oct 11 12:02:46 parus volumio[8126]: at /data/plugins/music_service/spop/index.js:3360:60 Oct 11 12:02:46 parus volumio[8126]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Oct 11 12:02:46 parus volumio[8126]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 11 12:02:47 parus sudo[9302]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-11 12:01' Oct 11 12:02:47 parus sudo[9302]: 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"