-- Logs begin at Thu 2019-02-14 10:11:59 UTC, end at Thu 2024-07-11 22:46:49 UTC. --
Jul 11 22:46:44 volumio ntpd[619]: receive: Unexpected origin timestamp 0xe7dab878.616a0e30 does not match aorg 0000000000.00000000 from server@162.252.172.49 xmt 0xea3adf54.dba33723
Jul 11 22:46:44 volumio ntpd[619]: receive: Unexpected origin timestamp 0xe7dab878.6163ec66 does not match aorg 0000000000.00000000 from server@129.250.35.250 xmt 0xea3adf54.db591219
Jul 11 22:46:44 volumio systemd[1]: Starting Daily apt download activities...
Jul 11 22:46:44 volumio ntpd[619]: receive: Unexpected origin timestamp 0xe7dab878.616b6607 does not match aorg 0000000000.00000000 from server@69.164.213.136 xmt 0xea3adf54.db020348
Jul 11 22:46:44 volumio ntpd[619]: receive: Unexpected origin timestamp 0xe7dab878.61689d1d does not match aorg 0000000000.00000000 from server@99.119.214.210 xmt 0xea3adf54.ddd4d0e8
Jul 11 22:46:44 volumio ntpd[619]: receive: Unexpected origin timestamp 0xe7dab878.6165a8a5 does not match aorg 0000000000.00000000 from server@45.79.1.70 xmt 0xea3adf54.df771c3e
Jul 11 22:46:44 volumio ntpd[619]: receive: Unexpected origin timestamp 0xe7dab878.61672c39 does not match aorg 0000000000.00000000 from server@129.146.193.200 xmt 0xea3adf54.e29178c2
Jul 11 22:46:44 volumio ntpd[619]: receive: Unexpected origin timestamp 0xe7dab878.615fbb65 does not match aorg 0000000000.00000000 from server@204.17.205.27 xmt 0xea3adf54.e1f2d733
Jul 11 22:46:45 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 11 22:46:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6.
Jul 11 22:46:45 volumio systemd[1]: Stopped go-librespot Daemon.
Jul 11 22:46:45 volumio systemd[1]: Started go-librespot Daemon.
Jul 11 22:46:45 volumio go-librespot[1295]: Librespot-go daemon starting...
Jul 11 22:46:45 volumio go-librespot[1295]: time="2024-07-11T22:46:45Z" level=info msg="generated new device id: 49b3aea621528ea86e3e8d77ce0eb51e652b7a42"
Jul 11 22:46:45 volumio go-librespot[1295]: time="2024-07-11T22:46:45Z" level=debug msg="stored credentials found for 31ziiaa4ktzdw7qarz25tiesao5q"
Jul 11 22:46:45 volumio go-librespot[1295]: time="2024-07-11T22:46:45Z" level=debug msg="obtained new client token: AADWhaCplbEfOm2w5fTt7N+PeZueHX7t/WoVbtCHD3TYNg+w2qsAfOWQZLE3/21nokrPH0aw+5PIWDq53OKl4dEbAoBpZGUq4JU5CNPtsNoir6B7ilLcV+BavmsfNj4rMaKugEyDb94jAqlusdIu7IWnCDtKSpa0f03GvbhbSEdUrUo2If5A5CzuD9aPdRo2qLVDSysAB6T471VVh93YEJrzOGZUfimGOE98MTa3z/adcL4jM3M7XnZKtJExy88="
Jul 11 22:46:45 volumio go-librespot[1295]: time="2024-07-11T22:46:45Z" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Jul 11 22:46:45 volumio go-librespot[1295]: time="2024-07-11T22:46:45Z" level=debug msg="completed keyexchange"
Jul 11 22:46:46 volumio go-librespot[1295]: time="2024-07-11T22:46:46Z" level=debug msg="completed challenge"
Jul 11 22:46:46 volumio go-librespot[1295]: time="2024-07-11T22:46:46Z" level=debug msg="authenticated as 31ziiaa4ktzdw7qarz25tiesao5q"
Jul 11 22:46:46 volumio go-librespot[1295]: time="2024-07-11T22:46:46Z" level=debug msg="authenticated as 31ziiaa4ktzdw7qarz25tiesao5q"
Jul 11 22:46:46 volumio go-librespot[1295]: time="2024-07-11T22:46:46Z" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Jul 11 22:46:46 volumio go-librespot[1295]: time="2024-07-11T22:46:46Z" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Jul 11 22:46:46 volumio systemd[1]: apt-daily.service: Succeeded.
Jul 11 22:46:46 volumio go-librespot[1295]: time="2024-07-11T22:46:46Z" level=debug msg="dealer connection opened"
Jul 11 22:46:46 volumio go-librespot[1295]: time="2024-07-11T22:46:46Z" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336"
Jul 11 22:46:46 volumio go-librespot[1295]: time="2024-07-11T22:46:46Z" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2"
Jul 11 22:46:46 volumio systemd[1]: Started Daily apt download activities.
Jul 11 22:46:46 volumio go-librespot[1295]: time="2024-07-11T22:46:46Z" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17"
Jul 11 22:46:46 volumio go-librespot[1295]: time="2024-07-11T22:46:46Z" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0"
Jul 11 22:46:46 volumio go-librespot[1295]: time="2024-07-11T22:46:46Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 513"
Jul 11 22:46:46 volumio go-librespot[1295]: time="2024-07-11T22:46:46Z" level=debug msg="received connection id: M2FjOTAyODAtNTVjNS00MzdiLTk5ZjUtZTAwOGZmZDYwNTAxK2RlYWxlcit0Y3A6Ly9ndWUxLWRlYWxlci1hLWhoODguZ3VlMS5zcG90aWZ5Lm5ldDo1NzAwK0ZBNzcxOTNCM0MzNzU4NTlENjU4QkUxRjZENzQyNkM0QjhGNDREOTMzQ0VCMUE5NzdFMTBCQzM2NTM1MEJBQjI="
Jul 11 22:46:46 volumio systemd[1]: Starting Daily apt upgrade and clean activities...
Jul 11 22:46:47 volumio go-librespot[1295]: time="2024-07-11T22:46:47Z" level=debug msg="new websocket client"
Jul 11 22:46:47 volumio go-librespot[1295]: time="2024-07-11T22:46:47Z" level=debug msg="put connect state because NEW_DEVICE"
Jul 11 22:46:48 volumio systemd[1]: apt-daily-upgrade.service: Succeeded.
Jul 11 22:46:48 volumio systemd[1]: Started Daily apt upgrade and clean activities.
Jul 11 22:46:48 volumio go-librespot[1295]: time="2024-07-11T22:46:48Z" level=debug msg="handling transfer player command from cc1494728a4a01820ecf698ad283a43dde6e72e7"
Jul 11 22:46:48 volumio go-librespot[1295]: time="2024-07-11T22:46:48Z" level=trace msg="fetched new page 0 with 50 items (list: 50)"
Jul 11 22:46:48 volumio go-librespot[1295]: time="2024-07-11T22:46:48Z" level=debug msg="shuffled context with seed 2529936742671142212 (len: 50, keep: 48)"
Jul 11 22:46:48 volumio go-librespot[1295]: time="2024-07-11T22:46:48Z" level=debug msg="loading track spotify:track:3OBzTMqncLaFNjLQQfXOpe (paused: true, position: 6895ms)"
Jul 11 22:46:48 volumio go-librespot[1295]: time="2024-07-11T22:46:48Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 11 22:46:48 volumio go-librespot[1295]: time="2024-07-11T22:46:48Z" level=trace msg="emitting websocket event: will_play"
Jul 11 22:46:48 volumio go-librespot[1295]: time="2024-07-11T22:46:48Z" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:3OBzTMqncLaFNjLQQfXOpe"
Jul 11 22:46:48 volumio go-librespot[1295]: time="2024-07-11T22:46:48Z" level=debug msg="requested aes key for file b952e7eb5c3834d4ffe0fa94b3c33fc8b41389cc, gid: 3OBzTMqncLaFNjLQQfXOpe"
Jul 11 22:46:48 volumio go-librespot[1295]: time="2024-07-11T22:46:48Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241"
Jul 11 22:46:48 volumio go-librespot[1295]: time="2024-07-11T22:46:48Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1627"
Jul 11 22:46:48 volumio go-librespot[1295]: time="2024-07-11T22:46:48Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1388"
Jul 11 22:46:48 volumio go-librespot[1295]: time="2024-07-11T22:46:48Z" level=debug msg="fetched first chunk of 24, total size is 12133928 bytes"
Jul 11 22:46:48 volumio go-librespot[1295]: time="2024-07-11T22:46:48Z" level=trace msg="seek to 6895ms (diff: 105ms, samples: 304069, bytes: 293750)"
Jul 11 22:46:48 volumio go-librespot[1295]: time="2024-07-11T22:46:48Z" level=info msg="loaded track \"Guitars and Tiki Bars\" (uri: spotify:track:3OBzTMqncLaFNjLQQfXOpe, paused: true, position: 6895ms, duration: 276400ms)"
Jul 11 22:46:48 volumio go-librespot[1295]: time="2024-07-11T22:46:48Z" level=debug msg="fetched chunk 1/23, size: 524288"
Jul 11 22:46:49 volumio go-librespot[1295]: time="2024-07-11T22:46:49Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 11 22:46:49 volumio go-librespot[1295]: time="2024-07-11T22:46:49Z" level=trace msg="emitting websocket event: metadata"
Jul 11 22:46:49 volumio go-librespot[1295]: time="2024-07-11T22:46:49Z" level=trace msg="emitting websocket event: active"
Jul 11 22:46:49 volumio go-librespot[1295]: time="2024-07-11T22:46:49Z" level=debug msg="sending successful reply for delaer request"
Jul 11 22:46:49 volumio go-librespot[1295]: time="2024-07-11T22:46:49Z" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update
Jul 11 22:46:49 volumio go-librespot[1295]: time="2024-07-11T22:46:49Z" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update
Jul 11 22:46:49 volumio go-librespot[1295]: time="2024-07-11T22:46:49Z" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update
Jul 11 22:46:49 volumio go-librespot[1295]: time="2024-07-11T22:46:49Z" level=debug msg="fetched chunk 2/23, size: 524288"
Jul 11 22:46:49 volumio go-librespot[1295]: time="2024-07-11T22:46:49Z" level=debug msg="fetched chunk 3/23, size: 524288"
Jul 11 22:46:49 volumio go-librespot[1295]: time="2024-07-11T22:46:49Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 11 22:46:49 volumio go-librespot[1295]: time="2024-07-11T22:46:49Z" level=trace msg="emitting websocket event: paused"
Jul 11 22:46:49 volumio go-librespot[1295]: time="2024-07-11T22:46:49Z" level=debug msg="handling resume player command from cc1494728a4a01820ecf698ad283a43dde6e72e7"
Jul 11 22:46:49 volumio go-librespot[1295]: time="2024-07-11T22:46:49Z" level=trace msg="seek to 6895ms (diff: 105ms, samples: 304069, bytes: 293750)"
Jul 11 22:46:49 volumio go-librespot[1295]: time="2024-07-11T22:46:49Z" level=debug msg="resume track at 6419ms"
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="c87c6e2b1ae33dc5801986cbcbe970898b92e7b4"
VOLUMIO_FE_VERSION="c433755e569617abac52264d17ad61be303ef463"
VOLUMIO_FE3_VERSION="2419ddd8e895c5bdc456962163c9dc7c0f187aa7"
VOLUMIO_BE_VERSION="b949d6001d7e656b4668f31c119d2247cdf45158"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Thu 30 Mar 2023 05:45:03 PM CEST"
VOLUMIO_VERSION="3.449"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="6428d8e2c06e98483f5c5d77e8f01989"