-- Logs begin at Thu 2019-02-14 10:11:59 UTC, end at Fri 2025-01-17 08:55:06 UTC. -- Jan 17 08:54:58 madtunes systemd[1]: Starting Daily apt download activities... Jan 17 08:54:59 madtunes systemd[1]: apt-daily.service: Succeeded. Jan 17 08:54:59 madtunes systemd[1]: Started Daily apt download activities. Jan 17 08:54:59 madtunes systemd[1]: Starting Daily apt upgrade and clean activities... Jan 17 08:55:00 madtunes systemd[1]: apt-daily-upgrade.service: Succeeded. Jan 17 08:55:00 madtunes systemd[1]: Started Daily apt upgrade and clean activities. Jan 17 08:55:00 madtunes systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 17 08:55:00 madtunes systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Jan 17 08:55:00 madtunes systemd[1]: Stopped go-librespot Daemon. Jan 17 08:55:00 madtunes systemd[1]: Started go-librespot Daemon. Jan 17 08:55:00 madtunes go-librespot[1298]: Librespot-go daemon starting... Jan 17 08:55:01 madtunes go-librespot[1298]: time="2025-01-17T08:55:01Z" level=info msg="generated new device id: 4ad9c5308c2f6efcd44eb70dad8eb56e83e893dc" Jan 17 08:55:01 madtunes go-librespot[1298]: time="2025-01-17T08:55:01Z" level=debug msg="stored credentials found for 31tblk7drvo3bdqosd6wecaacp6q" Jan 17 08:55:01 madtunes go-librespot[1298]: time="2025-01-17T08:55:01Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jan 17 08:55:01 madtunes go-librespot[1298]: time="2025-01-17T08:55:01Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jan 17 08:55:01 madtunes go-librespot[1298]: time="2025-01-17T08:55:01Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jan 17 08:55:01 madtunes go-librespot[1298]: time="2025-01-17T08:55:01Z" level=debug msg="zeroconf server listening on port 43559" Jan 17 08:55:01 madtunes go-librespot[1298]: time="2025-01-17T08:55:01Z" level=debug msg="new websocket client" Jan 17 08:55:01 madtunes go-librespot[1298]: time="2025-01-17T08:55:01Z" level=debug msg="obtained new client token: AAAsZNNgmmhfui4ZugXlgcsmCUK5yz/nGja2P38OnuyVRdv74KZnVNGxiYdiAECuV2M/dGVYTtZ4/RgtJmP3qOJ2WKilp+FvJCcff34GLzPxwlndy5uZPtZvJIwXCpdjIz1VFvhi5g2XCkTnO6U4tveGqCXbEXFmqaFMssnfSkNOPykzgXzkKKZ+iTfUf8ckAWcv2olojbWONJ/4an8V59s/Bt22Y6NVZfq5oc4GIAZhtILiAhirQGR/t8Q=" Jan 17 08:55:01 madtunes go-librespot[1298]: time="2025-01-17T08:55:01Z" level=info msg="connected to ap-gew1.spotify.com:4070" Jan 17 08:55:01 madtunes go-librespot[1298]: time="2025-01-17T08:55:01Z" level=debug msg="completed keyexchange" Jan 17 08:55:01 madtunes nmbd[613]: [2025/01/17 08:55:01.676271, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Jan 17 08:55:01 madtunes nmbd[613]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.0.18 for name WORKGROUP<1d>. Jan 17 08:55:01 madtunes nmbd[613]: This response was from IP 192.168.0.29, reporting an IP address of 192.168.0.29. Jan 17 08:55:01 madtunes go-librespot[1298]: time="2025-01-17T08:55:01Z" level=debug msg="completed challenge" Jan 17 08:55:01 madtunes go-librespot[1298]: time="2025-01-17T08:55:01Z" level=debug msg="authenticated as 31tblk7drvo3bdqosd6wecaacp6q" Jan 17 08:55:01 madtunes go-librespot[1298]: time="2025-01-17T08:55:01Z" level=debug msg="authenticated as 31tblk7drvo3bdqosd6wecaacp6q" Jan 17 08:55:02 madtunes go-librespot[1298]: time="2025-01-17T08:55:02Z" level=debug msg="dealer connection opened" Jan 17 08:55:02 madtunes go-librespot[1298]: time="2025-01-17T08:55:02Z" level=debug msg="initializing zeroconf session, username: 31tblk7drvo3bdqosd6wecaacp6q" Jan 17 08:55:02 madtunes go-librespot[1298]: time="2025-01-17T08:55:02Z" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jan 17 08:55:02 madtunes go-librespot[1298]: time="2025-01-17T08:55:02Z" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jan 17 08:55:02 madtunes go-librespot[1298]: time="2025-01-17T08:55:02Z" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jan 17 08:55:02 madtunes go-librespot[1298]: time="2025-01-17T08:55:02Z" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jan 17 08:55:02 madtunes go-librespot[1298]: time="2025-01-17T08:55:02Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jan 17 08:55:02 madtunes go-librespot[1298]: time="2025-01-17T08:55:02Z" level=debug msg="autoplay enabled: false" Jan 17 08:55:02 madtunes go-librespot[1298]: time="2025-01-17T08:55:02Z" level=debug msg="received connection id: ZTNlM2M2MzUtMjNlYi00YjI2LWJhMDUtMTIyYjkyMTA2NmQ5K2RlYWxlcit0Y3A6Ly8wYWNhNDBhNi5pcC5nZXcxLnNwb3RpZnkubmV0OjU3MDArQkQ1NDlFQTU3MDc5QUE1RkMyMTM5N0Q3RTlEOEU1RUUzMjY2OUJFOUFFNzk2MTY4MTg1Qzg0RjA5MDA1NzFBMQ==" Jan 17 08:55:02 madtunes go-librespot[1298]: time="2025-01-17T08:55:02Z" level=debug msg="put connect state because NEW_DEVICE" Jan 17 08:55:04 madtunes go-librespot[1298]: time="2025-01-17T08:55:04Z" level=debug msg="handling transfer player command from 7b4333a89e26d850ffe5a141b0569e88a9ac81f0" Jan 17 08:55:04 madtunes go-librespot[1298]: time="2025-01-17T08:55:04Z" level=debug msg="resolved context of track" uri="spotify:album:5sLTeaPfSXch1w7KB8lWgb" Jan 17 08:55:04 madtunes go-librespot[1298]: time="2025-01-17T08:55:04Z" level=trace msg="fetched new page 0 with 12 items (list: 12)" uri="spotify:album:5sLTeaPfSXch1w7KB8lWgb" Jan 17 08:55:04 madtunes go-librespot[1298]: time="2025-01-17T08:55:04Z" level=debug msg="loading track (paused: true, position: 26326ms)" uri="spotify:track:0KLrpCeVIZ7W6k5FtsAH7B" Jan 17 08:55:04 madtunes go-librespot[1298]: time="2025-01-17T08:55:04Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 17 08:55:04 madtunes go-librespot[1298]: time="2025-01-17T08:55:04Z" level=trace msg="emitting websocket event: will_play" Jan 17 08:55:04 madtunes go-librespot[1298]: time="2025-01-17T08:55:04Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" Jan 17 08:55:04 madtunes go-librespot[1298]: time="2025-01-17T08:55:04Z" level=debug msg="selected format OGG_VORBIS_320 (3bb4d00b5061afd03035ad48351d4dffc52f4b40)" uri="spotify:track:0KLrpCeVIZ7W6k5FtsAH7B" Jan 17 08:55:04 madtunes go-librespot[1298]: time="2025-01-17T08:55:04Z" level=debug msg="requested aes key for file 3bb4d00b5061afd03035ad48351d4dffc52f4b40, gid: 0KLrpCeVIZ7W6k5FtsAH7B" Jan 17 08:55:04 madtunes go-librespot[1298]: time="2025-01-17T08:55:04Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1377" Jan 17 08:55:04 madtunes go-librespot[1298]: time="2025-01-17T08:55:04Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1133" Jan 17 08:55:04 madtunes go-librespot[1298]: time="2025-01-17T08:55:04Z" level=debug msg="fetched first chunk of 16, total size is 7941347 bytes" uri="spotify:track:0KLrpCeVIZ7W6k5FtsAH7B" Jan 17 08:55:05 madtunes go-librespot[1298]: time="2025-01-17T08:55:05Z" level=debug msg="fetched chunk 1/15, size: 524288" uri="spotify:track:0KLrpCeVIZ7W6k5FtsAH7B" Jan 17 08:55:05 madtunes go-librespot[1298]: time="2025-01-17T08:55:05Z" level=debug msg="fetched chunk 2/15, size: 524288" uri="spotify:track:0KLrpCeVIZ7W6k5FtsAH7B" Jan 17 08:55:05 madtunes go-librespot[1298]: time="2025-01-17T08:55:05Z" level=trace msg="seek to 26326ms (diff: 18ms, samples: 1160976, bytes: 1365433)" uri="spotify:track:0KLrpCeVIZ7W6k5FtsAH7B" Jan 17 08:55:05 madtunes kernel: pcm512x 1-004c: No SCLK, using BCLK: -2 Jan 17 08:55:05 madtunes go-librespot[1298]: time="2025-01-17T08:55:05Z" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames" Jan 17 08:55:05 madtunes go-librespot[1298]: time="2025-01-17T08:55:05Z" level=debug msg="created new output device" Jan 17 08:55:05 madtunes go-librespot[1298]: time="2025-01-17T08:55:05Z" level=info msg="loaded track \"Never Once\" (paused: true, position: 26326ms, duration: 140516ms, prefetched: false)" uri="spotify:track:0KLrpCeVIZ7W6k5FtsAH7B" Jan 17 08:55:05 madtunes go-librespot[1298]: time="2025-01-17T08:55:05Z" level=debug msg="fetched chunk 5/15, size: 524288" uri="spotify:track:0KLrpCeVIZ7W6k5FtsAH7B" Jan 17 08:55:05 madtunes go-librespot[1298]: time="2025-01-17T08:55:05Z" level=debug msg="fetched chunk 3/15, size: 524288" uri="spotify:track:0KLrpCeVIZ7W6k5FtsAH7B" Jan 17 08:55:05 madtunes go-librespot[1298]: time="2025-01-17T08:55:05Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 17 08:55:05 madtunes go-librespot[1298]: time="2025-01-17T08:55:05Z" level=trace msg="emitting websocket event: metadata" Jan 17 08:55:05 madtunes go-librespot[1298]: time="2025-01-17T08:55:05Z" level=trace msg="emitting websocket event: active" Jan 17 08:55:05 madtunes go-librespot[1298]: time="2025-01-17T08:55:05Z" level=debug msg="sending successful reply for dealer request" Jan 17 08:55:05 madtunes go-librespot[1298]: time="2025-01-17T08:55:05Z" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jan 17 08:55:05 madtunes go-librespot[1298]: time="2025-01-17T08:55:05Z" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jan 17 08:55:05 madtunes go-librespot[1298]: time="2025-01-17T08:55:05Z" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jan 17 08:55:05 madtunes go-librespot[1298]: time="2025-01-17T08:55:05Z" level=debug msg="fetched chunk 4/15, size: 524288" uri="spotify:track:0KLrpCeVIZ7W6k5FtsAH7B" Jan 17 08:55:05 madtunes go-librespot[1298]: time="2025-01-17T08:55:05Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 17 08:55:05 madtunes go-librespot[1298]: time="2025-01-17T08:55:05Z" level=trace msg="emitting websocket event: paused" Jan 17 08:55:06 madtunes systemd-journald[194]: Suppressed 3594 messages from volumio.service Jan 17 08:55:06 madtunes sudo[1334]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-17 08:54 Jan 17 08:55:06 madtunes sudo[1334]: 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="b1c3cf61c2a0027c66bab1eb0a3795f80c1f2e95" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="e3eb3ee5b16063502f3a1735e11a28cfe54a0f46" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sun 25 Jun 2023 07:20:58 PM CEST" VOLUMIO_VERSION="3.512" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="946a42b62509f37b5e7e2d86a2932a62"