Jan 09 13:21:00 volumio-test1 volumio[1296]: info: CoreStateMachine::pushState Jan 09 13:21:00 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 1 Jan 09 13:21:00 volumio-test1 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 09 13:21:00 volumio-test1 volumio[1296]: info: CoreCommandRouter::volumioPushState Jan 09 13:21:00 volumio-test1 volumio[1296]: SPOTIFY: RECEIVED VOLUMIO VOLUME 81 Jan 09 13:21:00 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:00+01:00" level=debug msg="update volume requested to 51917/65535" Jan 09 13:21:00 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:00+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Jan 09 13:21:00 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:00+01:00" level=trace msg="emitting websocket event: volume" Jan 09 13:21:00 volumio-test1 volumio[1296]: SPOTIFY: received: {"type":"volume","data":{"value":79,"max":100}} Jan 09 13:21:00 volumio-test1 volumio[1296]: SPOTIFY: RECEIVED SPOTIFY VOLUME 79 Jan 09 13:21:00 volumio-test1 volumio[1296]: info: Setting Volumio Volume from Spotify: 79 Jan 09 13:21:00 volumio-test1 volumio[1296]: info: VolumeController::SetAlsaVolume79 Jan 09 13:21:00 volumio-test1 volumio[1296]: info: CoreStateMachine::pushState Jan 09 13:21:00 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 1 Jan 09 13:21:00 volumio-test1 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 09 13:21:01 volumio-test1 volumio[1296]: info: CoreCommandRouter::volumioPushState Jan 09 13:21:01 volumio-test1 volumio[1296]: SPOTIFY: RECEIVED VOLUMIO VOLUME 79 Jan 09 13:21:01 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:01+01:00" level=debug msg="update volume requested to 43322/65535" Jan 09 13:21:01 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:01+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Jan 09 13:21:01 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:01+01:00" level=trace msg="emitting websocket event: volume" Jan 09 13:21:01 volumio-test1 volumio[1296]: SPOTIFY: received: {"type":"volume","data":{"value":66,"max":100}} Jan 09 13:21:01 volumio-test1 volumio[1296]: SPOTIFY: RECEIVED SPOTIFY VOLUME 66 Jan 09 13:21:01 volumio-test1 volumio[1296]: info: Setting Volumio Volume from Spotify: 66 Jan 09 13:21:01 volumio-test1 volumio[1296]: info: VolumeController::SetAlsaVolume66 Jan 09 13:21:01 volumio-test1 volumio[1296]: info: CoreStateMachine::pushState Jan 09 13:21:01 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 1 Jan 09 13:21:01 volumio-test1 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 09 13:21:01 volumio-test1 volumio[1296]: info: CoreCommandRouter::volumioPushState Jan 09 13:21:01 volumio-test1 volumio[1296]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66 Jan 09 13:21:01 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:01+01:00" level=debug msg="update volume requested to 40914/65535" Jan 09 13:21:02 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:02+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Jan 09 13:21:02 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:02+01:00" level=trace msg="emitting websocket event: volume" Jan 09 13:21:02 volumio-test1 volumio[1296]: SPOTIFY: received: {"type":"volume","data":{"value":62,"max":100}} Jan 09 13:21:02 volumio-test1 volumio[1296]: SPOTIFY: RECEIVED SPOTIFY VOLUME 62 Jan 09 13:21:02 volumio-test1 volumio[1296]: info: Setting Volumio Volume from Spotify: 62 Jan 09 13:21:02 volumio-test1 volumio[1296]: info: VolumeController::SetAlsaVolume62 Jan 09 13:21:02 volumio-test1 volumio[1296]: info: CoreStateMachine::pushState Jan 09 13:21:02 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 1 Jan 09 13:21:02 volumio-test1 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 09 13:21:02 volumio-test1 volumio[1296]: info: CoreCommandRouter::volumioPushState Jan 09 13:21:02 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:02+01:00" level=debug msg="update volume requested to 36597/65535" Jan 09 13:21:02 volumio-test1 volumio[1296]: SPOTIFY: RECEIVED VOLUMIO VOLUME 62 Jan 09 13:21:02 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:02+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Jan 09 13:21:02 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:02+01:00" level=trace msg="emitting websocket event: volume" Jan 09 13:21:02 volumio-test1 volumio[1296]: SPOTIFY: received: {"type":"volume","data":{"value":56,"max":100}} Jan 09 13:21:02 volumio-test1 volumio[1296]: SPOTIFY: RECEIVED SPOTIFY VOLUME 56 Jan 09 13:21:02 volumio-test1 volumio[1296]: info: Setting Volumio Volume from Spotify: 56 Jan 09 13:21:02 volumio-test1 volumio[1296]: info: VolumeController::SetAlsaVolume56 Jan 09 13:21:02 volumio-test1 volumio[1296]: info: CoreStateMachine::pushState Jan 09 13:21:02 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 1 Jan 09 13:21:02 volumio-test1 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 09 13:21:02 volumio-test1 volumio[1296]: info: CoreCommandRouter::volumioPushState Jan 09 13:21:02 volumio-test1 volumio[1296]: SPOTIFY: RECEIVED VOLUMIO VOLUME 56 Jan 09 13:21:06 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:06+01:00" level=debug msg="fetched chunk 5/18, size: 524288" uri="spotify:track:3euZKF0hmGxQ6h2JHHY4iu" Jan 09 13:21:06 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:06+01:00" level=info msg="playback was transferred to S24 von Tobias" Jan 09 13:21:06 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:06+01:00" level=trace msg="closed output device because of stop command" Jan 09 13:21:06 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:06+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jan 09 13:21:06 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:06+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jan 09 13:21:06 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:06+01:00" level=debug msg="put connect state inactive" Jan 09 13:21:06 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:06+01:00" level=trace msg="emitting websocket event: inactive" Jan 09 13:21:06 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:06+01:00" level=trace msg="emitting websocket event: stopped" Jan 09 13:21:06 volumio-test1 volumio[1296]: SPOTIFY: received: {"type":"inactive","data":null} Jan 09 13:21:06 volumio-test1 volumio[1296]: error: Failed to decode event: inactive Jan 09 13:21:06 volumio-test1 volumio[1296]: SPOTIFY: received: {"type":"stopped","data":{"play_origin":""}} Jan 09 13:21:06 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:06+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1194" Jan 09 13:21:06 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:06+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 464" Jan 09 13:21:06 volumio-test1 volumio[1296]: SPOTIFY: PUSH STATE SPOTIFY Jan 09 13:21:06 volumio-test1 volumio[1296]: SPOTIFY: {"status":"stop","service":"spop","title":"Opalite","artist":"Taylor Swift","album":"The Life of a Showgirl","albumart":"https://i.scdn.co/image/ab67616d00001e02b034f9cdf12ae14c603daa99","uri":"spotify:track:3euZKF0hmGxQ6h2JHHY4iu","trackType":"spotify","seek":26000,"duration":235,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 09 13:21:06 volumio-test1 volumio[1296]: info: CoreCommandRouter::servicePushState Jan 09 13:21:06 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:06+01:00" level=debug msg="dealer connection closed" Jan 09 13:21:06 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:06+01:00" level=debug msg="dealer recv loop stopped" Jan 09 13:21:06 volumio-test1 volumio[1296]: info: CoreStateMachine::pushState Jan 09 13:21:06 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 1 Jan 09 13:21:06 volumio-test1 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 09 13:21:06 volumio-test1 volumio[1296]: info: CoreCommandRouter::volumioPushState Jan 09 13:21:06 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:06+01:00" level=debug msg="obtained new client token: AAAZQvAIgZCZOa8wRoCq9FXOqlBZ4mxkcPY9ug4LzXG/rfe17TSPah+FD1oHZbL60cNFZwd43fzG+mxr//IGDxmCPisRa8kmRO6fsG5gy0JtGNJX5F7Ih6ML+D5bw6PssfqOGOpSDflIrn5Ypr0Y5ox9sHCDBjBKEG05HWjKxbp7s3N5XJ6B/fOp+C9gKHvmDew1VLxhGc3MR3SIcW0MfglNG/qt1qDXNDyqGAwHMQrRpIvSbxFZnYun" Jan 09 13:21:06 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:06+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" Jan 09 13:21:06 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 1 Jan 09 13:21:06 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:06+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Jan 09 13:21:06 volumio-test1 volumio[1296]: verbose: STATE SERVICE {"status":"stop","service":"spop","title":"Opalite","artist":"Taylor Swift","album":"The Life of a Showgirl","albumart":"https://i.scdn.co/image/ab67616d00001e02b034f9cdf12ae14c603daa99","uri":"spotify:track:3euZKF0hmGxQ6h2JHHY4iu","trackType":"spotify","seek":26000,"duration":235,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 09 13:21:06 volumio-test1 volumio[1296]: verbose: CURRENT POSITION 1 Jan 09 13:21:06 volumio-test1 volumio[1296]: info: CoreStateMachine::syncState stateService stop Jan 09 13:21:06 volumio-test1 volumio[1296]: info: CoreStateMachine::syncState currentStatus play Jan 09 13:21:06 volumio-test1 volumio[1296]: info: CoreStateMachine::play index undefined Jan 09 13:21:06 volumio-test1 volumio[1296]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 09 13:21:06 volumio-test1 volumio[1296]: info: CoreStateMachine::pushState Jan 09 13:21:06 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 2 Jan 09 13:21:06 volumio-test1 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 09 13:21:06 volumio-test1 volumio[1296]: info: CoreCommandRouter::volumioPushState Jan 09 13:21:06 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:06+01:00" level=debug msg="completed keyexchange" Jan 09 13:21:06 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:06+01:00" level=debug msg="completed challenge" Jan 09 13:21:06 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:06+01:00" level=info msg="authenticated AP" username="gn*********************59" Jan 09 13:21:07 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 2 Jan 09 13:21:07 volumio-test1 volumio[1296]: info: CoreStateMachine::startPlaybackTimer Jan 09 13:21:07 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 2 Jan 09 13:21:07 volumio-test1 volumio[1296]: info: [1767961267019] ControllerSpotify::clearAddPlayTrack Jan 09 13:21:07 volumio-test1 volumio[1296]: info: Sending Spotify command with payload to local API: /player/play Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=info msg="authenticated Login5" username="gn*********************59" Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=debug msg="restored session after logout" username="gn*********************59" Jan 09 13:21:07 volumio-test1 volumio[1296]: info: CoreStateMachine::pushState Jan 09 13:21:07 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 2 Jan 09 13:21:07 volumio-test1 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 09 13:21:07 volumio-test1 volumio[1296]: info: CoreCommandRouter::volumioPushState Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=debug msg="dealer connection opened" Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=trace msg="starting accesspoint recv loop" Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=trace msg="starting dealer recv loop" Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=trace msg="received accesspoint ping" Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=debug msg="received connection id: NTEzMjhlM2QtYmJl...MzM2NTExNTU4Rg==" Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=trace msg="received accesspoint pong ack" Jan 09 13:21:07 volumio-test1 volumio[1296]: SPOTIFY: RECEIVED VOLUMIO VOLUME 56 Jan 09 13:21:07 volumio-test1 volumio[1296]: SPOTIFY: RECEIVED VOLUMIO VOLUME 56 Jan 09 13:21:07 volumio-test1 volumio[1296]: SPOTIFY: RECEIVED VOLUMIO VOLUME 56 Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=debug msg="put connect state because NEW_DEVICE" Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=debug msg="resolved context of track" uri="spotify:track:1BxfuPKGuaTgP7aM0Bbdwr" Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:1BxfuPKGuaTgP7aM0Bbdwr" Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:1BxfuPKGuaTgP7aM0Bbdwr" Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=trace msg="emitting websocket event: will_play" Jan 09 13:21:07 volumio-test1 volumio[1296]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:1BxfuPKGuaTgP7aM0Bbdwr","uri":"spotify:track:1BxfuPKGuaTgP7aM0Bbdwr","play_origin":"go-librespot"}} Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=debug msg="selected format OGG_VORBIS_320 (3a9ae6f611096fcb8a0ed9150df32224941b3eb2)" uri="spotify:track:1BxfuPKGuaTgP7aM0Bbdwr" Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=debug msg="requested aes key for file 3a9ae6f611096fcb8a0ed9150df32224941b3eb2, gid: 1BxfuPKGuaTgP7aM0Bbdwr" Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 411" Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1129" Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=trace msg="found 2 cdn urls" uri="spotify:track:1BxfuPKGuaTgP7aM0Bbdwr" Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=debug msg="fetched first chunk of 15, total size is 7633484 bytes" uri="spotify:track:1BxfuPKGuaTgP7aM0Bbdwr" Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=debug msg="created new output device" Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 100000 us, period size = 4410 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 5 frames, PCM format = FLOAT_LE" Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=info msg="loaded track \"Cruel Summer\" (paused: false, position: 0ms, duration: 178426ms, prefetched: false)" uri="spotify:track:1BxfuPKGuaTgP7aM0Bbdwr" Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=debug msg="fetched chunk 1/14, size: 524288" uri="spotify:track:1BxfuPKGuaTgP7aM0Bbdwr" Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=trace msg="scheduling prefetch in 148s" Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=trace msg="emitting websocket event: metadata" Jan 09 13:21:07 volumio-test1 volumio[1296]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:1BxfuPKGuaTgP7aM0Bbdwr","name":"Cruel Summer","artist_names":["Taylor Swift"],"album_name":"Lover","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02e787cffec20aa2a396a61647","position":0,"duration":178426,"release_date":"year:2019 month:8 day:23","track_number":2,"disc_number":1}} Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=debug msg="fetched chunk 3/14, size: 524288" uri="spotify:track:1BxfuPKGuaTgP7aM0Bbdwr" Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=trace msg="emitting websocket event: playing" Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=debug msg="fetched chunk 2/14, size: 524288" uri="spotify:track:1BxfuPKGuaTgP7aM0Bbdwr" Jan 09 13:21:07 volumio-test1 volumio[1296]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:1BxfuPKGuaTgP7aM0Bbdwr","uri":"spotify:track:1BxfuPKGuaTgP7aM0Bbdwr","resume":false,"play_origin":"go-librespot"}} Jan 09 13:21:07 volumio-test1 volumio[1296]: SPOTIFY: PUSH STATE SPOTIFY Jan 09 13:21:07 volumio-test1 volumio[1296]: SPOTIFY: {"status":"play","service":"spop","title":"Cruel Summer","artist":"Taylor Swift","album":"Lover","albumart":"https://i.scdn.co/image/ab67616d00001e02e787cffec20aa2a396a61647","uri":"spotify:track:1BxfuPKGuaTgP7aM0Bbdwr","trackType":"spotify","seek":0,"duration":178,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 09 13:21:07 volumio-test1 volumio[1296]: info: CoreCommandRouter::servicePushState Jan 09 13:21:07 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 2 Jan 09 13:21:07 volumio-test1 volumio[1296]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Cruel Summer","artist":"Taylor Swift","album":"Lover","albumart":"https://i.scdn.co/image/ab67616d00001e02e787cffec20aa2a396a61647","uri":"spotify:track:1BxfuPKGuaTgP7aM0Bbdwr","trackType":"spotify","seek":0,"duration":178,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 09 13:21:07 volumio-test1 volumio[1296]: verbose: CURRENT POSITION 2 Jan 09 13:21:07 volumio-test1 volumio[1296]: info: CoreStateMachine::syncState stateService play Jan 09 13:21:07 volumio-test1 volumio[1296]: info: CoreStateMachine::syncState currentStatus stop Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=debug msg="skipping dealer message" uri=playback-settings/content-settings-update Jan 09 13:21:07 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:07+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 159" Jan 09 13:21:07 volumio-test1 volumio[1296]: SPOTIFY: PUSH STATE SPOTIFY Jan 09 13:21:07 volumio-test1 volumio[1296]: SPOTIFY: {"status":"play","service":"spop","title":"Cruel Summer","artist":"Taylor Swift","album":"Lover","albumart":"https://i.scdn.co/image/ab67616d00001e02e787cffec20aa2a396a61647","uri":"spotify:track:1BxfuPKGuaTgP7aM0Bbdwr","trackType":"spotify","seek":0,"duration":178,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 09 13:21:07 volumio-test1 volumio[1296]: info: CoreCommandRouter::servicePushState Jan 09 13:21:07 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 2 Jan 09 13:21:07 volumio-test1 volumio[1296]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Cruel Summer","artist":"Taylor Swift","album":"Lover","albumart":"https://i.scdn.co/image/ab67616d00001e02e787cffec20aa2a396a61647","uri":"spotify:track:1BxfuPKGuaTgP7aM0Bbdwr","trackType":"spotify","seek":0,"duration":178,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 09 13:21:07 volumio-test1 volumio[1296]: verbose: CURRENT POSITION 2 Jan 09 13:21:07 volumio-test1 volumio[1296]: info: CoreStateMachine::syncState stateService play Jan 09 13:21:07 volumio-test1 volumio[1296]: info: CoreStateMachine::syncState currentStatus play Jan 09 13:21:07 volumio-test1 volumio[1296]: info: Received an update from plugin. extracting info from payload Jan 09 13:21:07 volumio-test1 volumio[1296]: info: CoreStateMachine::pushState Jan 09 13:21:07 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 2 Jan 09 13:21:07 volumio-test1 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 09 13:21:07 volumio-test1 volumio[1296]: info: CoreCommandRouter::volumioPushState Jan 09 13:21:07 volumio-test1 volumio[1296]: info: CoreStateMachine::pushState Jan 09 13:21:07 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 2 Jan 09 13:21:07 volumio-test1 volumio[1296]: info: CoreCommandRouter::volumioPushState Jan 09 13:21:07 volumio-test1 volumio[1296]: SPOTIFY: RECEIVED VOLUMIO VOLUME 56 Jan 09 13:21:07 volumio-test1 volumio[1296]: SPOTIFY: RECEIVED VOLUMIO VOLUME 56 Jan 09 13:21:11 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:11+01:00" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1DX3h1vasAdBTc" Jan 09 13:21:11 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:11+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Jan 09 13:21:19 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:19+01:00" level=debug msg="fetched chunk 4/14, size: 524288" uri="spotify:track:1BxfuPKGuaTgP7aM0Bbdwr" Jan 09 13:21:19 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:19+01:00" level=info msg="playback was transferred to S24 von Tobias" Jan 09 13:21:19 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:19+01:00" level=trace msg="closed output device because of stop command" Jan 09 13:21:19 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:19+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jan 09 13:21:19 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:19+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jan 09 13:21:19 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:19+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 464" Jan 09 13:21:19 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:19+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1194" Jan 09 13:21:19 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:19+01:00" level=debug msg="put connect state inactive" Jan 09 13:21:19 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:19+01:00" level=trace msg="emitting websocket event: inactive" Jan 09 13:21:19 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:19+01:00" level=trace msg="emitting websocket event: stopped" Jan 09 13:21:19 volumio-test1 volumio[1296]: SPOTIFY: received: {"type":"inactive","data":null} Jan 09 13:21:19 volumio-test1 volumio[1296]: error: Failed to decode event: inactive Jan 09 13:21:19 volumio-test1 volumio[1296]: SPOTIFY: received: {"type":"stopped","data":{"play_origin":""}} Jan 09 13:21:19 volumio-test1 volumio[1296]: SPOTIFY: PUSH STATE SPOTIFY Jan 09 13:21:19 volumio-test1 volumio[1296]: SPOTIFY: {"status":"stop","service":"spop","title":"Cruel Summer","artist":"Taylor Swift","album":"Lover","albumart":"https://i.scdn.co/image/ab67616d00001e02e787cffec20aa2a396a61647","uri":"spotify:track:1BxfuPKGuaTgP7aM0Bbdwr","trackType":"spotify","seek":11000,"duration":178,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 09 13:21:19 volumio-test1 volumio[1296]: info: CoreCommandRouter::servicePushState Jan 09 13:21:19 volumio-test1 volumio[1296]: info: CoreStateMachine::pushState Jan 09 13:21:19 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 2 Jan 09 13:21:19 volumio-test1 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 09 13:21:19 volumio-test1 volumio[1296]: info: CoreCommandRouter::volumioPushState Jan 09 13:21:19 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 2 Jan 09 13:21:19 volumio-test1 volumio[1296]: verbose: STATE SERVICE {"status":"stop","service":"spop","title":"Cruel Summer","artist":"Taylor Swift","album":"Lover","albumart":"https://i.scdn.co/image/ab67616d00001e02e787cffec20aa2a396a61647","uri":"spotify:track:1BxfuPKGuaTgP7aM0Bbdwr","trackType":"spotify","seek":11000,"duration":178,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 09 13:21:19 volumio-test1 volumio[1296]: verbose: CURRENT POSITION 2 Jan 09 13:21:19 volumio-test1 volumio[1296]: info: CoreStateMachine::syncState stateService stop Jan 09 13:21:19 volumio-test1 volumio[1296]: info: CoreStateMachine::syncState currentStatus play Jan 09 13:21:19 volumio-test1 volumio[1296]: info: CoreStateMachine::play index undefined Jan 09 13:21:19 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:19+01:00" level=debug msg="dealer connection closed" Jan 09 13:21:19 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:19+01:00" level=debug msg="dealer recv loop stopped" Jan 09 13:21:19 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:19+01:00" level=debug msg="obtained new client token: AACI/9/IjojdvMTF76v+2yUbsJ2h9ReRXSrfophE9afg3+CXZXM6V8WigY0ng5H1SnZOhlmGHSobVAFbQz8pqXjQYjTg+ZceC1Qmkz/ObvKf3iV82izDhK6bigwDSJFIrP2OxUwtQSbZBoPxDBPmQMU0WXByAq83bj0p1KQ+vQemx1k+1z5a/b/Ss51ovJCfuwgCF2mP7SIyqawmLLKF/jCw5JFJ03ZRkQ7HxRZ59opEOFN8Emq8F8P7" Jan 09 13:21:19 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:19+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Jan 09 13:21:19 volumio-test1 volumio[1296]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 09 13:21:19 volumio-test1 volumio[1296]: info: CoreStateMachine::pushState Jan 09 13:21:19 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 3 Jan 09 13:21:19 volumio-test1 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 09 13:21:19 volumio-test1 volumio[1296]: info: CoreCommandRouter::volumioPushState Jan 09 13:21:19 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:19+01:00" level=debug msg="completed keyexchange" Jan 09 13:21:19 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:19+01:00" level=debug msg="completed challenge" Jan 09 13:21:19 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:19+01:00" level=info msg="authenticated AP" username="gn*********************59" Jan 09 13:21:19 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:19+01:00" level=info msg="authenticated Login5" username="gn*********************59" Jan 09 13:21:19 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:19+01:00" level=debug msg="restored session after logout" username="gn*********************59" Jan 09 13:21:19 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 3 Jan 09 13:21:19 volumio-test1 volumio[1296]: info: CoreStateMachine::startPlaybackTimer Jan 09 13:21:19 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 3 Jan 09 13:21:19 volumio-test1 volumio[1296]: info: [1767961279773] ControllerSpotify::clearAddPlayTrack Jan 09 13:21:19 volumio-test1 volumio[1296]: info: Sending Spotify command with payload to local API: /player/play Jan 09 13:21:19 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:19+01:00" level=debug msg="dealer connection opened" Jan 09 13:21:19 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:19+01:00" level=trace msg="starting accesspoint recv loop" Jan 09 13:21:19 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:19+01:00" level=trace msg="starting dealer recv loop" Jan 09 13:21:19 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:19+01:00" level=trace msg="received accesspoint ping" Jan 09 13:21:19 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:19+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jan 09 13:21:19 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:19+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jan 09 13:21:19 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:19+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jan 09 13:21:19 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:19+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jan 09 13:21:19 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:19+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jan 09 13:21:19 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:19+01:00" level=debug msg="received connection id: NjI1NGI2YTUtZmU2...OTU0OUMwNkM0Mw==" Jan 09 13:21:19 volumio-test1 volumio[1296]: info: CoreStateMachine::pushState Jan 09 13:21:19 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 3 Jan 09 13:21:19 volumio-test1 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 09 13:21:19 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:19+01:00" level=trace msg="received accesspoint pong ack" Jan 09 13:21:19 volumio-test1 volumio[1296]: info: CoreCommandRouter::volumioPushState Jan 09 13:21:19 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:19+01:00" level=debug msg="put connect state because NEW_DEVICE" Jan 09 13:21:19 volumio-test1 volumio[1296]: SPOTIFY: RECEIVED VOLUMIO VOLUME 56 Jan 09 13:21:19 volumio-test1 volumio[1296]: SPOTIFY: RECEIVED VOLUMIO VOLUME 56 Jan 09 13:21:19 volumio-test1 volumio[1296]: SPOTIFY: RECEIVED VOLUMIO VOLUME 56 Jan 09 13:21:19 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:19+01:00" level=debug msg="resolved context of track" uri="spotify:track:1u8c2t2Cy7UBoG4ArRcF5g" Jan 09 13:21:19 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:19+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:1u8c2t2Cy7UBoG4ArRcF5g" Jan 09 13:21:19 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:19+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:1u8c2t2Cy7UBoG4ArRcF5g" Jan 09 13:21:19 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:19+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 09 13:21:19 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:19+01:00" level=trace msg="emitting websocket event: will_play" Jan 09 13:21:19 volumio-test1 volumio[1296]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:1u8c2t2Cy7UBoG4ArRcF5g","uri":"spotify:track:1u8c2t2Cy7UBoG4ArRcF5g","play_origin":"go-librespot"}} Jan 09 13:21:20 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:20+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jan 09 13:21:20 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:20+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jan 09 13:21:20 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:20+01:00" level=debug msg="selected format OGG_VORBIS_320 (960f2e110cd91df99527903653f0f8e81befc823)" uri="spotify:track:1u8c2t2Cy7UBoG4ArRcF5g" Jan 09 13:21:20 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:20+01:00" level=debug msg="requested aes key for file 960f2e110cd91df99527903653f0f8e81befc823, gid: 1u8c2t2Cy7UBoG4ArRcF5g" Jan 09 13:21:20 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:20+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1129" Jan 09 13:21:20 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:20+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 411" Jan 09 13:21:20 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:20+01:00" level=trace msg="found 2 cdn urls" uri="spotify:track:1u8c2t2Cy7UBoG4ArRcF5g" Jan 09 13:21:20 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:20+01:00" level=debug msg="fetched first chunk of 20, total size is 10144848 bytes" uri="spotify:track:1u8c2t2Cy7UBoG4ArRcF5g" Jan 09 13:21:20 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:20+01:00" level=debug msg="created new output device" Jan 09 13:21:20 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:20+01:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 100000 us, period size = 4410 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 5 frames, PCM format = FLOAT_LE" Jan 09 13:21:20 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:20+01:00" level=info msg="loaded track \"Blank Space\" (paused: false, position: 0ms, duration: 231826ms, prefetched: false)" uri="spotify:track:1u8c2t2Cy7UBoG4ArRcF5g" Jan 09 13:21:20 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:20+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 09 13:21:20 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:20+01:00" level=trace msg="scheduling prefetch in 202s" Jan 09 13:21:20 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:20+01:00" level=trace msg="emitting websocket event: metadata" Jan 09 13:21:20 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:20+01:00" level=debug msg="fetched chunk 1/19, size: 524288" uri="spotify:track:1u8c2t2Cy7UBoG4ArRcF5g" Jan 09 13:21:20 volumio-test1 volumio[1296]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:1u8c2t2Cy7UBoG4ArRcF5g","name":"Blank Space","artist_names":["Taylor Swift"],"album_name":"1989 (Deluxe)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0252b2a3824413eefe9e33817a","position":0,"duration":231826,"release_date":"year:2014 month:1 day:1","track_number":2,"disc_number":1}} Jan 09 13:21:20 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:20+01:00" level=debug msg="fetched chunk 3/19, size: 524288" uri="spotify:track:1u8c2t2Cy7UBoG4ArRcF5g" Jan 09 13:21:20 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:20+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 09 13:21:20 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:20+01:00" level=trace msg="emitting websocket event: playing" Jan 09 13:21:20 volumio-test1 volumio[1296]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:1u8c2t2Cy7UBoG4ArRcF5g","uri":"spotify:track:1u8c2t2Cy7UBoG4ArRcF5g","resume":false,"play_origin":"go-librespot"}} Jan 09 13:21:20 volumio-test1 volumio[1296]: SPOTIFY: PUSH STATE SPOTIFY Jan 09 13:21:20 volumio-test1 volumio[1296]: SPOTIFY: {"status":"play","service":"spop","title":"Blank Space","artist":"Taylor Swift","album":"1989 (Deluxe)","albumart":"https://i.scdn.co/image/ab67616d00001e0252b2a3824413eefe9e33817a","uri":"spotify:track:1u8c2t2Cy7UBoG4ArRcF5g","trackType":"spotify","seek":0,"duration":231,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 09 13:21:20 volumio-test1 volumio[1296]: info: CoreCommandRouter::servicePushState Jan 09 13:21:20 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 3 Jan 09 13:21:20 volumio-test1 volumio[1296]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Blank Space","artist":"Taylor Swift","album":"1989 (Deluxe)","albumart":"https://i.scdn.co/image/ab67616d00001e0252b2a3824413eefe9e33817a","uri":"spotify:track:1u8c2t2Cy7UBoG4ArRcF5g","trackType":"spotify","seek":0,"duration":231,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 09 13:21:20 volumio-test1 volumio[1296]: verbose: CURRENT POSITION 3 Jan 09 13:21:20 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:20+01:00" level=debug msg="fetched chunk 2/19, size: 524288" uri="spotify:track:1u8c2t2Cy7UBoG4ArRcF5g" Jan 09 13:21:20 volumio-test1 volumio[1296]: info: CoreStateMachine::syncState stateService play Jan 09 13:21:20 volumio-test1 volumio[1296]: info: CoreStateMachine::syncState currentStatus stop Jan 09 13:21:20 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:20+01:00" level=debug msg="skipping dealer message" uri=playback-settings/content-settings-update Jan 09 13:21:20 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:20+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 159" Jan 09 13:21:20 volumio-test1 volumio[1296]: SPOTIFY: PUSH STATE SPOTIFY Jan 09 13:21:20 volumio-test1 volumio[1296]: SPOTIFY: {"status":"play","service":"spop","title":"Blank Space","artist":"Taylor Swift","album":"1989 (Deluxe)","albumart":"https://i.scdn.co/image/ab67616d00001e0252b2a3824413eefe9e33817a","uri":"spotify:track:1u8c2t2Cy7UBoG4ArRcF5g","trackType":"spotify","seek":0,"duration":231,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 09 13:21:20 volumio-test1 volumio[1296]: info: CoreCommandRouter::servicePushState Jan 09 13:21:20 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 3 Jan 09 13:21:20 volumio-test1 volumio[1296]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Blank Space","artist":"Taylor Swift","album":"1989 (Deluxe)","albumart":"https://i.scdn.co/image/ab67616d00001e0252b2a3824413eefe9e33817a","uri":"spotify:track:1u8c2t2Cy7UBoG4ArRcF5g","trackType":"spotify","seek":0,"duration":231,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 09 13:21:20 volumio-test1 volumio[1296]: verbose: CURRENT POSITION 3 Jan 09 13:21:20 volumio-test1 volumio[1296]: info: CoreStateMachine::syncState stateService play Jan 09 13:21:20 volumio-test1 volumio[1296]: info: CoreStateMachine::syncState currentStatus play Jan 09 13:21:20 volumio-test1 volumio[1296]: info: Received an update from plugin. extracting info from payload Jan 09 13:21:20 volumio-test1 volumio[1296]: info: CoreStateMachine::pushState Jan 09 13:21:20 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 3 Jan 09 13:21:20 volumio-test1 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 09 13:21:20 volumio-test1 volumio[1296]: info: CoreCommandRouter::volumioPushState Jan 09 13:21:20 volumio-test1 volumio[1296]: info: CoreStateMachine::pushState Jan 09 13:21:20 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 3 Jan 09 13:21:20 volumio-test1 volumio[1296]: info: CoreCommandRouter::volumioPushState Jan 09 13:21:20 volumio-test1 volumio[1296]: SPOTIFY: RECEIVED VOLUMIO VOLUME 56 Jan 09 13:21:20 volumio-test1 volumio[1296]: SPOTIFY: RECEIVED VOLUMIO VOLUME 56 Jan 09 13:21:21 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:21+01:00" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1EVJHK7Q1TBABQ" Jan 09 13:21:21 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:21+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Jan 09 13:21:26 volumio-test1 wpa_supplicant[1193]: RRM: Ignoring radio measurement request: Not RRM network Jan 09 13:21:27 volumio-test1 volumio[1296]: info: CoreCommandRouter::volumioPause Jan 09 13:21:27 volumio-test1 volumio[1296]: info: CoreStateMachine::pause Jan 09 13:21:27 volumio-test1 volumio[1296]: info: CoreStateMachine::stPlaybackTimer Jan 09 13:21:27 volumio-test1 volumio[1296]: info: CoreStateMachine::servicePause Jan 09 13:21:27 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 3 Jan 09 13:21:27 volumio-test1 volumio[1296]: info: CoreCommandRouter::servicePause Jan 09 13:21:27 volumio-test1 volumio[1296]: info: Spotify Received pause Jan 09 13:21:27 volumio-test1 volumio[1296]: SPOTIFY: SPOTIFY PAUSE Jan 09 13:21:27 volumio-test1 volumio[1296]: SPOTIFY: {"status":"play","position":3,"title":"Blank Space","artist":"Taylor Swift","album":"1989 (Deluxe)","albumart":"https://i.scdn.co/image/ab67616d0000b27352b2a3824413eefe9e33817a","uri":"spotify:track:1u8c2t2Cy7UBoG4ArRcF5g","trackType":"spotify","codec":"ogg","seek":0,"duration":231,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":56,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Jan 09 13:21:27 volumio-test1 volumio[1296]: info: Sending Spotify command to local API: /player/pause Jan 09 13:21:27 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:27+01:00" level=debug msg="pause track at 7529ms" Jan 09 13:21:27 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:27+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 09 13:21:27 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:27+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 09 13:21:27 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:27+01:00" level=trace msg="emitting websocket event: paused" Jan 09 13:21:27 volumio-test1 volumio[1296]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:1u8c2t2Cy7UBoG4ArRcF5g","uri":"spotify:track:1u8c2t2Cy7UBoG4ArRcF5g","play_origin":"go-librespot"}} Jan 09 13:21:27 volumio-test1 volumio[1296]: SPOTIFY: PUSH STATE SPOTIFY Jan 09 13:21:27 volumio-test1 volumio[1296]: SPOTIFY: {"status":"pause","service":"spop","title":"Blank Space","artist":"Taylor Swift","album":"1989 (Deluxe)","albumart":"https://i.scdn.co/image/ab67616d00001e0252b2a3824413eefe9e33817a","uri":"spotify:track:1u8c2t2Cy7UBoG4ArRcF5g","trackType":"spotify","seek":7000,"duration":231,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 09 13:21:27 volumio-test1 volumio[1296]: info: CoreCommandRouter::servicePushState Jan 09 13:21:27 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 3 Jan 09 13:21:27 volumio-test1 volumio[1296]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Blank Space","artist":"Taylor Swift","album":"1989 (Deluxe)","albumart":"https://i.scdn.co/image/ab67616d00001e0252b2a3824413eefe9e33817a","uri":"spotify:track:1u8c2t2Cy7UBoG4ArRcF5g","trackType":"spotify","seek":7000,"duration":231,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 09 13:21:27 volumio-test1 volumio[1296]: verbose: CURRENT POSITION 3 Jan 09 13:21:27 volumio-test1 volumio[1296]: info: CoreStateMachine::syncState stateService pause Jan 09 13:21:27 volumio-test1 volumio[1296]: info: CoreStateMachine::syncState currentStatus pause Jan 09 13:21:27 volumio-test1 volumio[1296]: info: CoreStateMachine::pushState Jan 09 13:21:27 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 3 Jan 09 13:21:27 volumio-test1 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 09 13:21:27 volumio-test1 volumio[1296]: info: CoreCommandRouter::volumioPushState Jan 09 13:21:27 volumio-test1 volumio[1296]: info: CoreStateMachine::stPlaybackTimer Jan 09 13:21:27 volumio-test1 volumio[1296]: SPOTIFY: RECEIVED VOLUMIO VOLUME 56 Jan 09 13:21:28 volumio-test1 wpa_supplicant[1193]: RRM: Ignoring radio measurement request: Not RRM network Jan 09 13:21:30 volumio-test1 wpa_supplicant[1193]: RRM: Ignoring radio measurement request: Not RRM network Jan 09 13:21:33 volumio-test1 wpa_supplicant[1193]: RRM: Ignoring radio measurement request: Not RRM network Jan 09 13:21:33 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:33+01:00" level=debug msg="handling resume player command from dbacd9fcc56cd2d7840f8740d5f3140530247a5c" Jan 09 13:21:33 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:33+01:00" level=trace msg="seek to 7529ms (diff: 112ms, samples: 332028, bytes: 272105)" uri="spotify:track:1u8c2t2Cy7UBoG4ArRcF5g" Jan 09 13:21:33 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:33+01:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 100000 us, period size = 4410 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 5 frames, PCM format = FLOAT_LE" Jan 09 13:21:33 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:33+01:00" level=debug msg="resume track at 7417ms" Jan 09 13:21:33 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:33+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 09 13:21:33 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:33+01:00" level=trace msg="scheduling prefetch in 194s" Jan 09 13:21:33 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:33+01:00" level=debug msg="sending successful reply for dealer request" Jan 09 13:21:33 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:33+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 09 13:21:33 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:33+01:00" level=trace msg="emitting websocket event: playing" Jan 09 13:21:33 volumio-test1 volumio[1296]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:1u8c2t2Cy7UBoG4ArRcF5g","uri":"spotify:track:1u8c2t2Cy7UBoG4ArRcF5g","resume":true,"play_origin":"go-librespot"}} Jan 09 13:21:33 volumio-test1 volumio[1296]: SPOTIFY: PUSH STATE SPOTIFY Jan 09 13:21:33 volumio-test1 volumio[1296]: SPOTIFY: {"status":"play","service":"spop","title":"Blank Space","artist":"Taylor Swift","album":"1989 (Deluxe)","albumart":"https://i.scdn.co/image/ab67616d00001e0252b2a3824413eefe9e33817a","uri":"spotify:track:1u8c2t2Cy7UBoG4ArRcF5g","trackType":"spotify","seek":7000,"duration":231,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 09 13:21:33 volumio-test1 volumio[1296]: info: CoreCommandRouter::servicePushState Jan 09 13:21:33 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 3 Jan 09 13:21:33 volumio-test1 volumio[1296]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Blank Space","artist":"Taylor Swift","album":"1989 (Deluxe)","albumart":"https://i.scdn.co/image/ab67616d00001e0252b2a3824413eefe9e33817a","uri":"spotify:track:1u8c2t2Cy7UBoG4ArRcF5g","trackType":"spotify","seek":7000,"duration":231,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 09 13:21:33 volumio-test1 volumio[1296]: verbose: CURRENT POSITION 3 Jan 09 13:21:33 volumio-test1 volumio[1296]: info: CoreStateMachine::syncState stateService play Jan 09 13:21:33 volumio-test1 volumio[1296]: info: CoreStateMachine::syncState currentStatus pause Jan 09 13:21:33 volumio-test1 volumio[1296]: info: CoreStateMachine::pushState Jan 09 13:21:33 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 3 Jan 09 13:21:33 volumio-test1 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 09 13:21:33 volumio-test1 volumio[1296]: info: CoreCommandRouter::volumioPushState Jan 09 13:21:33 volumio-test1 volumio[1296]: SPOTIFY: RECEIVED VOLUMIO VOLUME 56 Jan 09 13:21:33 volumio-test1 volumio[1296]: SPOTIFY: PUSH STATE SPOTIFY Jan 09 13:21:33 volumio-test1 volumio[1296]: SPOTIFY: {"status":"play","service":"spop","title":"Blank Space","artist":"Taylor Swift","album":"1989 (Deluxe)","albumart":"https://i.scdn.co/image/ab67616d00001e0252b2a3824413eefe9e33817a","uri":"spotify:track:1u8c2t2Cy7UBoG4ArRcF5g","trackType":"spotify","seek":7000,"duration":231,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 09 13:21:33 volumio-test1 volumio[1296]: info: CoreCommandRouter::servicePushState Jan 09 13:21:33 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 3 Jan 09 13:21:33 volumio-test1 volumio[1296]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Blank Space","artist":"Taylor Swift","album":"1989 (Deluxe)","albumart":"https://i.scdn.co/image/ab67616d00001e0252b2a3824413eefe9e33817a","uri":"spotify:track:1u8c2t2Cy7UBoG4ArRcF5g","trackType":"spotify","seek":7000,"duration":231,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 09 13:21:33 volumio-test1 volumio[1296]: verbose: CURRENT POSITION 3 Jan 09 13:21:33 volumio-test1 volumio[1296]: info: CoreStateMachine::syncState stateService play Jan 09 13:21:33 volumio-test1 volumio[1296]: info: CoreStateMachine::syncState currentStatus play Jan 09 13:21:33 volumio-test1 volumio[1296]: info: Received an update from plugin. extracting info from payload Jan 09 13:21:33 volumio-test1 volumio[1296]: info: CoreStateMachine::pushState Jan 09 13:21:33 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 3 Jan 09 13:21:33 volumio-test1 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 09 13:21:33 volumio-test1 volumio[1296]: info: CoreCommandRouter::volumioPushState Jan 09 13:21:33 volumio-test1 volumio[1296]: info: CoreStateMachine::pushState Jan 09 13:21:33 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 3 Jan 09 13:21:33 volumio-test1 volumio[1296]: info: CoreCommandRouter::volumioPushState Jan 09 13:21:33 volumio-test1 volumio[1296]: SPOTIFY: RECEIVED VOLUMIO VOLUME 56 Jan 09 13:21:33 volumio-test1 volumio[1296]: SPOTIFY: RECEIVED VOLUMIO VOLUME 56 Jan 09 13:21:35 volumio-test1 wpa_supplicant[1193]: RRM: Ignoring radio measurement request: Not RRM network Jan 09 13:21:37 volumio-test1 wpa_supplicant[1193]: RRM: Ignoring radio measurement request: Not RRM network Jan 09 13:21:38 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:38+01:00" level=info msg="playback was transferred to S24 von Tobias" Jan 09 13:21:38 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:38+01:00" level=trace msg="closed output device because of stop command" Jan 09 13:21:38 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:38+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jan 09 13:21:38 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:38+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jan 09 13:21:38 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:38+01:00" level=debug msg="put connect state inactive" Jan 09 13:21:38 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:38+01:00" level=trace msg="emitting websocket event: inactive" Jan 09 13:21:38 volumio-test1 volumio[1296]: SPOTIFY: received: {"type":"inactive","data":null} Jan 09 13:21:38 volumio-test1 volumio[1296]: error: Failed to decode event: inactive Jan 09 13:21:38 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:38+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 370" Jan 09 13:21:38 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:38+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1100" Jan 09 13:21:38 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:38+01:00" level=debug msg="dealer connection closed" Jan 09 13:21:38 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:38+01:00" level=debug msg="dealer recv loop stopped" Jan 09 13:21:38 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:38+01:00" level=debug msg="obtained new client token: AABv1CcQ2Q162dTKFotLyUplxIA73PVVP9xHDqKP46zBUJ2d6ruvv3Hy9mvghQ9XK29MJbP5aF0+4XsllGtYEZ7vmywJ//xzWFUHZbSb0HWSiibKNpOZoqrTteKjWIRq1oXSg/CMigpzJnSIeIzZbnH5Cc2cFP/dEm/+50Z0ilU7g89azFbXXyPpzcj0Rl8BNI4/2FiUJl92whZPS9z2qBfE0KDUEq/9kXtTGLMXpTySTNAl1gq+LA==" Jan 09 13:21:38 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:38+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Jan 09 13:21:38 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:38+01:00" level=debug msg="completed keyexchange" Jan 09 13:21:38 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:38+01:00" level=debug msg="completed challenge" Jan 09 13:21:38 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:38+01:00" level=info msg="authenticated AP" username="gn*********************59" Jan 09 13:21:38 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:38+01:00" level=info msg="authenticated Login5" username="gn*********************59" Jan 09 13:21:38 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:38+01:00" level=debug msg="restored session after logout" username="gn*********************59" Jan 09 13:21:38 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:38+01:00" level=debug msg="dealer connection opened" Jan 09 13:21:38 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:38+01:00" level=trace msg="starting accesspoint recv loop" Jan 09 13:21:38 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:38+01:00" level=trace msg="starting dealer recv loop" Jan 09 13:21:38 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:38+01:00" level=trace msg="received accesspoint ping" Jan 09 13:21:38 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:38+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jan 09 13:21:38 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:38+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jan 09 13:21:38 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:38+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jan 09 13:21:38 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:38+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jan 09 13:21:38 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:38+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jan 09 13:21:38 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:38+01:00" level=debug msg="received connection id: NTZhYjlmMjYtODU2...MkNFRTQ0NDUxMg==" Jan 09 13:21:38 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:38+01:00" level=trace msg="received accesspoint pong ack" Jan 09 13:21:38 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:38+01:00" level=debug msg="put connect state because NEW_DEVICE" Jan 09 13:21:39 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:39+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jan 09 13:21:39 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:39+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jan 09 13:21:40 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:40+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 464" Jan 09 13:21:40 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:40+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1194" Jan 09 13:21:45 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:45+01:00" level=debug msg="handling transfer player command from dbacd9fcc56cd2d7840f8740d5f3140530247a5c" Jan 09 13:21:45 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:45+01:00" level=debug msg="resolved context of track" uri="spotify:track:1u8c2t2Cy7UBoG4ArRcF5g" Jan 09 13:21:45 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:45+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:1u8c2t2Cy7UBoG4ArRcF5g" Jan 09 13:21:45 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:45+01:00" level=debug msg="loading track (paused: false, position: 14599ms)" uri="spotify:track:1u8c2t2Cy7UBoG4ArRcF5g" Jan 09 13:21:45 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:45+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 09 13:21:45 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:45+01:00" level=trace msg="emitting websocket event: will_play" Jan 09 13:21:45 volumio-test1 volumio[1296]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:1u8c2t2Cy7UBoG4ArRcF5g","uri":"spotify:track:1u8c2t2Cy7UBoG4ArRcF5g","play_origin":"go-librespot"}} Jan 09 13:21:45 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:45+01:00" level=debug msg="selected format OGG_VORBIS_320 (960f2e110cd91df99527903653f0f8e81befc823)" uri="spotify:track:1u8c2t2Cy7UBoG4ArRcF5g" Jan 09 13:21:45 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:45+01:00" level=debug msg="requested aes key for file 960f2e110cd91df99527903653f0f8e81befc823, gid: 1u8c2t2Cy7UBoG4ArRcF5g" Jan 09 13:21:45 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:45+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1129" Jan 09 13:21:45 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:45+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 411" Jan 09 13:21:45 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:45+01:00" level=trace msg="found 2 cdn urls" uri="spotify:track:1u8c2t2Cy7UBoG4ArRcF5g" Jan 09 13:21:45 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:45+01:00" level=debug msg="fetched first chunk of 20, total size is 10144848 bytes" uri="spotify:track:1u8c2t2Cy7UBoG4ArRcF5g" Jan 09 13:21:45 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:45+01:00" level=debug msg="fetched chunk 3/19, size: 524288" uri="spotify:track:1u8c2t2Cy7UBoG4ArRcF5g" Jan 09 13:21:45 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:45+01:00" level=debug msg="fetched chunk 2/19, size: 524288" uri="spotify:track:1u8c2t2Cy7UBoG4ArRcF5g" Jan 09 13:21:45 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:45+01:00" level=debug msg="fetched chunk 4/19, size: 524288" uri="spotify:track:1u8c2t2Cy7UBoG4ArRcF5g" Jan 09 13:21:45 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:45+01:00" level=debug msg="fetched chunk 1/19, size: 524288" uri="spotify:track:1u8c2t2Cy7UBoG4ArRcF5g" Jan 09 13:21:45 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:45+01:00" level=trace msg="seek to 14599ms (diff: 86ms, samples: 643815, bytes: 565073)" uri="spotify:track:1u8c2t2Cy7UBoG4ArRcF5g" Jan 09 13:21:45 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:45+01:00" level=debug msg="created new output device" Jan 09 13:21:45 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:45+01:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 100000 us, period size = 4410 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 5 frames, PCM format = FLOAT_LE" Jan 09 13:21:45 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:45+01:00" level=info msg="loaded track \"Blank Space\" (paused: false, position: 14599ms, duration: 231826ms, prefetched: false)" uri="spotify:track:1u8c2t2Cy7UBoG4ArRcF5g" Jan 09 13:21:45 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:45+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 09 13:21:45 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:45+01:00" level=trace msg="scheduling prefetch in 187s" Jan 09 13:21:45 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:45+01:00" level=trace msg="emitting websocket event: metadata" Jan 09 13:21:45 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:45+01:00" level=trace msg="emitting websocket event: active" Jan 09 13:21:45 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:45+01:00" level=debug msg="sending successful reply for dealer request" Jan 09 13:21:45 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:45+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jan 09 13:21:45 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:45+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jan 09 13:21:45 volumio-test1 volumio[1296]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:1u8c2t2Cy7UBoG4ArRcF5g","name":"Blank Space","artist_names":["Taylor Swift"],"album_name":"1989 (Deluxe)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0252b2a3824413eefe9e33817a","position":14599,"duration":231826,"release_date":"year:2014 month:1 day:1","track_number":2,"disc_number":1}} Jan 09 13:21:45 volumio-test1 volumio[1296]: SPOTIFY: received: {"type":"active","data":null} Jan 09 13:21:45 volumio-test1 volumio[1296]: info: Aligning Spotify Volume to Volumio Volume Jan 09 13:21:45 volumio-test1 volumio[1296]: info: CoreCommandRouter::volumioGetState Jan 09 13:21:45 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 3 Jan 09 13:21:45 volumio-test1 volumio[1296]: info: Setting Spotify Volume from Volumio: 56 Jan 09 13:21:45 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:45+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 09 13:21:45 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:45+01:00" level=trace msg="emitting websocket event: playing" Jan 09 13:21:45 volumio-test1 volumio[1296]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:1u8c2t2Cy7UBoG4ArRcF5g","uri":"spotify:track:1u8c2t2Cy7UBoG4ArRcF5g","resume":false,"play_origin":"go-librespot"}} Jan 09 13:21:45 volumio-test1 volumio[1296]: SPOTIFY: PUSH STATE SPOTIFY Jan 09 13:21:45 volumio-test1 volumio[1296]: SPOTIFY: {"status":"play","service":"spop","title":"Blank Space","artist":"Taylor Swift","album":"1989 (Deluxe)","albumart":"https://i.scdn.co/image/ab67616d00001e0252b2a3824413eefe9e33817a","uri":"spotify:track:1u8c2t2Cy7UBoG4ArRcF5g","trackType":"spotify","seek":14599,"duration":231,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 09 13:21:45 volumio-test1 volumio[1296]: info: CoreCommandRouter::servicePushState Jan 09 13:21:45 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 3 Jan 09 13:21:45 volumio-test1 volumio[1296]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Blank Space","artist":"Taylor Swift","album":"1989 (Deluxe)","albumart":"https://i.scdn.co/image/ab67616d00001e0252b2a3824413eefe9e33817a","uri":"spotify:track:1u8c2t2Cy7UBoG4ArRcF5g","trackType":"spotify","seek":14599,"duration":231,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 09 13:21:45 volumio-test1 volumio[1296]: verbose: CURRENT POSITION 3 Jan 09 13:21:45 volumio-test1 volumio[1296]: info: CoreStateMachine::syncState stateService play Jan 09 13:21:45 volumio-test1 volumio[1296]: info: CoreStateMachine::syncState currentStatus play Jan 09 13:21:45 volumio-test1 volumio[1296]: info: Received an update from plugin. extracting info from payload Jan 09 13:21:45 volumio-test1 volumio[1296]: info: CoreStateMachine::pushState Jan 09 13:21:45 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 3 Jan 09 13:21:45 volumio-test1 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 09 13:21:45 volumio-test1 volumio[1296]: info: CoreCommandRouter::volumioPushState Jan 09 13:21:45 volumio-test1 volumio[1296]: info: CoreStateMachine::pushState Jan 09 13:21:45 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 3 Jan 09 13:21:45 volumio-test1 volumio[1296]: info: CoreCommandRouter::volumioPushState Jan 09 13:21:46 volumio-test1 volumio[1296]: SPOTIFY: RECEIVED VOLUMIO VOLUME 56 Jan 09 13:21:46 volumio-test1 volumio[1296]: SPOTIFY: RECEIVED VOLUMIO VOLUME 56 Jan 09 13:21:46 volumio-test1 volumio[1296]: SPOTIFY: PUSH STATE SPOTIFY Jan 09 13:21:46 volumio-test1 volumio[1296]: SPOTIFY: {"status":"play","service":"spop","title":"Blank Space","artist":"Taylor Swift","album":"1989 (Deluxe)","albumart":"https://i.scdn.co/image/ab67616d00001e0252b2a3824413eefe9e33817a","uri":"spotify:track:1u8c2t2Cy7UBoG4ArRcF5g","trackType":"spotify","seek":14599,"duration":231,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 09 13:21:46 volumio-test1 volumio[1296]: info: CoreCommandRouter::servicePushState Jan 09 13:21:46 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 3 Jan 09 13:21:46 volumio-test1 volumio[1296]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Blank Space","artist":"Taylor Swift","album":"1989 (Deluxe)","albumart":"https://i.scdn.co/image/ab67616d00001e0252b2a3824413eefe9e33817a","uri":"spotify:track:1u8c2t2Cy7UBoG4ArRcF5g","trackType":"spotify","seek":14599,"duration":231,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 09 13:21:46 volumio-test1 volumio[1296]: verbose: CURRENT POSITION 3 Jan 09 13:21:46 volumio-test1 volumio[1296]: info: CoreStateMachine::syncState stateService play Jan 09 13:21:46 volumio-test1 volumio[1296]: info: CoreStateMachine::syncState currentStatus play Jan 09 13:21:46 volumio-test1 volumio[1296]: info: Received an update from plugin. extracting info from payload Jan 09 13:21:46 volumio-test1 volumio[1296]: info: CoreStateMachine::pushState Jan 09 13:21:46 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 3 Jan 09 13:21:46 volumio-test1 volumio[1296]: info: CoreCommandRouter::volumioPushState Jan 09 13:21:46 volumio-test1 volumio[1296]: info: CoreStateMachine::pushState Jan 09 13:21:46 volumio-test1 volumio[1296]: info: CorePlayQueue::getTrack 3 Jan 09 13:21:46 volumio-test1 volumio[1296]: info: CoreCommandRouter::volumioPushState Jan 09 13:21:46 volumio-test1 volumio[1296]: SPOTIFY: RECEIVED VOLUMIO VOLUME 56 Jan 09 13:21:46 volumio-test1 volumio[1296]: SPOTIFY: RECEIVED VOLUMIO VOLUME 56 Jan 09 13:21:47 volumio-test1 volumio[1296]: SPOTIFY: SETTING SPOTIFY VOLUME 56 Jan 09 13:21:47 volumio-test1 volumio[1296]: info: Sending Spotify command with payload to local API: /player/volume Jan 09 13:21:47 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:47+01:00" level=debug msg="update volume requested to 36699/65535" Jan 09 13:21:47 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:47+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Jan 09 13:21:47 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:47+01:00" level=trace msg="emitting websocket event: volume" Jan 09 13:21:47 volumio-test1 volumio[1296]: SPOTIFY: received: {"type":"volume","data":{"value":56,"max":100}} Jan 09 13:21:47 volumio-test1 volumio[1296]: SPOTIFY: RECEIVED SPOTIFY VOLUME 56 Jan 09 13:21:56 volumio-test1 go-librespot[1683]: time="2026-01-09T13:21:56+01:00" level=debug msg="fetched chunk 5/19, size: 524288" uri="spotify:track:1u8c2t2Cy7UBoG4ArRcF5g" Jan 09 13:22:08 volumio-test1 go-librespot[1683]: time="2026-01-09T13:22:08+01:00" level=trace msg="sent dealer ping" Jan 09 13:22:08 volumio-test1 go-librespot[1683]: time="2026-01-09T13:22:08+01:00" level=trace msg="received dealer pong" Jan 09 13:22:08 volumio-test1 go-librespot[1683]: time="2026-01-09T13:22:08+01:00" level=debug msg="fetched chunk 6/19, size: 524288" uri="spotify:track:1u8c2t2Cy7UBoG4ArRcF5g" Jan 09 13:22:14 volumio-test1 volumio[1296]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 09 13:22:14 volumio-test1 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jan 09 13:22:14 volumio-test1 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jan 09 13:22:14 volumio-test1 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jan 09 13:22:14 volumio-test1 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableUIs Jan 09 13:22:14 volumio-test1 volumio[1296]: info: Received Get System Version Jan 09 13:22:14 volumio-test1 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 09 13:22:19 volumio-test1 go-librespot[1683]: time="2026-01-09T13:22:19+01:00" level=debug msg="fetched chunk 7/19, size: 524288" uri="spotify:track:1u8c2t2Cy7UBoG4ArRcF5g" Jan 09 13:22:27 volumio-test1 volumio[1296]: info: CALLMETHOD: system_controller system saveGeneralSettings [object Object] Jan 09 13:22:27 volumio-test1 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: system , saveGeneralSettings Jan 09 13:22:27 volumio-test1 volumio[1296]: info: System name has changed, restarting Shairport Sync Jan 09 13:22:27 volumio-test1 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 09 13:22:27 volumio-test1 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 09 13:22:27 volumio-test1 volumio[1296]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 09 13:22:27 volumio-test1 volumio[1296]: info: Updating MyVolumio device info Jan 09 13:22:27 volumio-test1 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 09 13:22:27 volumio-test1 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 09 13:22:27 volumio-test1 volumio[1296]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 09 13:22:27 volumio-test1 volumio[1296]: info: Discovery: Restarting Advertising due to device name change Jan 09 13:22:27 volumio-test1 sudo[2288]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/killall upmpdcli Jan 09 13:22:27 volumio-test1 sudo[2288]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 13:22:27 volumio-test1 volumio[1296]: info: Starting Shairport Sync Jan 09 13:22:27 volumio-test1 sudo[2290]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/hosts Jan 09 13:22:27 volumio-test1 sudo[2288]: pam_unix(sudo:session): session closed for user root Jan 09 13:22:27 volumio-test1 sudo[2293]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 09 13:22:27 volumio-test1 sudo[2293]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 13:22:27 volumio-test1 sudo[2290]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 13:22:27 volumio-test1 sudo[2290]: pam_unix(sudo:session): session closed for user root Jan 09 13:22:27 volumio-test1 volumio[1296]: info: Permissions for /etc/hosts set Jan 09 13:22:27 volumio-test1 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 09 13:22:27 volumio-test1 systemd[1]: shairport-sync.service: Deactivated successfully. Jan 09 13:22:27 volumio-test1 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 09 13:22:27 volumio-test1 systemd[1]: shairport-sync.service: Consumed 1.872s CPU time. Jan 09 13:22:27 volumio-test1 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 09 13:22:27 volumio-test1 sudo[2293]: pam_unix(sudo:session): session closed for user root Jan 09 13:22:27 volumio-test1 sudo[2298]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/hostname hifiberry Jan 09 13:22:27 volumio-test1 sudo[2298]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 13:22:27 hifiberry sudo[2298]: pam_unix(sudo:session): session closed for user root Jan 09 13:22:27 hifiberry volumio[1296]: info: New hostname set Jan 09 13:22:27 hifiberry volumio[1296]: info: Shairport-Sync Started Jan 09 13:22:27 hifiberry volumio[1296]: info: Hostname now is hifiberry Jan 09 13:22:27 hifiberry volumio[1296]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jan 09 13:22:27 hifiberry sudo[2315]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /etc/avahi/services/ Jan 09 13:22:27 hifiberry sudo[2315]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 13:22:27 hifiberry sudo[2315]: pam_unix(sudo:session): session closed for user root Jan 09 13:22:27 hifiberry volumio[1296]: info: Permissions for /etc/avahi/services/volumio.service Jan 09 13:22:27 hifiberry upmpdcli[1697]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 09 13:22:27 hifiberry upmpdcli[1697]: :2:../src/ohmetacache.cxx:94::dmcacheSaveWorker: can't get task from queue Jan 09 13:22:27 hifiberry systemd[1]: upmpdcli.service: Deactivated successfully. Jan 09 13:22:27 hifiberry avahi-daemon[1299]: Files changed, reloading. Jan 09 13:22:27 hifiberry avahi-daemon[1299]: Service group file /services/volumio.service changed, reloading. Jan 09 13:22:28 hifiberry volumio[1296]: info: Avahi name changed to hifiberry Jan 09 13:22:28 hifiberry volumio[1296]: info: Discovery: A device disappeared from network Jan 09 13:22:28 hifiberry volumio[1296]: info: Discovery: A device disappeared from network Jan 09 13:22:28 hifiberry avahi-daemon[1299]: Service "HiFiBerry" (/services/volumio.service) successfully established. Jan 09 13:22:31 hifiberry go-librespot[1683]: time="2026-01-09T13:22:31+01:00" level=debug msg="fetched chunk 8/19, size: 524288" uri="spotify:track:1u8c2t2Cy7UBoG4ArRcF5g" Jan 09 13:22:32 hifiberry volumio[1296]: info: Discovery: Started advertising with name: HiFiBerry Jan 09 13:22:33 hifiberry volumio[1296]: compat.c: read() failed: Resource temporarily unavailable Jan 09 13:22:33 hifiberry volumio[1296]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 09 13:22:33 hifiberry volumio[1296]: Error: dns service error: unknown Jan 09 13:22:33 hifiberry volumio[1296]: at MDNSService.self.watcher.callback (/volumio/node_modules/mdns/lib/mdns_service.js:18:40) { Jan 09 13:22:33 hifiberry volumio[1296]: errorCode: -65537 Jan 09 13:22:33 hifiberry volumio[1296]: } Jan 09 13:22:33 hifiberry volumio[1296]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 09 13:22:36 hifiberry sudo[2350]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-09 13:21' Jan 09 13:22:36 hifiberry sudo[2350]: 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="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"