-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Wed 2026-02-18 12:51:30 CET. -- Feb 18 12:51:29 volumio systemd-timedated[1451]: Changed local time to Wed Feb 18 12:51:29 2026 Feb 18 12:51:29 volumio systemd[1]: Starting Daily apt download activities... Feb 18 12:51:29 volumio sudo[1449]: pam_unix(sudo:session): session closed for user root Feb 18 12:51:29 volumio volumio-time-update[725]: volumio-time-update-util: System time updated successfully. Feb 18 12:51:29 volumio go-librespot[1369]: time="2026-02-18T12:51:29+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" Feb 18 12:51:29 volumio systemd[1]: Started Volumio Time Update Utility. Feb 18 12:51:29 volumio systemd[1]: Reached target Multi-User System. Feb 18 12:51:29 volumio systemd[1]: Reached target Graphical Interface. Feb 18 12:51:29 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... Feb 18 12:51:29 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Feb 18 12:51:29 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. Feb 18 12:51:29 volumio go-librespot[1369]: time="2026-02-18T12:51:29+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Feb 18 12:51:29 volumio go-librespot[1369]: time="2026-02-18T12:51:29+01:00" level=debug msg="completed keyexchange" Feb 18 12:51:29 volumio go-librespot[1369]: time="2026-02-18T12:51:29+01:00" level=debug msg="completed challenge" Feb 18 12:51:29 volumio go-librespot[1369]: time="2026-02-18T12:51:29+01:00" level=info msg="authenticated AP" username="mi************ed" Feb 18 12:51:29 volumio go-librespot[1369]: time="2026-02-18T12:51:29+01:00" level=info msg="authenticated Login5" username="mi************ed" Feb 18 12:51:29 volumio go-librespot[1369]: time="2026-02-18T12:51:29+01:00" level=info msg="accepted zeroconf from iPhone" username="mi************ed" Feb 18 12:51:29 volumio systemd[1]: apt-daily.service: Succeeded. Feb 18 12:51:29 volumio systemd[1]: Started Daily apt download activities. Feb 18 12:51:29 volumio systemd[1]: Starting Daily apt upgrade and clean activities... Feb 18 12:51:29 volumio go-librespot[1369]: time="2026-02-18T12:51:29+01:00" level=debug msg="dealer connection opened" Feb 18 12:51:29 volumio go-librespot[1369]: time="2026-02-18T12:51:29+01:00" level=trace msg="starting accesspoint recv loop" Feb 18 12:51:29 volumio go-librespot[1369]: time="2026-02-18T12:51:29+01:00" level=trace msg="starting dealer recv loop" Feb 18 12:51:29 volumio go-librespot[1369]: time="2026-02-18T12:51:29+01:00" level=trace msg="received accesspoint ping" Feb 18 12:51:29 volumio go-librespot[1369]: time="2026-02-18T12:51:29+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Feb 18 12:51:29 volumio go-librespot[1369]: time="2026-02-18T12:51:29+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Feb 18 12:51:29 volumio go-librespot[1369]: time="2026-02-18T12:51:29+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Feb 18 12:51:29 volumio go-librespot[1369]: time="2026-02-18T12:51:29+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Feb 18 12:51:29 volumio go-librespot[1369]: time="2026-02-18T12:51:29+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Feb 18 12:51:29 volumio go-librespot[1369]: time="2026-02-18T12:51:29+01:00" level=debug msg="received connection id: ODQzNDgzOWQtODc4...RjJBREM4OTc4Nw==" Feb 18 12:51:29 volumio volumio[1432]: ..............................................++++ Feb 18 12:51:29 volumio go-librespot[1369]: time="2026-02-18T12:51:29+01:00" level=debug msg="put connect state because NEW_DEVICE" Feb 18 12:51:29 volumio go-librespot[1369]: time="2026-02-18T12:51:29+01:00" level=debug msg="update volume requested to 65535/65535" Feb 18 12:51:29 volumio go-librespot[1369]: time="2026-02-18T12:51:29+01:00" level=trace msg="received accesspoint pong ack" Feb 18 12:51:29 volumio systemd[1]: apt-daily-upgrade.service: Succeeded. Feb 18 12:51:29 volumio systemd[1]: Started Daily apt upgrade and clean activities. Feb 18 12:51:29 volumio systemd[1]: Startup finished in 11.780s (kernel) + 23.093s (userspace) = 34.873s. Feb 18 12:51:29 volumio go-librespot[1369]: time="2026-02-18T12:51:29+01:00" level=debug msg="handling transfer player command from cefe538e242e5b4d04b27899e771424f6b3e7cf2" Feb 18 12:51:29 volumio go-librespot[1369]: time="2026-02-18T12:51:29+01:00" level=debug msg="resolved context of track" uri="spotify:user:miranda.remnehed:collection" Feb 18 12:51:29 volumio go-librespot[1369]: time="2026-02-18T12:51:29+01:00" level=trace msg="fetched new page 0 with 1526 items (list: 1526)" uri="spotify:user:miranda.remnehed:collection" Feb 18 12:51:29 volumio go-librespot[1369]: time="2026-02-18T12:51:29+01:00" level=debug msg="loading track (paused: true, position: 138300ms)" uri="spotify:track:0kuArT0Tg3xbMQ3dtwnxGK" Feb 18 12:51:29 volumio go-librespot[1369]: time="2026-02-18T12:51:29+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 18 12:51:29 volumio go-librespot[1369]: time="2026-02-18T12:51:29+01:00" level=trace msg="emitting websocket event: will_play" Feb 18 12:51:29 volumio go-librespot[1369]: time="2026-02-18T12:51:29+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 411" Feb 18 12:51:29 volumio go-librespot[1369]: time="2026-02-18T12:51:29+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1692" Feb 18 12:51:29 volumio go-librespot[1369]: time="2026-02-18T12:51:29+01:00" level=debug msg="selected format OGG_VORBIS_320 (b28fc18e9c0e4afd2c0b9efbb10113ccfa006104)" uri="spotify:track:0kuArT0Tg3xbMQ3dtwnxGK" Feb 18 12:51:29 volumio go-librespot[1369]: time="2026-02-18T12:51:29+01:00" level=debug msg="requested aes key for file b28fc18e9c0e4afd2c0b9efbb10113ccfa006104, gid: 0kuArT0Tg3xbMQ3dtwnxGK" Feb 18 12:51:29 volumio go-librespot[1369]: time="2026-02-18T12:51:29+01:00" level=trace msg="found 2 cdn urls" uri="spotify:track:0kuArT0Tg3xbMQ3dtwnxGK" Feb 18 12:51:30 volumio go-librespot[1369]: time="2026-02-18T12:51:30+01:00" level=debug msg="fetched first chunk of 26, total size is 13128632 bytes" uri="spotify:track:0kuArT0Tg3xbMQ3dtwnxGK" Feb 18 12:51:30 volumio go-librespot[1369]: time="2026-02-18T12:51:30+01:00" level=debug msg="fetched chunk 3/25, size: 524288" uri="spotify:track:0kuArT0Tg3xbMQ3dtwnxGK" Feb 18 12:51:30 volumio go-librespot[1369]: time="2026-02-18T12:51:30+01:00" level=debug msg="fetched chunk 1/25, size: 524288" uri="spotify:track:0kuArT0Tg3xbMQ3dtwnxGK" Feb 18 12:51:30 volumio go-librespot[1369]: time="2026-02-18T12:51:30+01:00" level=debug msg="fetched chunk 2/25, size: 524288" uri="spotify:track:0kuArT0Tg3xbMQ3dtwnxGK" Feb 18 12:51:30 volumio go-librespot[1369]: time="2026-02-18T12:51:30+01:00" level=debug msg="fetched chunk 9/25, size: 524288" uri="spotify:track:0kuArT0Tg3xbMQ3dtwnxGK" Feb 18 12:51:30 volumio go-librespot[1369]: time="2026-02-18T12:51:30+01:00" level=trace msg="seek to 138300ms (diff: 245ms, samples: 6099030, bytes: 5152785)" uri="spotify:track:0kuArT0Tg3xbMQ3dtwnxGK" Feb 18 12:51:30 volumio go-librespot[1369]: time="2026-02-18T12:51:30+01:00" level=debug msg="created new output device" Feb 18 12:51:30 volumio go-librespot[1369]: time="2026-02-18T12:51:30+01:00" level=info msg="loaded track \"Bridge to Cross\" (paused: true, position: 138300ms, duration: 349413ms, prefetched: false)" uri="spotify:track:0kuArT0Tg3xbMQ3dtwnxGK" Feb 18 12:51:30 volumio go-librespot[1369]: time="2026-02-18T12:51:30+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1290" Feb 18 12:51:30 volumio go-librespot[1369]: time="2026-02-18T12:51:30+01:00" level=debug msg="fetched chunk 12/25, size: 524288" uri="spotify:track:0kuArT0Tg3xbMQ3dtwnxGK" Feb 18 12:51:30 volumio go-librespot[1369]: time="2026-02-18T12:51:30+01:00" level=debug msg="fetched chunk 10/25, size: 524288" uri="spotify:track:0kuArT0Tg3xbMQ3dtwnxGK" Feb 18 12:51:30 volumio go-librespot[1369]: time="2026-02-18T12:51:30+01:00" level=debug msg="fetched chunk 11/25, size: 524288" uri="spotify:track:0kuArT0Tg3xbMQ3dtwnxGK" Feb 18 12:51:30 volumio go-librespot[1369]: time="2026-02-18T12:51:30+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 18 12:51:30 volumio go-librespot[1369]: time="2026-02-18T12:51:30+01:00" level=trace msg="emitting websocket event: metadata" Feb 18 12:51:30 volumio go-librespot[1369]: time="2026-02-18T12:51:30+01:00" level=trace msg="emitting websocket event: active" Feb 18 12:51:30 volumio go-librespot[1369]: time="2026-02-18T12:51:30+01:00" level=debug msg="sending successful reply for dealer request" Feb 18 12:51:30 volumio go-librespot[1369]: time="2026-02-18T12:51:30+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Feb 18 12:51:30 volumio go-librespot[1369]: time="2026-02-18T12:51:30+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Feb 18 12:51:30 volumio go-librespot[1369]: time="2026-02-18T12:51:30+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Feb 18 12:51:30 volumio go-librespot[1369]: time="2026-02-18T12:51:30+01:00" level=trace msg="emitting websocket event: volume" Feb 18 12:51:30 volumio go-librespot[1369]: time="2026-02-18T12:51:30+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 18 12:51:30 volumio go-librespot[1369]: time="2026-02-18T12:51:30+01:00" level=trace msg="emitting websocket event: paused" 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="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 05 Feb 2026 01:46:18 PM CET" VOLUMIO_VERSION="3.908" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="3e9dbaf8f44792d26e97456a18f12823"