-- Logs begin at Sat 2025-02-22 19:22:50 UTC, end at Fri 2025-02-28 20:52:22 UTC. -- Feb 28 20:52:18 volumiosalon systemd-timedated[2301]: Changed local time to Fri Feb 28 20:52:18 2025 Feb 28 20:52:18 volumiosalon sudo[2299]: pam_unix(sudo:session): session closed for user root Feb 28 20:52:18 volumiosalon volumio-time-update[597]: volumio-time-update-util: System time updated successfully. Feb 28 20:52:18 volumiosalon go-librespot[2286]: time="2025-02-28T20:52:18Z" level=debug msg="handling transfer player command from 145f65f3a60a9545ab03e1cf3a641dcb773342c4" Feb 28 20:52:18 volumiosalon go-librespot[2286]: time="2025-02-28T20:52:18Z" level=debug msg="resolved context of track" uri="spotify:playlist:37i9dQZEVXbcbd59CH85FD" Feb 28 20:52:18 volumiosalon go-librespot[2286]: time="2025-02-28T20:52:18Z" level=trace msg="fetched new page 0 with 30 items (list: 30)" uri="spotify:playlist:37i9dQZEVXbcbd59CH85FD" Feb 28 20:52:18 volumiosalon go-librespot[2286]: time="2025-02-28T20:52:18Z" level=debug msg="loading track (paused: false, position: 83291ms)" uri="spotify:track:40PrHg3A1SAERuMVfOMqI2" Feb 28 20:52:18 volumiosalon go-librespot[2286]: time="2025-02-28T20:52:18Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 28 20:52:18 volumiosalon go-librespot[2286]: time="2025-02-28T20:52:18Z" level=trace msg="emitting websocket event: will_play" Feb 28 20:52:18 volumiosalon systemd[1]: Started Volumio Time Update Utility. Feb 28 20:52:18 volumiosalon systemd[1]: Reached target Multi-User System. Feb 28 20:52:18 volumiosalon systemd[1]: Reached target Graphical Interface. Feb 28 20:52:18 volumiosalon go-librespot[2286]: time="2025-02-28T20:52:18Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" Feb 28 20:52:18 volumiosalon go-librespot[2286]: time="2025-02-28T20:52:18Z" level=debug msg="selected format OGG_VORBIS_320 (b5a8f48780fb2f614e1f9832a15c5cc8fc9e37d8)" uri="spotify:track:40PrHg3A1SAERuMVfOMqI2" Feb 28 20:52:18 volumiosalon go-librespot[2286]: time="2025-02-28T20:52:18Z" level=debug msg="requested aes key for file b5a8f48780fb2f614e1f9832a15c5cc8fc9e37d8, gid: 40PrHg3A1SAERuMVfOMqI2" Feb 28 20:52:18 volumiosalon systemd[1]: Starting Update UTMP about System Runlevel Changes... Feb 28 20:52:18 volumiosalon systemd[1]: Starting Daily apt download activities... Feb 28 20:52:18 volumiosalon go-librespot[2286]: time="2025-02-28T20:52:18Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1373" Feb 28 20:52:18 volumiosalon systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Feb 28 20:52:18 volumiosalon systemd[1]: Started Update UTMP about System Runlevel Changes. Feb 28 20:52:18 volumiosalon go-librespot[2286]: time="2025-02-28T20:52:18Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1133" Feb 28 20:52:18 volumiosalon go-librespot[2286]: time="2025-02-28T20:52:18Z" level=debug msg="fetched first chunk of 18, total size is 9270254 bytes" uri="spotify:track:40PrHg3A1SAERuMVfOMqI2" Feb 28 20:52:18 volumiosalon go-librespot[2286]: time="2025-02-28T20:52:18Z" level=debug msg="fetched chunk 1/17, size: 524288" uri="spotify:track:40PrHg3A1SAERuMVfOMqI2" Feb 28 20:52:18 volumiosalon go-librespot[2286]: time="2025-02-28T20:52:18Z" level=debug msg="fetched chunk 8/17, size: 524288" uri="spotify:track:40PrHg3A1SAERuMVfOMqI2" Feb 28 20:52:18 volumiosalon go-librespot[2286]: time="2025-02-28T20:52:18Z" level=debug msg="fetched chunk 3/17, size: 524288" uri="spotify:track:40PrHg3A1SAERuMVfOMqI2" Feb 28 20:52:19 volumiosalon go-librespot[2286]: time="2025-02-28T20:52:19Z" level=debug msg="fetched chunk 6/17, size: 524288" uri="spotify:track:40PrHg3A1SAERuMVfOMqI2" Feb 28 20:52:19 volumiosalon go-librespot[2286]: time="2025-02-28T20:52:19Z" level=trace msg="seek to 83291ms (diff: 157ms, samples: 3673133, bytes: 3646721)" uri="spotify:track:40PrHg3A1SAERuMVfOMqI2" Feb 28 20:52:19 volumiosalon go-librespot[2286]: time="2025-02-28T20:52:19Z" level=debug msg="fetched chunk 7/17, size: 524288" uri="spotify:track:40PrHg3A1SAERuMVfOMqI2" Feb 28 20:52:19 volumiosalon go-librespot[2286]: time="2025-02-28T20:52:19Z" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 10068 us, period size = 444 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 49 frames" Feb 28 20:52:19 volumiosalon go-librespot[2286]: time="2025-02-28T20:52:19Z" level=debug msg="created new output device" Feb 28 20:52:19 volumiosalon go-librespot[2286]: time="2025-02-28T20:52:19Z" level=info msg="loaded track \"Прочь от меня\" (paused: false, position: 83291ms, duration: 214800ms, prefetched: false)" uri="spotify:track:40PrHg3A1SAERuMVfOMqI2" Feb 28 20:52:19 volumiosalon go-librespot[2286]: time="2025-02-28T20:52:19Z" level=debug msg="fetched chunk 2/17, size: 524288" uri="spotify:track:40PrHg3A1SAERuMVfOMqI2" Feb 28 20:52:19 volumiosalon go-librespot[2286]: time="2025-02-28T20:52:19Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 28 20:52:19 volumiosalon go-librespot[2286]: time="2025-02-28T20:52:19Z" level=trace msg="scheduling prefetch in 102s" Feb 28 20:52:19 volumiosalon go-librespot[2286]: time="2025-02-28T20:52:19Z" level=trace msg="emitting websocket event: metadata" Feb 28 20:52:19 volumiosalon go-librespot[2286]: time="2025-02-28T20:52:19Z" level=trace msg="emitting websocket event: active" Feb 28 20:52:19 volumiosalon go-librespot[2286]: time="2025-02-28T20:52:19Z" level=debug msg="sending successful reply for dealer request" Feb 28 20:52:19 volumiosalon go-librespot[2286]: time="2025-02-28T20:52:19Z" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Feb 28 20:52:19 volumiosalon go-librespot[2286]: time="2025-02-28T20:52:19Z" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Feb 28 20:52:19 volumiosalon go-librespot[2286]: time="2025-02-28T20:52:19Z" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Feb 28 20:52:19 volumiosalon go-librespot[2286]: time="2025-02-28T20:52:19Z" level=debug msg="fetched chunk 10/17, size: 524288" uri="spotify:track:40PrHg3A1SAERuMVfOMqI2" Feb 28 20:52:19 volumiosalon go-librespot[2286]: time="2025-02-28T20:52:19Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 28 20:52:19 volumiosalon go-librespot[2286]: time="2025-02-28T20:52:19Z" level=trace msg="emitting websocket event: playing" Feb 28 20:52:19 volumiosalon go-librespot[2286]: time="2025-02-28T20:52:19Z" level=debug msg="fetched chunk 9/17, size: 524288" uri="spotify:track:40PrHg3A1SAERuMVfOMqI2" Feb 28 20:52:22 volumiosalon systemd[1]: apt-daily.service: Succeeded. Feb 28 20:52:22 volumiosalon systemd[1]: Started Daily apt download activities. Feb 28 20:52:22 volumiosalon systemd[1]: Starting Daily apt upgrade and clean activities... 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="f6610a1100d2380eef33bd3004af43153c786f96" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="1c0e5daee99fe3a72cc38b0d1fe6cd78d7f001fe" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 16 Dec 2024 09:30:04 AM CET" VOLUMIO_VERSION="3.785" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fe0ac4b79aed19ccde4b5bd83d468193"