-- Logs begin at Thu 2019-02-14 10:11:59 UTC, end at Fri 2025-06-27 18:21:31 UTC. -- Jun 27 18:20:02 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:02Z" level=trace msg="received accesspoint ping" Jun 27 18:20:02 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:02Z" level=trace msg="received accesspoint pong ack" Jun 27 18:20:02 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:02Z" level=trace msg="sent dealer ping" Jun 27 18:20:02 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:02Z" level=trace msg="received dealer pong" Jun 27 18:20:07 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:07Z" level=debug msg="fetched chunk 21/45, size: 524288" uri="spotify:track:4WNaefp3sGsnTBzHEQb97g" Jun 27 18:20:13 volumiojbs volumio[964]: info: CoreCommandRouter::volumioGetQueue Jun 27 18:20:13 volumiojbs volumio[964]: info: CoreStateMachine::getQueue Jun 27 18:20:13 volumiojbs volumio[964]: info: CorePlayQueue::getQueue Jun 27 18:20:14 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 27 18:20:14 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 27 18:20:14 volumiojbs volumio[964]: info: Discovery: Getting this device information Jun 27 18:20:14 volumiojbs volumio[964]: info: CoreCommandRouter::volumioGetState Jun 27 18:20:14 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 0 Jun 27 18:20:14 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 27 18:20:18 volumiojbs volumio[964]: info: Preload queue cleared Jun 27 18:20:18 volumiojbs volumio[964]: info: CoreCommandRouter::volumioReplaceandPlayItems Jun 27 18:20:18 volumiojbs volumio[964]: info: CoreStateMachine::ClearQueue Jun 27 18:20:18 volumiojbs volumio[964]: info: CoreStateMachine::stop Jun 27 18:20:18 volumiojbs volumio[964]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 27 18:20:18 volumiojbs volumio[964]: info: CoreStateMachine::stPlaybackTimer Jun 27 18:20:18 volumiojbs volumio[964]: info: CoreStateMachine::updateTrackBlock Jun 27 18:20:18 volumiojbs volumio[964]: info: CorePlayQueue::getTrackBlock Jun 27 18:20:18 volumiojbs volumio[964]: info: CoreStateMachine::pushState Jun 27 18:20:18 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 0 Jun 27 18:20:18 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 27 18:20:18 volumiojbs volumio[964]: info: CoreCommandRouter::volumioPushState Jun 27 18:20:18 volumiojbs volumio[964]: info: CoreStateMachine::serviceStop Jun 27 18:20:18 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 0 Jun 27 18:20:18 volumiojbs volumio[964]: info: CoreCommandRouter::serviceStop Jun 27 18:20:18 volumiojbs volumio[964]: info: Spotify Stop Jun 27 18:20:18 volumiojbs volumio[964]: SPOTIFY: SPOTIFY STOP Jun 27 18:20:18 volumiojbs volumio[964]: SPOTIFY: {"status":"play","position":0,"title":"Hello Heaven, Hello","artist":"YUNGBLUD","album":"Idols","albumart":"https://i.scdn.co/image/ab67616d0000b2737808f0d7992027b6b10254dd","uri":"spotify:track:4WNaefp3sGsnTBzHEQb97g","trackType":"spotify","codec":"ogg","seek":1252,"duration":546,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":false,"repeat":false,"repeatSingle":false,"consume":false,"volume":30,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Jun 27 18:20:18 volumiojbs volumio[964]: info: Sending Spotify command to local API: /player/pause Jun 27 18:20:18 volumiojbs volumio[964]: info: CorePlayQueue::clearPlayQueue Jun 27 18:20:18 volumiojbs volumio[964]: info: CorePlayQueue::saveQueue Jun 27 18:20:18 volumiojbs volumio[964]: info: CoreCommandRouter::volumioPushQueue Jun 27 18:20:18 volumiojbs volumio[964]: info: CoreStateMachine::addQueueItems Jun 27 18:20:18 volumiojbs volumio[964]: info: CorePlayQueue::addQueueItems Jun 27 18:20:18 volumiojbs volumio[964]: info: Preload queue cleared Jun 27 18:20:18 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:4WNaefp3sGsnTBzHEQb97g Jun 27 18:20:18 volumiojbs volumio[964]: info: Exploding uri spotify:track:4WNaefp3sGsnTBzHEQb97g in service spop Jun 27 18:20:18 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:4WNaefp3sGsnTBzHEQb97g Jun 27 18:20:18 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:5UJbgR4XF4y1DvbkxEqe8S Jun 27 18:20:18 volumiojbs volumio[964]: info: Exploding uri spotify:track:5UJbgR4XF4y1DvbkxEqe8S in service spop Jun 27 18:20:18 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:5UJbgR4XF4y1DvbkxEqe8S Jun 27 18:20:18 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:3rUGC1vUpkDG9CZFHMur1t Jun 27 18:20:18 volumiojbs volumio[964]: info: Exploding uri spotify:track:3rUGC1vUpkDG9CZFHMur1t in service spop Jun 27 18:20:18 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:3rUGC1vUpkDG9CZFHMur1t Jun 27 18:20:18 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:36gcliMRX1vCpgnrZE3dFZ Jun 27 18:20:18 volumiojbs volumio[964]: info: Exploding uri spotify:track:36gcliMRX1vCpgnrZE3dFZ in service spop Jun 27 18:20:18 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:36gcliMRX1vCpgnrZE3dFZ Jun 27 18:20:18 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:3OfqwyE7RrZrtuxCRixfII Jun 27 18:20:18 volumiojbs volumio[964]: info: Exploding uri spotify:track:3OfqwyE7RrZrtuxCRixfII in service spop Jun 27 18:20:18 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:3OfqwyE7RrZrtuxCRixfII Jun 27 18:20:18 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:6eutgX6jfXAsjTXgQtCtYV Jun 27 18:20:18 volumiojbs volumio[964]: info: Exploding uri spotify:track:6eutgX6jfXAsjTXgQtCtYV in service spop Jun 27 18:20:18 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:6eutgX6jfXAsjTXgQtCtYV Jun 27 18:20:18 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:2p4cYfKQbg8xHXNG4eQaGo Jun 27 18:20:18 volumiojbs volumio[964]: info: Exploding uri spotify:track:2p4cYfKQbg8xHXNG4eQaGo in service spop Jun 27 18:20:18 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:2p4cYfKQbg8xHXNG4eQaGo Jun 27 18:20:18 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:3t4zZ2SxXgQRIhc5N6a6oZ Jun 27 18:20:18 volumiojbs volumio[964]: info: Exploding uri spotify:track:3t4zZ2SxXgQRIhc5N6a6oZ in service spop Jun 27 18:20:18 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:3t4zZ2SxXgQRIhc5N6a6oZ Jun 27 18:20:18 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:0fFMt9cc1EEQDIWLGDcqKd Jun 27 18:20:18 volumiojbs volumio[964]: info: Exploding uri spotify:track:0fFMt9cc1EEQDIWLGDcqKd in service spop Jun 27 18:20:18 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:0fFMt9cc1EEQDIWLGDcqKd Jun 27 18:20:18 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:4l0RmWt52FxpVxMNni6i63 Jun 27 18:20:18 volumiojbs volumio[964]: info: Exploding uri spotify:track:4l0RmWt52FxpVxMNni6i63 in service spop Jun 27 18:20:18 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:4l0RmWt52FxpVxMNni6i63 Jun 27 18:20:18 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:7CmQjA7j6CxyPBkH3tP95W Jun 27 18:20:18 volumiojbs volumio[964]: info: Exploding uri spotify:track:7CmQjA7j6CxyPBkH3tP95W in service spop Jun 27 18:20:18 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:7CmQjA7j6CxyPBkH3tP95W Jun 27 18:20:18 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:0mD1a7haZKdX9I0oPywrMb Jun 27 18:20:18 volumiojbs volumio[964]: info: Exploding uri spotify:track:0mD1a7haZKdX9I0oPywrMb in service spop Jun 27 18:20:18 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:0mD1a7haZKdX9I0oPywrMb Jun 27 18:20:18 volumiojbs volumio[964]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Jun 27 18:20:18 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:18Z" level=debug msg="pause track at 227345ms" Jun 27 18:20:19 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:19Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5UJbgR4XF4y1DvbkxEqe8S","service":"spop","name":"Sports car","artist":"Tate McRae","album":"So Close To What","type":"song","duration":165,"albumart":"https://i.scdn.co/image/ab67616d0000b273ec58cd730a52c5899b947d3e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3OfqwyE7RrZrtuxCRixfII","service":"spop","name":"It's ok I'm ok","artist":"Tate McRae","album":"So Close To What","type":"song","duration":156,"albumart":"https://i.scdn.co/image/ab67616d0000b273de9b9cbdd872ae103d8530c2","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4l0RmWt52FxpVxMNni6i63","service":"spop","name":"you broke me first","artist":"Tate McRae","album":"TOO YOUNG TO BE SAD","type":"song","duration":170,"albumart":"https://i.scdn.co/image/ab67616d0000b2736c2b76e0d78170d577add561","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0mD1a7haZKdX9I0oPywrMb","service":"spop","name":"Air on a G String","artist":"Johann Sebastian Bach","album":"Classic","type":"song","duration":289,"albumart":"https://i.scdn.co/image/ab67616d0000b273574875c8196e704ca79605c7","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:19 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:19Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 27 18:20:19 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:19Z" level=trace msg="emitting websocket event: paused" Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4WNaefp3sGsnTBzHEQb97g","service":"spop","name":"Hello Heaven, Hello","artist":"YUNGBLUD","album":"Idols","type":"song","duration":546,"albumart":"https://i.scdn.co/image/ab67616d0000b2737808f0d7992027b6b10254dd","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:4WNaefp3sGsnTBzHEQb97g","play_origin":"go-librespot"}} Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: PUSH STATE SPOTIFY Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: {"status":"pause","service":"spop","title":"Hello Heaven, Hello","artist":"YUNGBLUD","album":"Idols","albumart":"https://i.scdn.co/image/ab67616d00001e027808f0d7992027b6b10254dd","uri":"spotify:track:4WNaefp3sGsnTBzHEQb97g","trackType":"spotify","seek":227000,"duration":546,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 27 18:20:19 volumiojbs volumio[964]: info: CoreCommandRouter::servicePushState Jun 27 18:20:19 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 0 Jun 27 18:20:19 volumiojbs volumio[964]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Hello Heaven, Hello","artist":"YUNGBLUD","album":"Idols","albumart":"https://i.scdn.co/image/ab67616d00001e027808f0d7992027b6b10254dd","uri":"spotify:track:4WNaefp3sGsnTBzHEQb97g","trackType":"spotify","seek":227000,"duration":546,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 27 18:20:19 volumiojbs volumio[964]: verbose: CURRENT POSITION 0 Jun 27 18:20:19 volumiojbs volumio[964]: info: CoreStateMachine::syncState stateService pause Jun 27 18:20:19 volumiojbs volumio[964]: info: CoreStateMachine::syncState currentStatus stop Jun 27 18:20:19 volumiojbs volumio[964]: info: CoreStateMachine::pushState Jun 27 18:20:19 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 0 Jun 27 18:20:19 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 27 18:20:19 volumiojbs volumio[964]: info: CoreCommandRouter::volumioPushState Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7CmQjA7j6CxyPBkH3tP95W","service":"spop","name":"Dear god","artist":"Tate McRae","album":"So Close To What","type":"song","duration":171,"albumart":"https://i.scdn.co/image/ab67616d0000b273ec58cd730a52c5899b947d3e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3t4zZ2SxXgQRIhc5N6a6oZ","service":"spop","name":"The Funeral","artist":"YUNGBLUD","album":"YUNGBLUD","type":"song","duration":210,"albumart":"https://i.scdn.co/image/ab67616d0000b273661c226e74eeed60652291c0","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6eutgX6jfXAsjTXgQtCtYV","service":"spop","name":"girls girls girls","artist":"FLETCHER","album":"girls girls girls","type":"song","duration":161,"albumart":"https://i.scdn.co/image/ab67616d0000b273df3b152de2710e272ace62cc","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3rUGC1vUpkDG9CZFHMur1t","service":"spop","name":"greedy","artist":"Tate McRae","album":"greedy","type":"song","duration":131,"albumart":"https://i.scdn.co/image/ab67616d0000b27322fd802bc61db666c7c81aa8","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2p4cYfKQbg8xHXNG4eQaGo","service":"spop","name":"Hele Vejen (feat. Mumle)","artist":"Omar","album":"Hele Vejen (feat. Mumle)","type":"song","duration":177,"albumart":"https://i.scdn.co/image/ab67616d0000b27391c479e9cd2f8e147bb564d9","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0fFMt9cc1EEQDIWLGDcqKd","service":"spop","name":"Så længe jeg er sexy.","artist":"Annika","album":"Så længe jeg er sexy.","type":"song","duration":150,"albumart":"https://i.scdn.co/image/ab67616d0000b273dc85dfa0c19ff924d2fdcc23","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:36gcliMRX1vCpgnrZE3dFZ","service":"spop","name":"10:35","artist":"Tiësto","album":"DRIVE","type":"song","duration":172,"albumart":"https://i.scdn.co/image/ab67616d0000b273cf8c47967e5c6bbc7dca5abb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:19 volumiojbs volumio[964]: info: CoreCommandRouter::volumioPushQueue Jun 27 18:20:19 volumiojbs volumio[964]: info: CorePlayQueue::saveQueue Jun 27 18:20:19 volumiojbs volumio[964]: info: CoreStateMachine::updateTrackBlock Jun 27 18:20:19 volumiojbs volumio[964]: info: CorePlayQueue::getTrackBlock Jun 27 18:20:19 volumiojbs volumio[964]: info: CoreCommandRouter::volumioPlay Jun 27 18:20:19 volumiojbs volumio[964]: info: CoreStateMachine::play index 11 Jun 27 18:20:19 volumiojbs volumio[964]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 27 18:20:19 volumiojbs volumio[964]: info: CoreStateMachine::addQueueItems Jun 27 18:20:19 volumiojbs volumio[964]: info: CorePlayQueue::addQueueItems Jun 27 18:20:19 volumiojbs volumio[964]: info: Preload queue cleared Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:0RMqPnXgdZoP6dmvFUZfEP Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:0RMqPnXgdZoP6dmvFUZfEP in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:0RMqPnXgdZoP6dmvFUZfEP Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:29cMQlJXTeUEfl4rKL9gDw Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:29cMQlJXTeUEfl4rKL9gDw in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:29cMQlJXTeUEfl4rKL9gDw Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:44nX7Y9AgkHyinw8RSXOgP Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:44nX7Y9AgkHyinw8RSXOgP in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:44nX7Y9AgkHyinw8RSXOgP Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:7LoyqdrF51XVflrSKFHH1a Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:7LoyqdrF51XVflrSKFHH1a in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:7LoyqdrF51XVflrSKFHH1a Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:0iXvldXRa915oqeJUhnePc Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:0iXvldXRa915oqeJUhnePc in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:0iXvldXRa915oqeJUhnePc Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:1uprWeHo3ZsC8W8Fnox9Z5 Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:1uprWeHo3ZsC8W8Fnox9Z5 in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:1uprWeHo3ZsC8W8Fnox9Z5 Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:20hs5uYcsZa1BsZafOid24 Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:20hs5uYcsZa1BsZafOid24 in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:20hs5uYcsZa1BsZafOid24 Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:25I0HJIvPtmZAT0EbXZ1LK Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:25I0HJIvPtmZAT0EbXZ1LK in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:25I0HJIvPtmZAT0EbXZ1LK Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:262dMH9zpKTYhhGNZQjk4A Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:262dMH9zpKTYhhGNZQjk4A in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:262dMH9zpKTYhhGNZQjk4A Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:3xF2FcXiJjWQUqUYvrp4NT Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:3xF2FcXiJjWQUqUYvrp4NT in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:3xF2FcXiJjWQUqUYvrp4NT Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:5IDTIaKLOF0MDALUVfoipB Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:5IDTIaKLOF0MDALUVfoipB in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:5IDTIaKLOF0MDALUVfoipB Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:5NnIHhNURtKKqRDb3WIXT2 Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:5NnIHhNURtKKqRDb3WIXT2 in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:5NnIHhNURtKKqRDb3WIXT2 Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:5c5nDhtmcaPB2UQa0FWNs7 Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:5c5nDhtmcaPB2UQa0FWNs7 in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:5c5nDhtmcaPB2UQa0FWNs7 Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:7KNmIjcmGJIBrhP2s5Vioe Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:7KNmIjcmGJIBrhP2s5Vioe in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:7KNmIjcmGJIBrhP2s5Vioe Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:7px3lmdf4nzNEMt6zaQ5yJ Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:7px3lmdf4nzNEMt6zaQ5yJ in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:7px3lmdf4nzNEMt6zaQ5yJ Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:065hCOwsPu9rtuTkO4vLjz Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:065hCOwsPu9rtuTkO4vLjz in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:065hCOwsPu9rtuTkO4vLjz Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:11kjd2fjjQGncmBeX74e9a Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:11kjd2fjjQGncmBeX74e9a in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:11kjd2fjjQGncmBeX74e9a Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:2TpZAFpamrkPQcCdQcNjRT Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:2TpZAFpamrkPQcCdQcNjRT in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:2TpZAFpamrkPQcCdQcNjRT Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:2kDApipZtTzjwGfKujcg2z Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:2kDApipZtTzjwGfKujcg2z in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:2kDApipZtTzjwGfKujcg2z Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:3OtJnSQq23fgggHFZAe3w1 Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:3OtJnSQq23fgggHFZAe3w1 in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:3OtJnSQq23fgggHFZAe3w1 Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:3TFtD8GZNw9v6vVWr3hnWy Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:3TFtD8GZNw9v6vVWr3hnWy in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:3TFtD8GZNw9v6vVWr3hnWy Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:3a4PdwwaddhYbZnp0lxqyz Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:3a4PdwwaddhYbZnp0lxqyz in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:3a4PdwwaddhYbZnp0lxqyz Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:1augDsuBVF8F8jBgNrDpbt Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:1augDsuBVF8F8jBgNrDpbt in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:1augDsuBVF8F8jBgNrDpbt Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:4GZt2BpQpWhkEAgmfUrQOu Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:4GZt2BpQpWhkEAgmfUrQOu in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:4GZt2BpQpWhkEAgmfUrQOu Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:4xvEn1vhrF9JbPFWqTXsH4 Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:4xvEn1vhrF9JbPFWqTXsH4 in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:4xvEn1vhrF9JbPFWqTXsH4 Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:51hyZpbJlIgZIaX3TtMxmu Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:51hyZpbJlIgZIaX3TtMxmu in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:51hyZpbJlIgZIaX3TtMxmu Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:541sN2qNfIlllGn9nGOQoC Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:541sN2qNfIlllGn9nGOQoC in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:541sN2qNfIlllGn9nGOQoC Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:2gJ33IwQXrA6zTXD6ztHPz Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:2gJ33IwQXrA6zTXD6ztHPz in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:2gJ33IwQXrA6zTXD6ztHPz Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:2bFGGsScXp2Tu10jKMCKO6 Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:2bFGGsScXp2Tu10jKMCKO6 in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:2bFGGsScXp2Tu10jKMCKO6 Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:2vVLSYsOUNCfN66jTyJsMY Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:2vVLSYsOUNCfN66jTyJsMY in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:2vVLSYsOUNCfN66jTyJsMY Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:2oyUhz61OvaMiKG3hWbvpg Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:2oyUhz61OvaMiKG3hWbvpg in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:2oyUhz61OvaMiKG3hWbvpg Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:0GbSM08heTzfWO39fGKVdo Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:0GbSM08heTzfWO39fGKVdo in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:0GbSM08heTzfWO39fGKVdo Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:0pT6pQ9bfQNee3zDaGBlaO Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:0pT6pQ9bfQNee3zDaGBlaO in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:0pT6pQ9bfQNee3zDaGBlaO Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:23cU3OwfFcrnpkIkwlGp8V Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:23cU3OwfFcrnpkIkwlGp8V in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:23cU3OwfFcrnpkIkwlGp8V Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:5v66VjrhFwSlPqadCrubyb Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:5v66VjrhFwSlPqadCrubyb in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:5v66VjrhFwSlPqadCrubyb Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:03zuGqxMwUFFmCwusq0WKE Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:03zuGqxMwUFFmCwusq0WKE in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:03zuGqxMwUFFmCwusq0WKE Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:0qbFoKlLA7v2ECDJDTXExs Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:0qbFoKlLA7v2ECDJDTXExs in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:0qbFoKlLA7v2ECDJDTXExs Jun 27 18:20:19 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:2QSimeBrPuaCxpGPSCh60C Jun 27 18:20:19 volumiojbs volumio[964]: info: Exploding uri spotify:track:2QSimeBrPuaCxpGPSCh60C in service spop Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: EXPLODING URI:spotify:track:2QSimeBrPuaCxpGPSCh60C Jun 27 18:20:19 volumiojbs volumio[964]: info: CoreStateMachine::stop Jun 27 18:20:19 volumiojbs volumio[964]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 27 18:20:19 volumiojbs volumio[964]: info: CoreStateMachine::play index undefined Jun 27 18:20:19 volumiojbs volumio[964]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 27 18:20:19 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 11 Jun 27 18:20:19 volumiojbs volumio[964]: info: CoreStateMachine::startPlaybackTimer Jun 27 18:20:19 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 11 Jun 27 18:20:19 volumiojbs volumio[964]: info: [1751048419284] ControllerSpotify::clearAddPlayTrack Jun 27 18:20:19 volumiojbs volumio[964]: info: Sending Spotify command with payload to local API: /player/play Jun 27 18:20:19 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:19Z" level=debug msg="resolved context of track" uri="spotify:track:0mD1a7haZKdX9I0oPywrMb" Jun 27 18:20:19 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:19Z" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:0mD1a7haZKdX9I0oPywrMb" Jun 27 18:20:19 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:19Z" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:0mD1a7haZKdX9I0oPywrMb" Jun 27 18:20:19 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:19Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 27 18:20:19 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:19Z" level=trace msg="emitting websocket event: will_play" Jun 27 18:20:19 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:19Z" level=debug msg="selected format OGG_VORBIS_320 (c2217a2e36b9b0310d30b7b4e7a88f868cc5e9e6)" uri="spotify:track:0mD1a7haZKdX9I0oPywrMb" Jun 27 18:20:19 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:19Z" level=debug msg="requested aes key for file c2217a2e36b9b0310d30b7b4e7a88f868cc5e9e6, gid: 0mD1a7haZKdX9I0oPywrMb" Jun 27 18:20:19 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:19Z" level=debug msg="fetched first chunk of 19, total size is 9709545 bytes" uri="spotify:track:0mD1a7haZKdX9I0oPywrMb" Jun 27 18:20:19 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:19Z" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames" Jun 27 18:20:19 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:19Z" level=info msg="loaded track \"Air on a G String\" (paused: false, position: 0ms, duration: 289640ms, prefetched: false)" uri="spotify:track:0mD1a7haZKdX9I0oPywrMb" Jun 27 18:20:19 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:19Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 27 18:20:19 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:19Z" level=trace msg="scheduling prefetch in 260s" Jun 27 18:20:19 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:19Z" level=debug msg="fetched chunk 2/18, size: 524288" uri="spotify:track:0mD1a7haZKdX9I0oPywrMb" Jun 27 18:20:19 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:19Z" level=trace msg="emitting websocket event: metadata" Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:0mD1a7haZKdX9I0oPywrMb","play_origin":"go-librespot"}} Jun 27 18:20:19 volumiojbs volumio[964]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0mD1a7haZKdX9I0oPywrMb","name":"Air on a G String","artist_names":["Johann Sebastian Bach","HAUSER","London Symphony Orchestra","Robert Ziegler"],"album_name":"Classic","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02574875c8196e704ca79605c7","position":0,"duration":289640,"release_date":"year:2020 month:2 day:7","track_number":4,"disc_number":1}} Jun 27 18:20:20 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:20Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 27 18:20:20 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:20Z" level=trace msg="emitting websocket event: playing" Jun 27 18:20:20 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:20Z" level=debug msg="fetched chunk 1/18, size: 524288" uri="spotify:track:0mD1a7haZKdX9I0oPywrMb" Jun 27 18:20:20 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:20Z" level=debug msg="fetched chunk 3/18, size: 524288" uri="spotify:track:0mD1a7haZKdX9I0oPywrMb" Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:0mD1a7haZKdX9I0oPywrMb","play_origin":"go-librespot"}} Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: PUSH STATE SPOTIFY Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: {"status":"play","service":"spop","title":"Air on a G String","artist":"Johann Sebastian Bach, HAUSER, London Symphony Orchestra, Robert Ziegler","album":"Classic","albumart":"https://i.scdn.co/image/ab67616d00001e02574875c8196e704ca79605c7","uri":"spotify:track:0mD1a7haZKdX9I0oPywrMb","trackType":"spotify","seek":0,"duration":289,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 27 18:20:20 volumiojbs volumio[964]: info: CoreCommandRouter::servicePushState Jun 27 18:20:20 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 11 Jun 27 18:20:20 volumiojbs volumio[964]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Air on a G String","artist":"Johann Sebastian Bach, HAUSER, London Symphony Orchestra, Robert Ziegler","album":"Classic","albumart":"https://i.scdn.co/image/ab67616d00001e02574875c8196e704ca79605c7","uri":"spotify:track:0mD1a7haZKdX9I0oPywrMb","trackType":"spotify","seek":0,"duration":289,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 27 18:20:20 volumiojbs volumio[964]: verbose: CURRENT POSITION 11 Jun 27 18:20:20 volumiojbs volumio[964]: info: CoreStateMachine::syncState stateService play Jun 27 18:20:20 volumiojbs volumio[964]: info: CoreStateMachine::syncState currentStatus stop Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:51hyZpbJlIgZIaX3TtMxmu","service":"spop","name":"run for the hills","artist":"Tate McRae","album":"THINK LATER","type":"song","duration":143,"albumart":"https://i.scdn.co/image/ab67616d0000b27377eb7a5b9367de79c3b92a49","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5IDTIaKLOF0MDALUVfoipB","service":"spop","name":"Mandemand","artist":"Mumle","album":"Mumler Ikke","type":"song","duration":170,"albumart":"https://i.scdn.co/image/ab67616d0000b2733397c98effdc469a1f26903e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3a4PdwwaddhYbZnp0lxqyz","service":"spop","name":"breakdown.","artist":"YUNGBLUD","album":"breakdown.","type":"song","duration":163,"albumart":"https://i.scdn.co/image/ab67616d0000b2734a47ccda97f42eef09ac9b4e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7px3lmdf4nzNEMt6zaQ5yJ","service":"spop","name":"SAMMEN","artist":"Marstein","album":"FRIHET I LENKER","type":"song","duration":178,"albumart":"https://i.scdn.co/image/ab67616d0000b27312b3c552fa4643026021b26a","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:25I0HJIvPtmZAT0EbXZ1LK","service":"spop","name":"I Just Want You","artist":"Matthew Crosby","album":"Take Only What You Can Carry in Your Hands","type":"song","duration":192,"albumart":"https://i.scdn.co/image/ab67616d0000b273dedc6ec587d541cc879e8fb8","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5NnIHhNURtKKqRDb3WIXT2","service":"spop","name":"Ung, Dum og Forelsket (feat. Marcus.wav)","artist":"Mumle","album":"Mumler Ikke","type":"song","duration":162,"albumart":"https://i.scdn.co/image/ab67616d0000b2733397c98effdc469a1f26903e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1uprWeHo3ZsC8W8Fnox9Z5","service":"spop","name":"Nabolarm","artist":"Mumle","album":"Mumler Ikke","type":"song","duration":144,"albumart":"https://i.scdn.co/image/ab67616d0000b2733397c98effdc469a1f26903e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2TpZAFpamrkPQcCdQcNjRT","service":"spop","name":"Guess We Lied...","artist":"FLETCHER","album":"Girl Of My Dreams","type":"song","duration":151,"albumart":"https://i.scdn.co/image/ab67616d0000b27354d18b47810756f87282ea43","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0GbSM08heTzfWO39fGKVdo","service":"spop","name":"Hot Killer","artist":"Julia Wolf","album":"Good Thing We Stayed","type":"song","duration":138,"albumart":"https://i.scdn.co/image/ab67616d0000b2736923283094bfd7c5b5482941","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:541sN2qNfIlllGn9nGOQoC","service":"spop","name":"Revolving door","artist":"Tate McRae","album":"So Close To What","type":"song","duration":180,"albumart":"https://i.scdn.co/image/ab67616d0000b273de9b9cbdd872ae103d8530c2","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:29cMQlJXTeUEfl4rKL9gDw","service":"spop","name":"Zolaank","artist":"Marlene Bakker","album":"Oaventuren","type":"song","duration":247,"albumart":"https://i.scdn.co/image/ab67616d0000b273244cd60abbdf3b44afbd08cf","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0pT6pQ9bfQNee3zDaGBlaO","service":"spop","name":"Drukner i os","artist":"Annika","album":"AW","type":"song","duration":147,"albumart":"https://i.scdn.co/image/ab67616d0000b27350972c4de866b940fb7a35a2","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:262dMH9zpKTYhhGNZQjk4A","service":"spop","name":"Canon in D","artist":"Lola Astanova","album":"Canon in D","type":"song","duration":192,"albumart":"https://i.scdn.co/image/ab67616d0000b2738e72efaf318071f71a2b0e02","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0iXvldXRa915oqeJUhnePc","service":"spop","name":"Waarkhanden","artist":"Marlene Bakker","album":"Raif","type":"song","duration":190,"albumart":"https://i.scdn.co/image/ab67616d0000b273b58cda6e7d799666cf179e2e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5v66VjrhFwSlPqadCrubyb","service":"spop","name":"Vertigo","artist":"Griff","album":"Vertigo","type":"song","duration":179,"albumart":"https://i.scdn.co/image/ab67616d0000b273961e1590a2f35c12814c9f8f","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2bFGGsScXp2Tu10jKMCKO6","service":"spop","name":"Figure You Out","artist":"VOILÀ","album":"Long Story Short","type":"song","duration":163,"albumart":"https://i.scdn.co/image/ab67616d0000b273dd7bd7afe1756edff721d273","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0RMqPnXgdZoP6dmvFUZfEP","service":"spop","name":"Der så meget jeg ikke fortæller","artist":"Annika","album":"AW","type":"song","duration":184,"albumart":"https://i.scdn.co/image/ab67616d0000b27350972c4de866b940fb7a35a2","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:065hCOwsPu9rtuTkO4vLjz","service":"spop","name":"Shh...Don't Say It","artist":"FLETCHER","album":"THE S(EX) TAPES [Extended]","type":"song","duration":168,"albumart":"https://i.scdn.co/image/ab67616d0000b273fc7a4716843bf6768776a537","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:03zuGqxMwUFFmCwusq0WKE","service":"spop","name":"feel like shit","artist":"Tate McRae","album":"i used to think i could fly","type":"song","duration":203,"albumart":"https://i.scdn.co/image/ab67616d0000b273f7108342ef45a402af8206b2","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:23cU3OwfFcrnpkIkwlGp8V","service":"spop","name":"Start på ny","artist":"Annika","album":"AW","type":"song","duration":168,"albumart":"https://i.scdn.co/image/ab67616d0000b27350972c4de866b940fb7a35a2","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2QSimeBrPuaCxpGPSCh60C","service":"spop","name":"Something Blue","artist":"VOILÀ","album":"Glass Half Empty (Part I)","type":"song","duration":186,"albumart":"https://i.scdn.co/image/ab67616d0000b2737be2416414e6ed67de980b41","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:20hs5uYcsZa1BsZafOid24","service":"spop","name":"I Ain't Gay","artist":"Biscuit Beats","album":"Nature's Ignition","type":"song","duration":124,"albumart":"https://i.scdn.co/image/ab67616d0000b2734e6d4b04614202f0452f2e20","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2vVLSYsOUNCfN66jTyJsMY","service":"spop","name":"Becky's So Hot","artist":"FLETCHER","album":"Girl Of My Dreams","type":"song","duration":162,"albumart":"https://i.scdn.co/image/ab67616d0000b27354d18b47810756f87282ea43","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5c5nDhtmcaPB2UQa0FWNs7","service":"spop","name":"Witte wieven","artist":"Marlene Bakker","album":"Oaventuren","type":"song","duration":212,"albumart":"https://i.scdn.co/image/ab67616d0000b273244cd60abbdf3b44afbd08cf","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3TFtD8GZNw9v6vVWr3hnWy","service":"spop","name":"fleabag","artist":"YUNGBLUD","album":"fleabag","type":"song","duration":176,"albumart":"https://i.scdn.co/image/ab67616d0000b27337987c1e5d9fd568880409e4","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3xF2FcXiJjWQUqUYvrp4NT","service":"spop","name":"all my friends are fake","artist":"Tate McRae","album":"all the things i never said","type":"song","duration":186,"albumart":"https://i.scdn.co/image/ab67616d0000b273cdfe41cd475f8ad3a29b3537","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7LoyqdrF51XVflrSKFHH1a","service":"spop","name":"greedy acoustic","artist":"Tate McRae","album":"greedy (remixes)","type":"song","duration":142,"albumart":"https://i.scdn.co/image/ab67616d0000b2731a560c8283bd88cbebfd0d01","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2gJ33IwQXrA6zTXD6ztHPz","service":"spop","name":"I Can't See You Coming Back","artist":"Matthew Crosby","album":"We're All Still Friends - Vol. 1","type":"song","duration":207,"albumart":"https://i.scdn.co/image/ab67616d0000b273fe72228d730a6a3d43e7d91b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4GZt2BpQpWhkEAgmfUrQOu","service":"spop","name":"Luk Mig Ind","artist":"Annika","album":"Luk Mig Ind","type":"song","duration":197,"albumart":"https://i.scdn.co/image/ab67616d0000b2732c15a900c296d04195eeed9a","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:11kjd2fjjQGncmBeX74e9a","service":"spop","name":"Knuser Hjerter (Youngmammmi Sound)","artist":"Annika","album":"Knuser Hjerter","type":"song","duration":250,"albumart":"https://i.scdn.co/image/ab67616d0000b273266993e4d6b4da9ed2d2b2ba","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4xvEn1vhrF9JbPFWqTXsH4","service":"spop","name":"I know love (feat. The Kid LAROI)","artist":"Tate McRae","album":"So Close To What","type":"song","duration":156,"albumart":"https://i.scdn.co/image/ab67616d0000b273de9b9cbdd872ae103d8530c2","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:44nX7Y9AgkHyinw8RSXOgP","service":"spop","name":"Maybe I Am","artist":"FLETCHER","album":"In Search Of The Antidote","type":"song","duration":164,"albumart":"https://i.scdn.co/image/ab67616d0000b273472962e709e40dedafb9c099","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7KNmIjcmGJIBrhP2s5Vioe","service":"spop","name":"Born Again (feat. Doja Cat & RAYE)","artist":"LISA","album":"Alter Ego","type":"song","duration":231,"albumart":"https://i.scdn.co/image/ab67616d0000b2738034090e4afb5b053cd3e067","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2kDApipZtTzjwGfKujcg2z","service":"spop","name":"Lowlife","artist":"YUNGBLUD","album":"Lowlife","type":"song","duration":233,"albumart":"https://i.scdn.co/image/ab67616d0000b273df5bd10ce6f6fc2723f892b4","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0qbFoKlLA7v2ECDJDTXExs","service":"spop","name":"Eras Of Us","artist":"FLETCHER","album":"In Search Of The Antidote","type":"song","duration":168,"albumart":"https://i.scdn.co/image/ab67616d0000b273472962e709e40dedafb9c099","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2oyUhz61OvaMiKG3hWbvpg","service":"spop","name":"Healing","artist":"FLETCHER","album":"Girl Of My Dreams (Deluxe)","type":"song","duration":187,"albumart":"https://i.scdn.co/image/ab67616d0000b2736e0d8199637baad3e4ce6615","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3OtJnSQq23fgggHFZAe3w1","service":"spop","name":"Fra Jylland til København","artist":"Mumle","album":"Mumler Ikke","type":"song","duration":166,"albumart":"https://i.scdn.co/image/ab67616d0000b2733397c98effdc469a1f26903e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1augDsuBVF8F8jBgNrDpbt","service":"spop","name":"Mennesker Nok","artist":"Mumle","album":"Mumler Ikke","type":"song","duration":139,"albumart":"https://i.scdn.co/image/ab67616d0000b2733397c98effdc469a1f26903e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 27 18:20:20 volumiojbs volumio[964]: info: CoreCommandRouter::volumioPushQueue Jun 27 18:20:20 volumiojbs volumio[964]: info: CorePlayQueue::saveQueue Jun 27 18:20:20 volumiojbs volumio[964]: info: CoreStateMachine::updateTrackBlock Jun 27 18:20:20 volumiojbs volumio[964]: info: CorePlayQueue::getTrackBlock Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: PUSH STATE SPOTIFY Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: {"status":"play","service":"spop","title":"Air on a G String","artist":"Johann Sebastian Bach, HAUSER, London Symphony Orchestra, Robert Ziegler","album":"Classic","albumart":"https://i.scdn.co/image/ab67616d00001e02574875c8196e704ca79605c7","uri":"spotify:track:0mD1a7haZKdX9I0oPywrMb","trackType":"spotify","seek":0,"duration":289,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 27 18:20:20 volumiojbs volumio[964]: info: CoreCommandRouter::servicePushState Jun 27 18:20:20 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 11 Jun 27 18:20:20 volumiojbs volumio[964]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Air on a G String","artist":"Johann Sebastian Bach, HAUSER, London Symphony Orchestra, Robert Ziegler","album":"Classic","albumart":"https://i.scdn.co/image/ab67616d00001e02574875c8196e704ca79605c7","uri":"spotify:track:0mD1a7haZKdX9I0oPywrMb","trackType":"spotify","seek":0,"duration":289,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 27 18:20:20 volumiojbs volumio[964]: verbose: CURRENT POSITION 11 Jun 27 18:20:20 volumiojbs volumio[964]: info: CoreStateMachine::syncState stateService play Jun 27 18:20:20 volumiojbs volumio[964]: info: CoreStateMachine::syncState currentStatus play Jun 27 18:20:20 volumiojbs volumio[964]: info: Received an update from plugin. extracting info from payload Jun 27 18:20:20 volumiojbs volumio[964]: info: CoreStateMachine::pushState Jun 27 18:20:20 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 11 Jun 27 18:20:20 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 27 18:20:20 volumiojbs volumio[964]: info: CoreCommandRouter::volumioPushState Jun 27 18:20:20 volumiojbs volumio[964]: info: CoreStateMachine::pushState Jun 27 18:20:20 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 11 Jun 27 18:20:20 volumiojbs volumio[964]: info: CoreCommandRouter::volumioPushState Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Jun 27 18:20:20 volumiojbs volumio[964]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Jun 27 18:20:32 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:32Z" level=trace msg="sent dealer ping" Jun 27 18:20:32 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:32Z" level=trace msg="received dealer pong" Jun 27 18:20:34 volumiojbs volumio[964]: info: Preload queue cleared Jun 27 18:20:34 volumiojbs volumio[964]: info: CoreCommandRouter::volumioReplaceandPlayItems Jun 27 18:20:34 volumiojbs volumio[964]: info: CoreStateMachine::ClearQueue Jun 27 18:20:34 volumiojbs volumio[964]: info: CoreStateMachine::stop Jun 27 18:20:34 volumiojbs volumio[964]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 27 18:20:34 volumiojbs volumio[964]: info: CoreStateMachine::stPlaybackTimer Jun 27 18:20:34 volumiojbs volumio[964]: info: CoreStateMachine::updateTrackBlock Jun 27 18:20:34 volumiojbs volumio[964]: info: CorePlayQueue::getTrackBlock Jun 27 18:20:34 volumiojbs volumio[964]: info: CoreStateMachine::pushState Jun 27 18:20:34 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 11 Jun 27 18:20:34 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 27 18:20:34 volumiojbs volumio[964]: info: CoreCommandRouter::volumioPushState Jun 27 18:20:34 volumiojbs volumio[964]: info: CoreStateMachine::serviceStop Jun 27 18:20:34 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 11 Jun 27 18:20:34 volumiojbs volumio[964]: info: CoreCommandRouter::serviceStop Jun 27 18:20:34 volumiojbs volumio[964]: info: Spotify Stop Jun 27 18:20:34 volumiojbs volumio[964]: SPOTIFY: SPOTIFY STOP Jun 27 18:20:34 volumiojbs volumio[964]: SPOTIFY: {"status":"play","position":11,"title":"Air on a G String","artist":"Johann Sebastian Bach","album":"Classic","albumart":"https://i.scdn.co/image/ab67616d0000b273574875c8196e704ca79605c7","uri":"spotify:track:0mD1a7haZKdX9I0oPywrMb","trackType":"spotify","codec":"ogg","seek":0,"duration":289,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":false,"repeat":false,"repeatSingle":false,"consume":false,"volume":30,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Jun 27 18:20:34 volumiojbs volumio[964]: info: Sending Spotify command to local API: /player/pause Jun 27 18:20:34 volumiojbs volumio[964]: info: CorePlayQueue::clearPlayQueue Jun 27 18:20:34 volumiojbs volumio[964]: info: CorePlayQueue::saveQueue Jun 27 18:20:34 volumiojbs volumio[964]: info: CoreCommandRouter::volumioPushQueue Jun 27 18:20:34 volumiojbs volumio[964]: info: CoreStateMachine::addQueueItems Jun 27 18:20:34 volumiojbs volumio[964]: info: CorePlayQueue::addQueueItems Jun 27 18:20:34 volumiojbs volumio[964]: info: Preload queue cleared Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:4WNaefp3sGsnTBzHEQb97g Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:4WNaefp3sGsnTBzHEQb97g Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:5UJbgR4XF4y1DvbkxEqe8S Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:5UJbgR4XF4y1DvbkxEqe8S Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:3rUGC1vUpkDG9CZFHMur1t Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:3rUGC1vUpkDG9CZFHMur1t Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:36gcliMRX1vCpgnrZE3dFZ Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:36gcliMRX1vCpgnrZE3dFZ Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:3OfqwyE7RrZrtuxCRixfII Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:3OfqwyE7RrZrtuxCRixfII Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:6eutgX6jfXAsjTXgQtCtYV Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:6eutgX6jfXAsjTXgQtCtYV Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:2p4cYfKQbg8xHXNG4eQaGo Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:2p4cYfKQbg8xHXNG4eQaGo Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:3t4zZ2SxXgQRIhc5N6a6oZ Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:3t4zZ2SxXgQRIhc5N6a6oZ Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:0fFMt9cc1EEQDIWLGDcqKd Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:0fFMt9cc1EEQDIWLGDcqKd Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:4l0RmWt52FxpVxMNni6i63 Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:4l0RmWt52FxpVxMNni6i63 Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:7CmQjA7j6CxyPBkH3tP95W Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:7CmQjA7j6CxyPBkH3tP95W Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:0mD1a7haZKdX9I0oPywrMb Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:0mD1a7haZKdX9I0oPywrMb Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:0RMqPnXgdZoP6dmvFUZfEP Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:0RMqPnXgdZoP6dmvFUZfEP Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:29cMQlJXTeUEfl4rKL9gDw Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:29cMQlJXTeUEfl4rKL9gDw Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:44nX7Y9AgkHyinw8RSXOgP Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:44nX7Y9AgkHyinw8RSXOgP Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:7LoyqdrF51XVflrSKFHH1a Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:7LoyqdrF51XVflrSKFHH1a Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:0iXvldXRa915oqeJUhnePc Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:0iXvldXRa915oqeJUhnePc Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:1uprWeHo3ZsC8W8Fnox9Z5 Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:1uprWeHo3ZsC8W8Fnox9Z5 Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:20hs5uYcsZa1BsZafOid24 Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:20hs5uYcsZa1BsZafOid24 Jun 27 18:20:34 volumiojbs volumio[964]: info: CoreCommandRouter::volumioPushQueue Jun 27 18:20:34 volumiojbs volumio[964]: info: CorePlayQueue::saveQueue Jun 27 18:20:34 volumiojbs volumio[964]: info: CoreStateMachine::updateTrackBlock Jun 27 18:20:34 volumiojbs volumio[964]: info: CorePlayQueue::getTrackBlock Jun 27 18:20:34 volumiojbs volumio[964]: info: CoreCommandRouter::volumioPlay Jun 27 18:20:34 volumiojbs volumio[964]: info: CoreStateMachine::play index 18 Jun 27 18:20:34 volumiojbs volumio[964]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 27 18:20:34 volumiojbs volumio[964]: info: CoreStateMachine::addQueueItems Jun 27 18:20:34 volumiojbs volumio[964]: info: CorePlayQueue::addQueueItems Jun 27 18:20:34 volumiojbs volumio[964]: info: Preload queue cleared Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:25I0HJIvPtmZAT0EbXZ1LK Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:25I0HJIvPtmZAT0EbXZ1LK Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:262dMH9zpKTYhhGNZQjk4A Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:262dMH9zpKTYhhGNZQjk4A Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:3xF2FcXiJjWQUqUYvrp4NT Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:3xF2FcXiJjWQUqUYvrp4NT Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:5IDTIaKLOF0MDALUVfoipB Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:5IDTIaKLOF0MDALUVfoipB Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:5NnIHhNURtKKqRDb3WIXT2 Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:5NnIHhNURtKKqRDb3WIXT2 Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:5c5nDhtmcaPB2UQa0FWNs7 Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:5c5nDhtmcaPB2UQa0FWNs7 Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:7KNmIjcmGJIBrhP2s5Vioe Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:7KNmIjcmGJIBrhP2s5Vioe Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:7px3lmdf4nzNEMt6zaQ5yJ Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:7px3lmdf4nzNEMt6zaQ5yJ Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:065hCOwsPu9rtuTkO4vLjz Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:065hCOwsPu9rtuTkO4vLjz Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:11kjd2fjjQGncmBeX74e9a Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:11kjd2fjjQGncmBeX74e9a Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:2TpZAFpamrkPQcCdQcNjRT Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:2TpZAFpamrkPQcCdQcNjRT Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:2kDApipZtTzjwGfKujcg2z Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:2kDApipZtTzjwGfKujcg2z Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:3OtJnSQq23fgggHFZAe3w1 Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:3OtJnSQq23fgggHFZAe3w1 Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:3TFtD8GZNw9v6vVWr3hnWy Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:3TFtD8GZNw9v6vVWr3hnWy Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:3a4PdwwaddhYbZnp0lxqyz Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:3a4PdwwaddhYbZnp0lxqyz Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:1augDsuBVF8F8jBgNrDpbt Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:1augDsuBVF8F8jBgNrDpbt Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:4GZt2BpQpWhkEAgmfUrQOu Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:4GZt2BpQpWhkEAgmfUrQOu Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:4xvEn1vhrF9JbPFWqTXsH4 Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:4xvEn1vhrF9JbPFWqTXsH4 Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:51hyZpbJlIgZIaX3TtMxmu Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:51hyZpbJlIgZIaX3TtMxmu Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:541sN2qNfIlllGn9nGOQoC Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:541sN2qNfIlllGn9nGOQoC Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:2gJ33IwQXrA6zTXD6ztHPz Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:2gJ33IwQXrA6zTXD6ztHPz Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:2bFGGsScXp2Tu10jKMCKO6 Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:2bFGGsScXp2Tu10jKMCKO6 Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:2vVLSYsOUNCfN66jTyJsMY Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:2vVLSYsOUNCfN66jTyJsMY Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:2oyUhz61OvaMiKG3hWbvpg Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:2oyUhz61OvaMiKG3hWbvpg Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:0GbSM08heTzfWO39fGKVdo Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:0GbSM08heTzfWO39fGKVdo Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:0pT6pQ9bfQNee3zDaGBlaO Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:0pT6pQ9bfQNee3zDaGBlaO Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:23cU3OwfFcrnpkIkwlGp8V Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:23cU3OwfFcrnpkIkwlGp8V Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:5v66VjrhFwSlPqadCrubyb Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:5v66VjrhFwSlPqadCrubyb Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:03zuGqxMwUFFmCwusq0WKE Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:03zuGqxMwUFFmCwusq0WKE Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:0qbFoKlLA7v2ECDJDTXExs Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:0qbFoKlLA7v2ECDJDTXExs Jun 27 18:20:34 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:2QSimeBrPuaCxpGPSCh60C Jun 27 18:20:34 volumiojbs volumio[964]: info: Using cached record of: spotify:track:2QSimeBrPuaCxpGPSCh60C Jun 27 18:20:34 volumiojbs volumio[964]: info: CoreStateMachine::stop Jun 27 18:20:34 volumiojbs volumio[964]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 27 18:20:34 volumiojbs volumio[964]: info: CoreCommandRouter::volumioPushQueue Jun 27 18:20:34 volumiojbs volumio[964]: info: CorePlayQueue::saveQueue Jun 27 18:20:34 volumiojbs volumio[964]: info: CoreStateMachine::play index undefined Jun 27 18:20:34 volumiojbs volumio[964]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 27 18:20:34 volumiojbs volumio[964]: info: CoreStateMachine::updateTrackBlock Jun 27 18:20:34 volumiojbs volumio[964]: info: CorePlayQueue::getTrackBlock Jun 27 18:20:34 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 18 Jun 27 18:20:34 volumiojbs volumio[964]: info: CoreStateMachine::startPlaybackTimer Jun 27 18:20:34 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 18 Jun 27 18:20:34 volumiojbs volumio[964]: info: [1751048434332] ControllerSpotify::clearAddPlayTrack Jun 27 18:20:34 volumiojbs volumio[964]: info: Sending Spotify command with payload to local API: /player/play Jun 27 18:20:34 volumiojbs volumio[964]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Jun 27 18:20:34 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:34Z" level=debug msg="pause track at 14546ms" Jun 27 18:20:34 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:34Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 27 18:20:34 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:34Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 27 18:20:34 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:34Z" level=trace msg="emitting websocket event: paused" Jun 27 18:20:34 volumiojbs volumio[964]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:0mD1a7haZKdX9I0oPywrMb","play_origin":"go-librespot"}} Jun 27 18:20:34 volumiojbs volumio[964]: SPOTIFY: PUSH STATE SPOTIFY Jun 27 18:20:34 volumiojbs volumio[964]: SPOTIFY: {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 27 18:20:34 volumiojbs volumio[964]: info: CoreCommandRouter::servicePushState Jun 27 18:20:34 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 18 Jun 27 18:20:34 volumiojbs volumio[964]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 27 18:20:34 volumiojbs volumio[964]: verbose: CURRENT POSITION 18 Jun 27 18:20:34 volumiojbs volumio[964]: info: CoreStateMachine::syncState stateService pause Jun 27 18:20:34 volumiojbs volumio[964]: info: CoreStateMachine::syncState currentStatus stop Jun 27 18:20:34 volumiojbs volumio[964]: info: CoreStateMachine::pushState Jun 27 18:20:34 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 18 Jun 27 18:20:34 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 27 18:20:34 volumiojbs volumio[964]: info: CoreCommandRouter::volumioPushState Jun 27 18:20:34 volumiojbs volumio[964]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Jun 27 18:20:34 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:34Z" level=debug msg="resolved context of track" uri="spotify:track:20hs5uYcsZa1BsZafOid24" Jun 27 18:20:34 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:34Z" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:20hs5uYcsZa1BsZafOid24" Jun 27 18:20:34 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:34Z" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:20hs5uYcsZa1BsZafOid24" Jun 27 18:20:34 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:34Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 27 18:20:34 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:34Z" level=trace msg="emitting websocket event: will_play" Jun 27 18:20:34 volumiojbs volumio[964]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:20hs5uYcsZa1BsZafOid24","play_origin":"go-librespot"}} Jun 27 18:20:34 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:34Z" level=debug msg="selected format OGG_VORBIS_320 (243de3b1487ab2b7e5e8b436656947a27a3d01a7)" uri="spotify:track:20hs5uYcsZa1BsZafOid24" Jun 27 18:20:34 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:34Z" level=debug msg="requested aes key for file 243de3b1487ab2b7e5e8b436656947a27a3d01a7, gid: 20hs5uYcsZa1BsZafOid24" Jun 27 18:20:34 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:34Z" level=debug msg="fetched first chunk of 10, total size is 4988287 bytes" uri="spotify:track:20hs5uYcsZa1BsZafOid24" Jun 27 18:20:34 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:34Z" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames" Jun 27 18:20:34 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:34Z" level=info msg="loaded track \"I Ain't Gay\" (paused: false, position: 0ms, duration: 124778ms, prefetched: false)" uri="spotify:track:20hs5uYcsZa1BsZafOid24" Jun 27 18:20:34 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:34Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 27 18:20:34 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:34Z" level=trace msg="scheduling prefetch in 95s" Jun 27 18:20:34 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:34Z" level=trace msg="emitting websocket event: metadata" Jun 27 18:20:34 volumiojbs volumio[964]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:20hs5uYcsZa1BsZafOid24","name":"I Ain't Gay","artist_names":["Biscuit Beats"],"album_name":"Nature's Ignition","album_cover_url":"https://i.scdn.co/image/ab67616d00001e024e6d4b04614202f0452f2e20","position":0,"duration":124778,"release_date":"year:2025 month:4 day:18","track_number":7,"disc_number":1}} Jun 27 18:20:34 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:34Z" level=debug msg="fetched chunk 1/9, size: 524288" uri="spotify:track:20hs5uYcsZa1BsZafOid24" Jun 27 18:20:35 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:35Z" level=debug msg="fetched chunk 3/9, size: 524288" uri="spotify:track:20hs5uYcsZa1BsZafOid24" Jun 27 18:20:35 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:35Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 27 18:20:35 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:35Z" level=trace msg="emitting websocket event: playing" Jun 27 18:20:35 volumiojbs volumio[964]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:20hs5uYcsZa1BsZafOid24","play_origin":"go-librespot"}} Jun 27 18:20:35 volumiojbs volumio[964]: SPOTIFY: PUSH STATE SPOTIFY Jun 27 18:20:35 volumiojbs volumio[964]: SPOTIFY: {"status":"play","service":"spop","title":"I Ain't Gay","artist":"Biscuit Beats","album":"Nature's Ignition","albumart":"https://i.scdn.co/image/ab67616d00001e024e6d4b04614202f0452f2e20","uri":"spotify:track:20hs5uYcsZa1BsZafOid24","trackType":"spotify","seek":0,"duration":124,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 27 18:20:35 volumiojbs volumio[964]: info: CoreCommandRouter::servicePushState Jun 27 18:20:35 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 18 Jun 27 18:20:35 volumiojbs volumio[964]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"I Ain't Gay","artist":"Biscuit Beats","album":"Nature's Ignition","albumart":"https://i.scdn.co/image/ab67616d00001e024e6d4b04614202f0452f2e20","uri":"spotify:track:20hs5uYcsZa1BsZafOid24","trackType":"spotify","seek":0,"duration":124,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 27 18:20:35 volumiojbs volumio[964]: verbose: CURRENT POSITION 18 Jun 27 18:20:35 volumiojbs volumio[964]: info: CoreStateMachine::syncState stateService play Jun 27 18:20:35 volumiojbs volumio[964]: info: CoreStateMachine::syncState currentStatus stop Jun 27 18:20:35 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:35Z" level=debug msg="fetched chunk 2/9, size: 524288" uri="spotify:track:20hs5uYcsZa1BsZafOid24" Jun 27 18:20:35 volumiojbs volumio[964]: SPOTIFY: PUSH STATE SPOTIFY Jun 27 18:20:35 volumiojbs volumio[964]: SPOTIFY: {"status":"play","service":"spop","title":"I Ain't Gay","artist":"Biscuit Beats","album":"Nature's Ignition","albumart":"https://i.scdn.co/image/ab67616d00001e024e6d4b04614202f0452f2e20","uri":"spotify:track:20hs5uYcsZa1BsZafOid24","trackType":"spotify","seek":0,"duration":124,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 27 18:20:35 volumiojbs volumio[964]: info: CoreCommandRouter::servicePushState Jun 27 18:20:35 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 18 Jun 27 18:20:35 volumiojbs volumio[964]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"I Ain't Gay","artist":"Biscuit Beats","album":"Nature's Ignition","albumart":"https://i.scdn.co/image/ab67616d00001e024e6d4b04614202f0452f2e20","uri":"spotify:track:20hs5uYcsZa1BsZafOid24","trackType":"spotify","seek":0,"duration":124,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 27 18:20:35 volumiojbs volumio[964]: verbose: CURRENT POSITION 18 Jun 27 18:20:35 volumiojbs volumio[964]: info: CoreStateMachine::syncState stateService play Jun 27 18:20:35 volumiojbs volumio[964]: info: CoreStateMachine::syncState currentStatus play Jun 27 18:20:35 volumiojbs volumio[964]: info: Received an update from plugin. extracting info from payload Jun 27 18:20:35 volumiojbs volumio[964]: info: CoreStateMachine::pushState Jun 27 18:20:35 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 18 Jun 27 18:20:35 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 27 18:20:35 volumiojbs volumio[964]: info: CoreCommandRouter::volumioPushState Jun 27 18:20:35 volumiojbs volumio[964]: info: CoreStateMachine::pushState Jun 27 18:20:35 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 18 Jun 27 18:20:35 volumiojbs volumio[964]: info: CoreCommandRouter::volumioPushState Jun 27 18:20:35 volumiojbs volumio[964]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Jun 27 18:20:35 volumiojbs volumio[964]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Jun 27 18:20:39 volumiojbs volumio[964]: info: Preload queue cleared Jun 27 18:20:39 volumiojbs volumio[964]: info: CoreCommandRouter::volumioReplaceandPlayItems Jun 27 18:20:39 volumiojbs volumio[964]: info: CoreStateMachine::ClearQueue Jun 27 18:20:39 volumiojbs volumio[964]: info: CoreStateMachine::stop Jun 27 18:20:39 volumiojbs volumio[964]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 27 18:20:39 volumiojbs volumio[964]: info: CoreStateMachine::stPlaybackTimer Jun 27 18:20:39 volumiojbs volumio[964]: info: CoreStateMachine::updateTrackBlock Jun 27 18:20:39 volumiojbs volumio[964]: info: CorePlayQueue::getTrackBlock Jun 27 18:20:39 volumiojbs volumio[964]: info: CoreStateMachine::pushState Jun 27 18:20:39 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 18 Jun 27 18:20:39 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 27 18:20:39 volumiojbs volumio[964]: info: CoreCommandRouter::volumioPushState Jun 27 18:20:39 volumiojbs volumio[964]: info: CoreStateMachine::serviceStop Jun 27 18:20:39 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 18 Jun 27 18:20:39 volumiojbs volumio[964]: info: CoreCommandRouter::serviceStop Jun 27 18:20:39 volumiojbs volumio[964]: info: Spotify Stop Jun 27 18:20:39 volumiojbs volumio[964]: SPOTIFY: SPOTIFY STOP Jun 27 18:20:39 volumiojbs volumio[964]: SPOTIFY: {"status":"play","position":18,"title":"I Ain't Gay","artist":"Biscuit Beats","album":"Nature's Ignition","albumart":"https://i.scdn.co/image/ab67616d0000b2734e6d4b04614202f0452f2e20","uri":"spotify:track:20hs5uYcsZa1BsZafOid24","trackType":"spotify","codec":"ogg","seek":0,"duration":124,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":false,"repeat":false,"repeatSingle":false,"consume":false,"volume":30,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Jun 27 18:20:39 volumiojbs volumio[964]: info: Sending Spotify command to local API: /player/pause Jun 27 18:20:39 volumiojbs volumio[964]: info: CorePlayQueue::clearPlayQueue Jun 27 18:20:39 volumiojbs volumio[964]: info: CorePlayQueue::saveQueue Jun 27 18:20:39 volumiojbs volumio[964]: info: CoreCommandRouter::volumioPushQueue Jun 27 18:20:39 volumiojbs volumio[964]: info: CoreStateMachine::addQueueItems Jun 27 18:20:39 volumiojbs volumio[964]: info: CorePlayQueue::addQueueItems Jun 27 18:20:39 volumiojbs volumio[964]: info: Preload queue cleared Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:4WNaefp3sGsnTBzHEQb97g Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:4WNaefp3sGsnTBzHEQb97g Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:5UJbgR4XF4y1DvbkxEqe8S Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:5UJbgR4XF4y1DvbkxEqe8S Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:3rUGC1vUpkDG9CZFHMur1t Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:3rUGC1vUpkDG9CZFHMur1t Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:36gcliMRX1vCpgnrZE3dFZ Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:36gcliMRX1vCpgnrZE3dFZ Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:3OfqwyE7RrZrtuxCRixfII Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:3OfqwyE7RrZrtuxCRixfII Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:6eutgX6jfXAsjTXgQtCtYV Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:6eutgX6jfXAsjTXgQtCtYV Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:2p4cYfKQbg8xHXNG4eQaGo Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:2p4cYfKQbg8xHXNG4eQaGo Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:3t4zZ2SxXgQRIhc5N6a6oZ Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:3t4zZ2SxXgQRIhc5N6a6oZ Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:0fFMt9cc1EEQDIWLGDcqKd Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:0fFMt9cc1EEQDIWLGDcqKd Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:4l0RmWt52FxpVxMNni6i63 Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:4l0RmWt52FxpVxMNni6i63 Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:7CmQjA7j6CxyPBkH3tP95W Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:7CmQjA7j6CxyPBkH3tP95W Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:0mD1a7haZKdX9I0oPywrMb Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:0mD1a7haZKdX9I0oPywrMb Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:0RMqPnXgdZoP6dmvFUZfEP Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:0RMqPnXgdZoP6dmvFUZfEP Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:29cMQlJXTeUEfl4rKL9gDw Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:29cMQlJXTeUEfl4rKL9gDw Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:44nX7Y9AgkHyinw8RSXOgP Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:44nX7Y9AgkHyinw8RSXOgP Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:7LoyqdrF51XVflrSKFHH1a Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:7LoyqdrF51XVflrSKFHH1a Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:0iXvldXRa915oqeJUhnePc Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:0iXvldXRa915oqeJUhnePc Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:1uprWeHo3ZsC8W8Fnox9Z5 Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:1uprWeHo3ZsC8W8Fnox9Z5 Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:20hs5uYcsZa1BsZafOid24 Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:20hs5uYcsZa1BsZafOid24 Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:25I0HJIvPtmZAT0EbXZ1LK Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:25I0HJIvPtmZAT0EbXZ1LK Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:262dMH9zpKTYhhGNZQjk4A Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:262dMH9zpKTYhhGNZQjk4A Jun 27 18:20:39 volumiojbs volumio[964]: info: CoreCommandRouter::volumioPushQueue Jun 27 18:20:39 volumiojbs volumio[964]: info: CorePlayQueue::saveQueue Jun 27 18:20:39 volumiojbs volumio[964]: info: CoreStateMachine::updateTrackBlock Jun 27 18:20:39 volumiojbs volumio[964]: info: CorePlayQueue::getTrackBlock Jun 27 18:20:39 volumiojbs volumio[964]: info: CoreCommandRouter::volumioPlay Jun 27 18:20:39 volumiojbs volumio[964]: info: CoreStateMachine::play index 20 Jun 27 18:20:39 volumiojbs volumio[964]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 27 18:20:39 volumiojbs volumio[964]: info: CoreStateMachine::addQueueItems Jun 27 18:20:39 volumiojbs volumio[964]: info: CorePlayQueue::addQueueItems Jun 27 18:20:39 volumiojbs volumio[964]: info: Preload queue cleared Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:3xF2FcXiJjWQUqUYvrp4NT Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:3xF2FcXiJjWQUqUYvrp4NT Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:5IDTIaKLOF0MDALUVfoipB Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:5IDTIaKLOF0MDALUVfoipB Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:5NnIHhNURtKKqRDb3WIXT2 Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:5NnIHhNURtKKqRDb3WIXT2 Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:5c5nDhtmcaPB2UQa0FWNs7 Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:5c5nDhtmcaPB2UQa0FWNs7 Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:7KNmIjcmGJIBrhP2s5Vioe Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:7KNmIjcmGJIBrhP2s5Vioe Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:7px3lmdf4nzNEMt6zaQ5yJ Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:7px3lmdf4nzNEMt6zaQ5yJ Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:065hCOwsPu9rtuTkO4vLjz Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:065hCOwsPu9rtuTkO4vLjz Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:11kjd2fjjQGncmBeX74e9a Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:11kjd2fjjQGncmBeX74e9a Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:2TpZAFpamrkPQcCdQcNjRT Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:2TpZAFpamrkPQcCdQcNjRT Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:2kDApipZtTzjwGfKujcg2z Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:2kDApipZtTzjwGfKujcg2z Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:3OtJnSQq23fgggHFZAe3w1 Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:3OtJnSQq23fgggHFZAe3w1 Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:3TFtD8GZNw9v6vVWr3hnWy Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:3TFtD8GZNw9v6vVWr3hnWy Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:3a4PdwwaddhYbZnp0lxqyz Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:3a4PdwwaddhYbZnp0lxqyz Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:1augDsuBVF8F8jBgNrDpbt Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:1augDsuBVF8F8jBgNrDpbt Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:4GZt2BpQpWhkEAgmfUrQOu Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:4GZt2BpQpWhkEAgmfUrQOu Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:4xvEn1vhrF9JbPFWqTXsH4 Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:4xvEn1vhrF9JbPFWqTXsH4 Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:51hyZpbJlIgZIaX3TtMxmu Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:51hyZpbJlIgZIaX3TtMxmu Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:541sN2qNfIlllGn9nGOQoC Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:541sN2qNfIlllGn9nGOQoC Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:2gJ33IwQXrA6zTXD6ztHPz Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:2gJ33IwQXrA6zTXD6ztHPz Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:2bFGGsScXp2Tu10jKMCKO6 Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:2bFGGsScXp2Tu10jKMCKO6 Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:2vVLSYsOUNCfN66jTyJsMY Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:2vVLSYsOUNCfN66jTyJsMY Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:2oyUhz61OvaMiKG3hWbvpg Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:2oyUhz61OvaMiKG3hWbvpg Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:0GbSM08heTzfWO39fGKVdo Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:0GbSM08heTzfWO39fGKVdo Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:0pT6pQ9bfQNee3zDaGBlaO Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:0pT6pQ9bfQNee3zDaGBlaO Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:23cU3OwfFcrnpkIkwlGp8V Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:23cU3OwfFcrnpkIkwlGp8V Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:5v66VjrhFwSlPqadCrubyb Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:5v66VjrhFwSlPqadCrubyb Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:03zuGqxMwUFFmCwusq0WKE Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:03zuGqxMwUFFmCwusq0WKE Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:0qbFoKlLA7v2ECDJDTXExs Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:0qbFoKlLA7v2ECDJDTXExs Jun 27 18:20:39 volumiojbs volumio[964]: info: Adding Item to queue: spotify:track:2QSimeBrPuaCxpGPSCh60C Jun 27 18:20:39 volumiojbs volumio[964]: info: Using cached record of: spotify:track:2QSimeBrPuaCxpGPSCh60C Jun 27 18:20:39 volumiojbs volumio[964]: info: CoreStateMachine::stop Jun 27 18:20:39 volumiojbs volumio[964]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 27 18:20:39 volumiojbs volumio[964]: info: CoreCommandRouter::volumioPushQueue Jun 27 18:20:39 volumiojbs volumio[964]: info: CorePlayQueue::saveQueue Jun 27 18:20:39 volumiojbs volumio[964]: info: CoreStateMachine::play index undefined Jun 27 18:20:39 volumiojbs volumio[964]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 27 18:20:39 volumiojbs volumio[964]: info: CoreStateMachine::updateTrackBlock Jun 27 18:20:39 volumiojbs volumio[964]: info: CorePlayQueue::getTrackBlock Jun 27 18:20:39 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 20 Jun 27 18:20:39 volumiojbs volumio[964]: info: CoreStateMachine::startPlaybackTimer Jun 27 18:20:39 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 20 Jun 27 18:20:39 volumiojbs volumio[964]: info: [1751048439993] ControllerSpotify::clearAddPlayTrack Jun 27 18:20:39 volumiojbs volumio[964]: info: Sending Spotify command with payload to local API: /player/play Jun 27 18:20:40 volumiojbs volumio[964]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Jun 27 18:20:40 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:40Z" level=debug msg="pause track at 5231ms" Jun 27 18:20:40 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:40Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 27 18:20:40 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:40Z" level=debug msg="resolved context of track" uri="spotify:track:262dMH9zpKTYhhGNZQjk4A" Jun 27 18:20:40 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:40Z" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:262dMH9zpKTYhhGNZQjk4A" Jun 27 18:20:40 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:40Z" level=debug msg="loading track (paused: false, position: 1ms)" uri="spotify:track:262dMH9zpKTYhhGNZQjk4A" Jun 27 18:20:40 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:40Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 27 18:20:40 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:40Z" level=trace msg="emitting websocket event: will_play" Jun 27 18:20:40 volumiojbs volumio[964]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:262dMH9zpKTYhhGNZQjk4A","play_origin":"go-librespot"}} Jun 27 18:20:40 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:40Z" level=debug msg="selected format OGG_VORBIS_320 (c67bfbbc0940c87f0b6e17b4b46faf19450b3ba9)" uri="spotify:track:262dMH9zpKTYhhGNZQjk4A" Jun 27 18:20:40 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:40Z" level=debug msg="requested aes key for file c67bfbbc0940c87f0b6e17b4b46faf19450b3ba9, gid: 262dMH9zpKTYhhGNZQjk4A" Jun 27 18:20:40 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:40Z" level=debug msg="fetched first chunk of 13, total size is 6655848 bytes" uri="spotify:track:262dMH9zpKTYhhGNZQjk4A" Jun 27 18:20:40 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:40Z" level=trace msg="seek to 1ms (diff: 1ms, samples: 44, bytes: 0)" uri="spotify:track:262dMH9zpKTYhhGNZQjk4A" Jun 27 18:20:40 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:40Z" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames" Jun 27 18:20:40 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:40Z" level=info msg="loaded track \"Canon in D\" (paused: false, position: 1ms, duration: 192242ms, prefetched: false)" uri="spotify:track:262dMH9zpKTYhhGNZQjk4A" Jun 27 18:20:40 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:40Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 27 18:20:40 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:40Z" level=trace msg="scheduling prefetch in 162s" Jun 27 18:20:40 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:40Z" level=trace msg="emitting websocket event: metadata" Jun 27 18:20:40 volumiojbs volumio[964]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:262dMH9zpKTYhhGNZQjk4A","name":"Canon in D","artist_names":["Lola Astanova","David Aaron Carpenter"],"album_name":"Canon in D","album_cover_url":"https://i.scdn.co/image/ab67616d00001e028e72efaf318071f71a2b0e02","position":1,"duration":192242,"release_date":"year:2021 month:2 day:16","track_number":1,"disc_number":1}} Jun 27 18:20:40 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:40Z" level=debug msg="fetched chunk 1/12, size: 524288" uri="spotify:track:262dMH9zpKTYhhGNZQjk4A" Jun 27 18:20:40 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:40Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 27 18:20:40 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:40Z" level=trace msg="emitting websocket event: paused" Jun 27 18:20:40 volumiojbs volumio[964]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:262dMH9zpKTYhhGNZQjk4A","play_origin":"go-librespot"}} Jun 27 18:20:40 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:40Z" level=debug msg="fetched chunk 2/12, size: 524288" uri="spotify:track:262dMH9zpKTYhhGNZQjk4A" Jun 27 18:20:40 volumiojbs volumio[964]: SPOTIFY: PUSH STATE SPOTIFY Jun 27 18:20:40 volumiojbs volumio[964]: SPOTIFY: {"status":"pause","service":"spop","title":"Canon in D","artist":"Lola Astanova, David Aaron Carpenter","album":"Canon in D","albumart":"https://i.scdn.co/image/ab67616d00001e028e72efaf318071f71a2b0e02","uri":"spotify:track:262dMH9zpKTYhhGNZQjk4A","trackType":"spotify","seek":1,"duration":192,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 27 18:20:40 volumiojbs volumio[964]: info: CoreCommandRouter::servicePushState Jun 27 18:20:40 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 20 Jun 27 18:20:40 volumiojbs volumio[964]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Canon in D","artist":"Lola Astanova, David Aaron Carpenter","album":"Canon in D","albumart":"https://i.scdn.co/image/ab67616d00001e028e72efaf318071f71a2b0e02","uri":"spotify:track:262dMH9zpKTYhhGNZQjk4A","trackType":"spotify","seek":1,"duration":192,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 27 18:20:40 volumiojbs volumio[964]: verbose: CURRENT POSITION 20 Jun 27 18:20:40 volumiojbs volumio[964]: info: CoreStateMachine::syncState stateService pause Jun 27 18:20:40 volumiojbs volumio[964]: info: CoreStateMachine::syncState currentStatus stop Jun 27 18:20:40 volumiojbs volumio[964]: info: CoreStateMachine::pushState Jun 27 18:20:40 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 20 Jun 27 18:20:40 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 27 18:20:40 volumiojbs volumio[964]: info: CoreCommandRouter::volumioPushState Jun 27 18:20:40 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:40Z" level=debug msg="fetched chunk 3/12, size: 524288" uri="spotify:track:262dMH9zpKTYhhGNZQjk4A" Jun 27 18:20:40 volumiojbs volumio[964]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Jun 27 18:20:40 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:40Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 27 18:20:40 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:40Z" level=trace msg="emitting websocket event: playing" Jun 27 18:20:40 volumiojbs volumio[964]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:262dMH9zpKTYhhGNZQjk4A","play_origin":"go-librespot"}} Jun 27 18:20:40 volumiojbs volumio[964]: SPOTIFY: PUSH STATE SPOTIFY Jun 27 18:20:40 volumiojbs volumio[964]: SPOTIFY: {"status":"play","service":"spop","title":"Canon in D","artist":"Lola Astanova, David Aaron Carpenter","album":"Canon in D","albumart":"https://i.scdn.co/image/ab67616d00001e028e72efaf318071f71a2b0e02","uri":"spotify:track:262dMH9zpKTYhhGNZQjk4A","trackType":"spotify","seek":1,"duration":192,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 27 18:20:40 volumiojbs volumio[964]: info: CoreCommandRouter::servicePushState Jun 27 18:20:40 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 20 Jun 27 18:20:40 volumiojbs volumio[964]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Canon in D","artist":"Lola Astanova, David Aaron Carpenter","album":"Canon in D","albumart":"https://i.scdn.co/image/ab67616d00001e028e72efaf318071f71a2b0e02","uri":"spotify:track:262dMH9zpKTYhhGNZQjk4A","trackType":"spotify","seek":1,"duration":192,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 27 18:20:40 volumiojbs volumio[964]: verbose: CURRENT POSITION 20 Jun 27 18:20:40 volumiojbs volumio[964]: info: CoreStateMachine::syncState stateService play Jun 27 18:20:40 volumiojbs volumio[964]: info: CoreStateMachine::syncState currentStatus stop Jun 27 18:20:41 volumiojbs volumio[964]: SPOTIFY: PUSH STATE SPOTIFY Jun 27 18:20:41 volumiojbs volumio[964]: SPOTIFY: {"status":"play","service":"spop","title":"Canon in D","artist":"Lola Astanova, David Aaron Carpenter","album":"Canon in D","albumart":"https://i.scdn.co/image/ab67616d00001e028e72efaf318071f71a2b0e02","uri":"spotify:track:262dMH9zpKTYhhGNZQjk4A","trackType":"spotify","seek":1,"duration":192,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 27 18:20:41 volumiojbs volumio[964]: info: CoreCommandRouter::servicePushState Jun 27 18:20:41 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 20 Jun 27 18:20:41 volumiojbs volumio[964]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Canon in D","artist":"Lola Astanova, David Aaron Carpenter","album":"Canon in D","albumart":"https://i.scdn.co/image/ab67616d00001e028e72efaf318071f71a2b0e02","uri":"spotify:track:262dMH9zpKTYhhGNZQjk4A","trackType":"spotify","seek":1,"duration":192,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 27 18:20:41 volumiojbs volumio[964]: verbose: CURRENT POSITION 20 Jun 27 18:20:41 volumiojbs volumio[964]: info: CoreStateMachine::syncState stateService play Jun 27 18:20:41 volumiojbs volumio[964]: info: CoreStateMachine::syncState currentStatus play Jun 27 18:20:41 volumiojbs volumio[964]: info: Received an update from plugin. extracting info from payload Jun 27 18:20:41 volumiojbs volumio[964]: info: CoreStateMachine::pushState Jun 27 18:20:41 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 20 Jun 27 18:20:41 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 27 18:20:41 volumiojbs volumio[964]: info: CoreCommandRouter::volumioPushState Jun 27 18:20:41 volumiojbs volumio[964]: info: CoreStateMachine::pushState Jun 27 18:20:41 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 20 Jun 27 18:20:41 volumiojbs volumio[964]: info: CoreCommandRouter::volumioPushState Jun 27 18:20:41 volumiojbs volumio[964]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Jun 27 18:20:41 volumiojbs volumio[964]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Jun 27 18:20:44 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 27 18:20:44 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 27 18:20:44 volumiojbs volumio[964]: info: Discovery: Getting this device information Jun 27 18:20:44 volumiojbs volumio[964]: info: CoreCommandRouter::volumioGetState Jun 27 18:20:44 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 20 Jun 27 18:20:44 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 27 18:20:45 volumiojbs volumio[964]: info: VolumeController::SetAlsaVolume49 Jun 27 18:20:45 volumiojbs volumio[964]: info: CoreStateMachine::pushState Jun 27 18:20:45 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 20 Jun 27 18:20:45 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 27 18:20:45 volumiojbs volumio[964]: info: CoreCommandRouter::volumioPushState Jun 27 18:20:45 volumiojbs volumio[964]: SPOTIFY: RECEIVED VOLUMIO VOLUME 49 Jun 27 18:20:45 volumiojbs volumio[964]: SPOTIFY: SPOTIFY VOLUME 30 Jun 27 18:20:45 volumiojbs volumio[964]: SPOTIFY: VOLUMIO VOLUME 49 Jun 27 18:20:45 volumiojbs volumio[964]: SPOTIFY: DELTA VOLUME ENOUGH: true Jun 27 18:20:45 volumiojbs volumio[964]: info: Setting Spotify Volume from Volumio: 49 Jun 27 18:20:46 volumiojbs volumio[964]: SPOTIFY: SETTING SPOTIFY VOLUME 49 Jun 27 18:20:46 volumiojbs volumio[964]: info: Sending Spotify command with payload to local API: /player/volume Jun 27 18:20:46 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:46Z" level=debug msg="update volume to 32112/65535" Jun 27 18:20:47 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:47Z" level=debug msg="put connect state because VOLUME_CHANGED" Jun 27 18:20:47 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:47Z" level=trace msg="emitting websocket event: volume" Jun 27 18:20:47 volumiojbs volumio[964]: SPOTIFY: received: {"type":"volume","data":{"value":49,"max":100}} Jun 27 18:20:47 volumiojbs volumio[964]: SPOTIFY: RECEIVED SPOTIFY VOLUME 49 Jun 27 18:20:54 volumiojbs go-librespot[1151]: time="2025-06-27T18:20:54Z" level=debug msg="fetched chunk 4/12, size: 524288" uri="spotify:track:262dMH9zpKTYhhGNZQjk4A" Jun 27 18:21:02 volumiojbs go-librespot[1151]: time="2025-06-27T18:21:02Z" level=trace msg="sent dealer ping" Jun 27 18:21:02 volumiojbs go-librespot[1151]: time="2025-06-27T18:21:02Z" level=trace msg="received dealer pong" Jun 27 18:21:10 volumiojbs go-librespot[1151]: time="2025-06-27T18:21:10Z" level=debug msg="fetched chunk 5/12, size: 524288" uri="spotify:track:262dMH9zpKTYhhGNZQjk4A" Jun 27 18:21:14 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 27 18:21:14 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 27 18:21:14 volumiojbs volumio[964]: info: Discovery: Getting this device information Jun 27 18:21:14 volumiojbs volumio[964]: info: CoreCommandRouter::volumioGetState Jun 27 18:21:14 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 20 Jun 27 18:21:14 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 27 18:21:14 volumiojbs sudo[1987]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 27 18:21:14 volumiojbs sudo[1987]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 18:21:14 volumiojbs sudo[1987]: pam_unix(sudo:session): session closed for user root Jun 27 18:21:14 volumiojbs sudo[1989]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 27 18:21:14 volumiojbs sudo[1989]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 18:21:14 volumiojbs sudo[1989]: pam_unix(sudo:session): session closed for user root Jun 27 18:21:14 volumiojbs volumio[964]: verbose: New Socket.io Connection to 192.168.1.75 from 192.168.1.66 UA: Mozilla/5.0 (Linux; Android 12; SM-G973F Build/SP1A.210812.016; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/137.0.7151.115 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Jun 27 18:21:14 volumiojbs sudo[2007]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 27 18:21:14 volumiojbs sudo[2007]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 18:21:14 volumiojbs sudo[2007]: pam_unix(sudo:session): session closed for user root Jun 27 18:21:14 volumiojbs sudo[2009]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 27 18:21:14 volumiojbs sudo[2009]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 27 18:21:14 volumiojbs sudo[2009]: pam_unix(sudo:session): session closed for user root Jun 27 18:21:14 volumiojbs volumio[964]: verbose: New Socket.io Connection to 192.168.1.75 from 192.168.1.66 UA: Mozilla/5.0 (Linux; Android 12; SM-G973F Build/SP1A.210812.016; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/137.0.7151.115 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Jun 27 18:21:15 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 27 18:21:15 volumiojbs volumio[964]: info: CoreCommandRouter::volumioGetVisibleSources Jun 27 18:21:15 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 27 18:21:15 volumiojbs volumio[964]: info: CoreCommandRouter::volumioGetState Jun 27 18:21:15 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 20 Jun 27 18:21:15 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jun 27 18:21:15 volumiojbs volumio[964]: info: CoreCommandRouter::volumioGetQueue Jun 27 18:21:15 volumiojbs volumio[964]: info: CoreStateMachine::getQueue Jun 27 18:21:15 volumiojbs volumio[964]: info: CorePlayQueue::getQueue Jun 27 18:21:15 volumiojbs volumio[964]: info: Listing playlists Jun 27 18:21:15 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 27 18:21:15 volumiojbs volumio[964]: info: Received Get System Info Jun 27 18:21:15 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 27 18:21:15 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 27 18:21:15 volumiojbs volumio[964]: info: Discovery: Getting this device information Jun 27 18:21:15 volumiojbs volumio[964]: info: CoreCommandRouter::volumioGetState Jun 27 18:21:15 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 20 Jun 27 18:21:15 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 27 18:21:15 volumiojbs volumio[964]: info: CoreCommandRouter::volumioGetState Jun 27 18:21:15 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 20 Jun 27 18:21:15 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jun 27 18:21:15 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 27 18:21:15 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jun 27 18:21:16 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jun 27 18:21:16 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 27 18:21:16 volumiojbs volumio[964]: info: Received Get System Info Jun 27 18:21:16 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 27 18:21:16 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 27 18:21:16 volumiojbs volumio[964]: info: Discovery: Getting this device information Jun 27 18:21:16 volumiojbs volumio[964]: info: CoreCommandRouter::volumioGetState Jun 27 18:21:16 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 20 Jun 27 18:21:16 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 27 18:21:17 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 27 18:21:17 volumiojbs volumio[964]: info: Received Get System Info Jun 27 18:21:17 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 27 18:21:17 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 27 18:21:17 volumiojbs volumio[964]: info: Discovery: Getting this device information Jun 27 18:21:17 volumiojbs volumio[964]: info: CoreCommandRouter::volumioGetState Jun 27 18:21:17 volumiojbs volumio[964]: info: CorePlayQueue::getTrack 20 Jun 27 18:21:17 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 27 18:21:23 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 27 18:21:23 volumiojbs volumio[964]: info: Preload queue cleared Jun 27 18:21:24 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jun 27 18:21:25 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 27 18:21:25 volumiojbs volumio[964]: info: Preload queue cleared Jun 27 18:21:26 volumiojbs go-librespot[1151]: time="2025-06-27T18:21:26Z" level=debug msg="fetched chunk 6/12, size: 524288" uri="spotify:track:262dMH9zpKTYhhGNZQjk4A" Jun 27 18:21:28 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 27 18:21:28 volumiojbs volumio[964]: info: Preload queue cleared Jun 27 18:21:29 volumiojbs volumio[964]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 27 18:21:30 volumiojbs volumio[964]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 27 18:21:30 volumiojbs volumio[964]: TypeError: Cannot read property 'length' of undefined Jun 27 18:21:30 volumiojbs volumio[964]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Jun 27 18:21:30 volumiojbs volumio[964]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Jun 27 18:21:30 volumiojbs volumio[964]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Jun 27 18:21:30 volumiojbs volumio[964]: at Parser.emit (events.js:315:20) Jun 27 18:21:30 volumiojbs volumio[964]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Jun 27 18:21:30 volumiojbs volumio[964]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Jun 27 18:21:30 volumiojbs volumio[964]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Jun 27 18:21:30 volumiojbs volumio[964]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Jun 27 18:21:30 volumiojbs volumio[964]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Jun 27 18:21:30 volumiojbs volumio[964]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Jun 27 18:21:30 volumiojbs volumio[964]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Jun 27 18:21:30 volumiojbs volumio[964]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Jun 27 18:21:30 volumiojbs volumio[964]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Jun 27 18:21:30 volumiojbs volumio[964]: at IncomingMessage.emit (events.js:327:22) Jun 27 18:21:30 volumiojbs volumio[964]: at endReadableNT (internal/streams/readable.js:1327:12) Jun 27 18:21:30 volumiojbs volumio[964]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jun 27 18:21:30 volumiojbs volumio[964]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 27 18:21:31 volumiojbs sudo[2043]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-27 18:20 Jun 27 18:21:31 volumiojbs sudo[2043]: 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="a142ed2648fb91920de0dde3a60cd39b5d0ba4f6" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 10 Jun 2025 04:52:53 PM CEST" VOLUMIO_VERSION="3.816" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="a72866a0de4045751d03a035de6290e1"