Aug 26 00:04:12 pi2 volumio[1209]: Searching plugin music_service/spop Aug 26 00:04:12 pi2 volumio[1209]: info: CoreCommandRouter::executeOnPlugin: spop , search Aug 26 00:04:12 pi2 volumio[1209]: info: All search sources collected, pushing search results Aug 26 00:04:13 pi2 volumio[1209]: Searching plugin music_service/spop Aug 26 00:04:13 pi2 volumio[1209]: info: CoreCommandRouter::executeOnPlugin: spop , search Aug 26 00:04:14 pi2 volumio[1209]: info: All search sources collected, pushing search results Aug 26 00:04:46 pi2 volumio[1209]: info: Preload queue cleared Aug 26 00:04:46 pi2 volumio[1209]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 26 00:04:46 pi2 volumio[1209]: info: CoreStateMachine::ClearQueue Aug 26 00:04:46 pi2 volumio[1209]: info: CoreStateMachine::stop Aug 26 00:04:46 pi2 volumio[1209]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 26 00:04:46 pi2 volumio[1209]: info: CoreStateMachine::stPlaybackTimer Aug 26 00:04:46 pi2 volumio[1209]: info: CoreStateMachine::updateTrackBlock Aug 26 00:04:46 pi2 volumio[1209]: info: CorePlayQueue::getTrackBlock Aug 26 00:04:46 pi2 volumio[1209]: info: CoreStateMachine::pushState Aug 26 00:04:46 pi2 volumio[1209]: info: CorePlayQueue::getTrack 7 Aug 26 00:04:46 pi2 volumio[1209]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 26 00:04:46 pi2 volumio[1209]: info: CoreCommandRouter::volumioPushState Aug 26 00:04:46 pi2 volumio[1209]: info: CoreStateMachine::serviceStop Aug 26 00:04:46 pi2 volumio[1209]: info: CorePlayQueue::getTrack 7 Aug 26 00:04:46 pi2 volumio[1209]: info: CoreCommandRouter::serviceStop Aug 26 00:04:46 pi2 volumio[1209]: info: ControllerMpd::stop Aug 26 00:04:46 pi2 volumio[1209]: verbose: ControllerMpd::sendMpdCommand stop Aug 26 00:04:46 pi2 volumio[1209]: info: CorePlayQueue::clearPlayQueue Aug 26 00:04:46 pi2 volumio[1209]: info: CorePlayQueue::saveQueue Aug 26 00:04:46 pi2 volumio[1209]: info: CoreCommandRouter::volumioPushQueue Aug 26 00:04:46 pi2 volumio[1209]: info: CoreStateMachine::addQueueItems Aug 26 00:04:46 pi2 volumio[1209]: info: CorePlayQueue::addQueueItems Aug 26 00:04:46 pi2 volumio[1209]: info: Preload queue cleared Aug 26 00:04:46 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:08mG3Y1vljYA6bvDt4Wqkj Aug 26 00:04:46 pi2 volumio[1209]: info: Exploding uri spotify:track:08mG3Y1vljYA6bvDt4Wqkj in service spop Aug 26 00:04:46 pi2 volumio[1209]: SPOTIFY: EXPLODING URI:spotify:track:08mG3Y1vljYA6bvDt4Wqkj Aug 26 00:04:46 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:57bgtoPSgt236HzfBOd8kj Aug 26 00:04:46 pi2 volumio[1209]: info: Exploding uri spotify:track:57bgtoPSgt236HzfBOd8kj in service spop Aug 26 00:04:46 pi2 volumio[1209]: SPOTIFY: EXPLODING URI:spotify:track:57bgtoPSgt236HzfBOd8kj Aug 26 00:04:46 pi2 volumio5-onboarding[1871]: time=2026-08-26T00:04:46.670-06:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.69:55311 @ 0x2e0e810" state=STATUS_STOPPED positionMs=0 volume=100 Aug 26 00:04:46 pi2 volumio5-onboarding[1871]: time=2026-08-26T00:04:46.674-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.69:55311 @ 0x2e0e810" id="mnt/USB/Volumio_2/2026 Pop Remix Spring/01 Dopamine (Jamie xx remix).m4a" title="Dopamine (Jamie xx remix)" Aug 26 00:04:46 pi2 volumio[1209]: info: Aug 26 00:04:46 pi2 volumio[1209]: ---------------------------- MPD announces state update: player Aug 26 00:04:46 pi2 volumio[1209]: info: sendMpdCommand stop took 79 milliseconds Aug 26 00:04:46 pi2 volumio[1209]: info: ControllerMpd::getState Aug 26 00:04:46 pi2 volumio[1209]: verbose: ControllerMpd::sendMpdCommand status Aug 26 00:04:46 pi2 volumio[1209]: info: Aug 26 00:04:46 pi2 volumio[1209]: ---------------------------- MPD announces state update: player Aug 26 00:04:46 pi2 volumio[1209]: info: ControllerMpd::getState Aug 26 00:04:46 pi2 volumio[1209]: verbose: ControllerMpd::sendMpdCommand status Aug 26 00:04:46 pi2 volumio[1209]: info: Aug 26 00:04:46 pi2 volumio[1209]: ---------------------------- MPD announces state update: player Aug 26 00:04:46 pi2 volumio[1209]: info: ControllerMpd::getState Aug 26 00:04:46 pi2 volumio[1209]: verbose: ControllerMpd::sendMpdCommand status Aug 26 00:04:46 pi2 volumio[1209]: info: sendMpdCommand status took 9 milliseconds Aug 26 00:04:46 pi2 volumio[1209]: info: sendMpdCommand status took 8 milliseconds Aug 26 00:04:46 pi2 volumio[1209]: info: sendMpdCommand status took 6 milliseconds Aug 26 00:04:46 pi2 volumio[1209]: verbose: ControllerMpd::parseState Aug 26 00:04:46 pi2 volumio[1209]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 26 00:04:46 pi2 volumio[1209]: verbose: ControllerMpd::parseState Aug 26 00:04:46 pi2 volumio[1209]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 26 00:04:46 pi2 volumio[1209]: verbose: ControllerMpd::parseState Aug 26 00:04:46 pi2 volumio[1209]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 26 00:04:46 pi2 volumio[1209]: info: sendMpdCommand playlistinfo took 5 milliseconds Aug 26 00:04:46 pi2 volumio[1209]: info: sendMpdCommand playlistinfo took 6 milliseconds Aug 26 00:04:46 pi2 volumio[1209]: verbose: ControllerMpd::parseTrackInfo Aug 26 00:04:46 pi2 volumio[1209]: verbose: ControllerMpd::parseTrackInfo Aug 26 00:04:46 pi2 volumio[1209]: info: ControllerMpd::pushState Aug 26 00:04:46 pi2 volumio[1209]: info: CoreCommandRouter::servicePushState Aug 26 00:04:46 pi2 volumio[1209]: info: CoreStateMachine::pushState Aug 26 00:04:46 pi2 volumio[1209]: info: CorePlayQueue::getTrack 7 Aug 26 00:04:46 pi2 volumio[1209]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 26 00:04:46 pi2 volumio[1209]: info: CoreCommandRouter::volumioPushState Aug 26 00:04:46 pi2 volumio[1209]: info: CorePlayQueue::getTrack 7 Aug 26 00:04:46 pi2 volumio[1209]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Dopamine (Jamie xx remix)","artist":"Robyn","album":"Dopamine (Jamie xx remix) - Single","uri":"USB/Volumio_2/2026 Pop Remix Spring/01 Dopamine (Jamie xx remix).m4a","trackType":"m4a"} Aug 26 00:04:46 pi2 volumio[1209]: verbose: CURRENT POSITION 7 Aug 26 00:04:46 pi2 volumio[1209]: info: CoreStateMachine::syncState stateService stop Aug 26 00:04:46 pi2 volumio[1209]: info: CoreStateMachine::syncState currentStatus stop Aug 26 00:04:46 pi2 volumio[1209]: info: CoreStateMachine::pushState Aug 26 00:04:46 pi2 volumio[1209]: info: CorePlayQueue::getTrack 7 Aug 26 00:04:46 pi2 volumio[1209]: info: CoreCommandRouter::volumioPushState Aug 26 00:04:46 pi2 volumio[1209]: info: No code Aug 26 00:04:46 pi2 volumio[1209]: info: CoreStateMachine::pushState Aug 26 00:04:46 pi2 volumio[1209]: info: CorePlayQueue::getTrack 7 Aug 26 00:04:46 pi2 volumio[1209]: info: CoreCommandRouter::volumioPushState Aug 26 00:04:46 pi2 volumio[1209]: info: ControllerMpd::pushState Aug 26 00:04:46 pi2 volumio[1209]: info: CoreCommandRouter::servicePushState Aug 26 00:04:46 pi2 volumio[1209]: info: CoreStateMachine::pushState Aug 26 00:04:46 pi2 volumio[1209]: info: CorePlayQueue::getTrack 7 Aug 26 00:04:46 pi2 volumio[1209]: info: CoreCommandRouter::volumioPushState Aug 26 00:04:46 pi2 volumio[1209]: info: CorePlayQueue::getTrack 7 Aug 26 00:04:46 pi2 volumio[1209]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Dopamine (Jamie xx remix)","artist":"Robyn","album":"Dopamine (Jamie xx remix) - Single","uri":"USB/Volumio_2/2026 Pop Remix Spring/01 Dopamine (Jamie xx remix).m4a","trackType":"m4a"} Aug 26 00:04:46 pi2 volumio[1209]: verbose: CURRENT POSITION 7 Aug 26 00:04:46 pi2 volumio[1209]: info: CoreStateMachine::syncState stateService stop Aug 26 00:04:46 pi2 volumio[1209]: info: CoreStateMachine::syncState currentStatus stop Aug 26 00:04:46 pi2 volumio[1209]: info: CoreStateMachine::pushState Aug 26 00:04:46 pi2 volumio[1209]: info: CorePlayQueue::getTrack 7 Aug 26 00:04:46 pi2 volumio[1209]: info: CoreCommandRouter::volumioPushState Aug 26 00:04:46 pi2 volumio[1209]: info: No code Aug 26 00:04:46 pi2 volumio[1209]: info: CoreStateMachine::pushState Aug 26 00:04:46 pi2 volumio[1209]: info: CorePlayQueue::getTrack 7 Aug 26 00:04:46 pi2 volumio[1209]: info: CoreCommandRouter::volumioPushState Aug 26 00:04:46 pi2 volumio5-onboarding[1871]: time=2026-08-26T00:04:46.804-06:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.69:55311 @ 0x2e0e810" state=STATUS_STOPPED positionMs=0 volume=100 Aug 26 00:04:46 pi2 volumio5-onboarding[1871]: time=2026-08-26T00:04:46.804-06:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.69:55311 @ 0x2e0e810" state=STATUS_STOPPED positionMs=0 volume=100 Aug 26 00:04:46 pi2 volumio5-onboarding[1871]: time=2026-08-26T00:04:46.805-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.69:55311 @ 0x2e0e810" id= title= Aug 26 00:04:46 pi2 volumio5-onboarding[1871]: time=2026-08-26T00:04:46.805-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.69:55311 @ 0x2e0e810" id= title= Aug 26 00:04:46 pi2 volumio5-onboarding[1871]: time=2026-08-26T00:04:46.818-06:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.69:55311 @ 0x2e0e810" state=STATUS_STOPPED positionMs=0 volume=100 Aug 26 00:04:46 pi2 volumio5-onboarding[1871]: time=2026-08-26T00:04:46.818-06:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.69:55311 @ 0x2e0e810" state=STATUS_STOPPED positionMs=0 volume=100 Aug 26 00:04:46 pi2 volumio5-onboarding[1871]: time=2026-08-26T00:04:46.824-06:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.69:55311 @ 0x2e0e810" state=STATUS_STOPPED positionMs=0 volume=100 Aug 26 00:04:46 pi2 volumio5-onboarding[1871]: time=2026-08-26T00:04:46.825-06:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.69:55311 @ 0x2e0e810" state=STATUS_STOPPED positionMs=0 volume=100 Aug 26 00:04:46 pi2 volumio5-onboarding[1871]: time=2026-08-26T00:04:46.826-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.69:55311 @ 0x2e0e810" id= title= Aug 26 00:04:46 pi2 volumio5-onboarding[1871]: time=2026-08-26T00:04:46.827-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.69:55311 @ 0x2e0e810" id= title= Aug 26 00:04:46 pi2 volumio5-onboarding[1871]: time=2026-08-26T00:04:46.832-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.69:55311 @ 0x2e0e810" id= title= Aug 26 00:04:46 pi2 volumio5-onboarding[1871]: time=2026-08-26T00:04:46.834-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.69:55311 @ 0x2e0e810" id= title= Aug 26 00:04:46 pi2 volumio[1209]: info: ------------------------------ 102ms Aug 26 00:04:46 pi2 volumio[1209]: info: ------------------------------ 103ms Aug 26 00:04:46 pi2 volumio[1209]: info: sendMpdCommand playlistinfo took 95 milliseconds Aug 26 00:04:46 pi2 volumio[1209]: verbose: ControllerMpd::parseTrackInfo Aug 26 00:04:46 pi2 volumio[1209]: info: ControllerMpd::pushState Aug 26 00:04:46 pi2 volumio[1209]: info: CoreCommandRouter::servicePushState Aug 26 00:04:46 pi2 volumio[1209]: info: CoreStateMachine::pushState Aug 26 00:04:46 pi2 volumio[1209]: info: CorePlayQueue::getTrack 7 Aug 26 00:04:46 pi2 volumio[1209]: info: CoreCommandRouter::volumioPushState Aug 26 00:04:46 pi2 volumio[1209]: info: CorePlayQueue::getTrack 7 Aug 26 00:04:46 pi2 volumio[1209]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Dopamine (Jamie xx remix)","artist":"Robyn","album":"Dopamine (Jamie xx remix) - Single","uri":"USB/Volumio_2/2026 Pop Remix Spring/01 Dopamine (Jamie xx remix).m4a","trackType":"m4a"} Aug 26 00:04:46 pi2 volumio[1209]: verbose: CURRENT POSITION 7 Aug 26 00:04:46 pi2 volumio[1209]: info: CoreStateMachine::syncState stateService stop Aug 26 00:04:46 pi2 volumio[1209]: info: CoreStateMachine::syncState currentStatus stop Aug 26 00:04:46 pi2 volumio[1209]: info: CoreStateMachine::pushState Aug 26 00:04:46 pi2 volumio[1209]: info: CorePlayQueue::getTrack 7 Aug 26 00:04:46 pi2 volumio[1209]: info: CoreCommandRouter::volumioPushState Aug 26 00:04:46 pi2 volumio[1209]: info: No code Aug 26 00:04:46 pi2 volumio[1209]: info: CoreStateMachine::pushState Aug 26 00:04:46 pi2 volumio[1209]: info: CorePlayQueue::getTrack 7 Aug 26 00:04:46 pi2 volumio[1209]: info: CoreCommandRouter::volumioPushState Aug 26 00:04:46 pi2 volumio5-onboarding[1871]: time=2026-08-26T00:04:46.867-06:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.69:55311 @ 0x2e0e810" state=STATUS_STOPPED positionMs=0 volume=100 Aug 26 00:04:46 pi2 volumio5-onboarding[1871]: time=2026-08-26T00:04:46.868-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.69:55311 @ 0x2e0e810" id= title= Aug 26 00:04:46 pi2 volumio5-onboarding[1871]: time=2026-08-26T00:04:46.868-06:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.69:55311 @ 0x2e0e810" state=STATUS_STOPPED positionMs=0 volume=100 Aug 26 00:04:46 pi2 volumio5-onboarding[1871]: time=2026-08-26T00:04:46.869-06:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.69:55311 @ 0x2e0e810" state=STATUS_STOPPED positionMs=0 volume=100 Aug 26 00:04:46 pi2 volumio5-onboarding[1871]: time=2026-08-26T00:04:46.874-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.69:55311 @ 0x2e0e810" id= title= Aug 26 00:04:46 pi2 volumio5-onboarding[1871]: time=2026-08-26T00:04:46.874-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.69:55311 @ 0x2e0e810" id= title= Aug 26 00:04:46 pi2 volumio[1209]: info: ------------------------------ 144ms Aug 26 00:04:47 pi2 volumio[1209]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:08mG3Y1vljYA6bvDt4Wqkj","service":"spop","name":"Back In Black","artist":"AC/DC","album":"Back In Black","type":"song","duration":256,"albumart":"https://i.scdn.co/image/ab67616d0000b273ff191d7fbdb5a13eaf84132b","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 26 00:04:47 pi2 volumio[1209]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:57bgtoPSgt236HzfBOd8kj","service":"spop","name":"Thunderstruck","artist":"AC/DC","album":"The Razors Edge","type":"song","duration":292,"albumart":"https://i.scdn.co/image/ab67616d0000b2739a9b1cc067e4460da04adce2","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 26 00:04:47 pi2 volumio[1209]: info: CoreCommandRouter::volumioPushQueue Aug 26 00:04:47 pi2 volumio[1209]: info: CorePlayQueue::saveQueue Aug 26 00:04:47 pi2 volumio[1209]: info: CoreStateMachine::updateTrackBlock Aug 26 00:04:47 pi2 volumio[1209]: info: CorePlayQueue::getTrackBlock Aug 26 00:04:47 pi2 volumio[1209]: info: CoreCommandRouter::volumioPlay Aug 26 00:04:47 pi2 volumio[1209]: info: CoreStateMachine::play index 1 Aug 26 00:04:47 pi2 volumio[1209]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 26 00:04:47 pi2 volumio[1209]: info: CoreStateMachine::addQueueItems Aug 26 00:04:47 pi2 volumio[1209]: info: CorePlayQueue::addQueueItems Aug 26 00:04:47 pi2 volumio[1209]: info: Preload queue cleared Aug 26 00:04:47 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:2iEGj7kAwH7HAa5epwYwLB Aug 26 00:04:47 pi2 volumio[1209]: info: Exploding uri spotify:track:2iEGj7kAwH7HAa5epwYwLB in service spop Aug 26 00:04:47 pi2 volumio[1209]: SPOTIFY: EXPLODING URI:spotify:track:2iEGj7kAwH7HAa5epwYwLB Aug 26 00:04:47 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:30FURVTCpbKyykjSEQzGkH Aug 26 00:04:47 pi2 volumio[1209]: info: Exploding uri spotify:track:30FURVTCpbKyykjSEQzGkH in service spop Aug 26 00:04:47 pi2 volumio[1209]: SPOTIFY: EXPLODING URI:spotify:track:30FURVTCpbKyykjSEQzGkH Aug 26 00:04:47 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:3dPQuX8Gs42Y7b454ybpMR Aug 26 00:04:47 pi2 volumio[1209]: info: Exploding uri spotify:track:3dPQuX8Gs42Y7b454ybpMR in service spop Aug 26 00:04:47 pi2 volumio[1209]: SPOTIFY: EXPLODING URI:spotify:track:3dPQuX8Gs42Y7b454ybpMR Aug 26 00:04:47 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:2P884dqfjksDMSzUZksfrS Aug 26 00:04:47 pi2 volumio[1209]: info: Exploding uri spotify:track:2P884dqfjksDMSzUZksfrS in service spop Aug 26 00:04:47 pi2 volumio[1209]: SPOTIFY: EXPLODING URI:spotify:track:2P884dqfjksDMSzUZksfrS Aug 26 00:04:47 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:69QHm3pustz01CJRwdo20z Aug 26 00:04:47 pi2 volumio[1209]: info: Exploding uri spotify:track:69QHm3pustz01CJRwdo20z in service spop Aug 26 00:04:47 pi2 volumio[1209]: SPOTIFY: EXPLODING URI:spotify:track:69QHm3pustz01CJRwdo20z Aug 26 00:04:47 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:2SiXAy7TuUkycRVbbWDEpo Aug 26 00:04:47 pi2 volumio[1209]: info: Exploding uri spotify:track:2SiXAy7TuUkycRVbbWDEpo in service spop Aug 26 00:04:47 pi2 volumio[1209]: SPOTIFY: EXPLODING URI:spotify:track:2SiXAy7TuUkycRVbbWDEpo Aug 26 00:04:47 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:0C80GCp0mMuBzLf3EAXqxv Aug 26 00:04:47 pi2 volumio[1209]: info: Exploding uri spotify:track:0C80GCp0mMuBzLf3EAXqxv in service spop Aug 26 00:04:47 pi2 volumio[1209]: SPOTIFY: EXPLODING URI:spotify:track:0C80GCp0mMuBzLf3EAXqxv Aug 26 00:04:47 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:7mocbWQc7a3Y7AOZNUpRJC Aug 26 00:04:47 pi2 volumio[1209]: info: Exploding uri spotify:track:7mocbWQc7a3Y7AOZNUpRJC in service spop Aug 26 00:04:47 pi2 volumio[1209]: SPOTIFY: EXPLODING URI:spotify:track:7mocbWQc7a3Y7AOZNUpRJC Aug 26 00:04:47 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:7ldGijnKCC5aN7HHUfSnp4 Aug 26 00:04:47 pi2 volumio[1209]: info: Exploding uri spotify:track:7ldGijnKCC5aN7HHUfSnp4 in service spop Aug 26 00:04:47 pi2 volumio[1209]: SPOTIFY: EXPLODING URI:spotify:track:7ldGijnKCC5aN7HHUfSnp4 Aug 26 00:04:47 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:3qhlB30KknSejmIvZZLjOD Aug 26 00:04:47 pi2 volumio[1209]: info: Exploding uri spotify:track:3qhlB30KknSejmIvZZLjOD in service spop Aug 26 00:04:47 pi2 volumio[1209]: SPOTIFY: EXPLODING URI:spotify:track:3qhlB30KknSejmIvZZLjOD Aug 26 00:04:47 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:3WPYapjyqcVpShYXQuChcs Aug 26 00:04:47 pi2 volumio[1209]: info: Exploding uri spotify:track:3WPYapjyqcVpShYXQuChcs in service spop Aug 26 00:04:47 pi2 volumio[1209]: SPOTIFY: EXPLODING URI:spotify:track:3WPYapjyqcVpShYXQuChcs Aug 26 00:04:47 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:2U2ONBrf1HJCDxQlynpD6J Aug 26 00:04:47 pi2 volumio[1209]: info: Exploding uri spotify:track:2U2ONBrf1HJCDxQlynpD6J in service spop Aug 26 00:04:47 pi2 volumio[1209]: SPOTIFY: EXPLODING URI:spotify:track:2U2ONBrf1HJCDxQlynpD6J Aug 26 00:04:47 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:3eQlGeyuSibgAGPEJugaDW Aug 26 00:04:47 pi2 volumio[1209]: info: Exploding uri spotify:track:3eQlGeyuSibgAGPEJugaDW in service spop Aug 26 00:04:47 pi2 volumio[1209]: SPOTIFY: EXPLODING URI:spotify:track:3eQlGeyuSibgAGPEJugaDW Aug 26 00:04:47 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:7oI0ieXKsWdBxSgEsYSYxI Aug 26 00:04:47 pi2 volumio[1209]: info: Exploding uri spotify:track:7oI0ieXKsWdBxSgEsYSYxI in service spop Aug 26 00:04:47 pi2 volumio[1209]: SPOTIFY: EXPLODING URI:spotify:track:7oI0ieXKsWdBxSgEsYSYxI Aug 26 00:04:47 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:1yiPNrjkKr523bZnVNvxlK Aug 26 00:04:47 pi2 volumio[1209]: info: Exploding uri spotify:track:1yiPNrjkKr523bZnVNvxlK in service spop Aug 26 00:04:47 pi2 volumio[1209]: SPOTIFY: EXPLODING URI:spotify:track:1yiPNrjkKr523bZnVNvxlK Aug 26 00:04:47 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:4OgwXdylh75fHfwUzJTUqg Aug 26 00:04:47 pi2 volumio[1209]: info: Exploding uri spotify:track:4OgwXdylh75fHfwUzJTUqg in service spop Aug 26 00:04:47 pi2 volumio[1209]: SPOTIFY: EXPLODING URI:spotify:track:4OgwXdylh75fHfwUzJTUqg Aug 26 00:04:47 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:7BAKWjphDrXRP6ygmxicfg Aug 26 00:04:47 pi2 volumio[1209]: info: Exploding uri spotify:track:7BAKWjphDrXRP6ygmxicfg in service spop Aug 26 00:04:47 pi2 volumio[1209]: SPOTIFY: EXPLODING URI:spotify:track:7BAKWjphDrXRP6ygmxicfg Aug 26 00:04:47 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:0d1pu1YYdXKvfx7LOW6ym3 Aug 26 00:04:47 pi2 volumio[1209]: info: Exploding uri spotify:track:0d1pu1YYdXKvfx7LOW6ym3 in service spop Aug 26 00:04:47 pi2 volumio[1209]: SPOTIFY: EXPLODING URI:spotify:track:0d1pu1YYdXKvfx7LOW6ym3 Aug 26 00:04:47 pi2 volumio[1209]: info: CoreStateMachine::stop Aug 26 00:04:47 pi2 volumio[1209]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 26 00:04:47 pi2 volumio[1209]: info: CoreStateMachine::play index undefined Aug 26 00:04:47 pi2 volumio[1209]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 26 00:04:47 pi2 volumio[1209]: info: CorePlayQueue::getTrack 1 Aug 26 00:04:47 pi2 volumio[1209]: info: CoreStateMachine::startPlaybackTimer Aug 26 00:04:47 pi2 volumio[1209]: info: CorePlayQueue::getTrack 1 Aug 26 00:04:47 pi2 volumio[1209]: info: [1787724287252] ControllerSpotify::clearAddPlayTrack Aug 26 00:04:47 pi2 volumio[1209]: info: Sending Spotify command with payload to local API: /player/play Aug 26 00:04:47 pi2 go-librespot[1734]: time="2026-08-26T00:04:47-06:00" level=debug msg="renewing login5 access token" Aug 26 00:04:47 pi2 go-librespot[1734]: time="2026-08-26T00:04:47-06:00" level=error msg="failed handling request play" error="failed resolving context: spclient request failed: failed obtaining spclient access token: failed renewing login5 access token: failed authenticating with login5: UNKNOWN_ERROR" Aug 26 00:04:48 pi2 volumio[1209]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Aug 26 00:04:48 pi2 volumio[1209]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7mocbWQc7a3Y7AOZNUpRJC","service":"spop","name":"Back in Black","artist":"Back In Black","album":"Back in Black","type":"song","duration":231,"albumart":"https://i.scdn.co/image/ab67616d0000b2733ad5858333ae0ddaae61e5df","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 26 00:04:48 pi2 volumio[1209]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3qhlB30KknSejmIvZZLjOD","service":"spop","name":"End of Beginning","artist":"Djo","album":"DECIDE","type":"song","duration":159,"albumart":"https://i.scdn.co/image/ab67616d0000b273fddfffec51b4580acae727c1","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 26 00:04:48 pi2 volumio[1209]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7ldGijnKCC5aN7HHUfSnp4","service":"spop","name":"Back in Black (Soul)","artist":"FAKE MUSIC","album":"Back in Black (Soul)","type":"song","duration":260,"albumart":"https://i.scdn.co/image/ab67616d0000b27358c54197d059e8530aa72712","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 26 00:04:48 pi2 volumio[1209]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2P884dqfjksDMSzUZksfrS","service":"spop","name":"Hells Bells","artist":"AC/DC","album":"Who Made Who","type":"song","duration":313,"albumart":"https://i.scdn.co/image/ab67616d0000b2734338785835437128f20a57fb","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 26 00:04:48 pi2 volumio[1209]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3dPQuX8Gs42Y7b454ybpMR","service":"spop","name":"Seven Nation Army","artist":"The White Stripes","album":"Elephant","type":"song","duration":232,"albumart":"https://i.scdn.co/image/ab67616d0000b2737028981d09d2e5833c9c78ad","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 26 00:04:48 pi2 volumio[1209]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:69QHm3pustz01CJRwdo20z","service":"spop","name":"Hells Bells","artist":"AC/DC","album":"Back In Black","type":"song","duration":312,"albumart":"https://i.scdn.co/image/ab67616d0000b273ff191d7fbdb5a13eaf84132b","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 26 00:04:48 pi2 volumio[1209]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7oI0ieXKsWdBxSgEsYSYxI","service":"spop","name":"Chipz in Black (Who You Gonna Call)","artist":"CDM Project","album":"Chipz in Black (Who You Gonna Call)","type":"song","duration":182,"albumart":"https://i.scdn.co/image/ab67616d0000b273e99a447070145ae1151beb03","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 26 00:04:48 pi2 volumio[1209]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3eQlGeyuSibgAGPEJugaDW","service":"spop","name":"Back in Time - featured in \"Men In Black 3\"","artist":"Pitbull","album":"Global Warming: Meltdown (Deluxe Version)","type":"song","duration":207,"albumart":"https://i.scdn.co/image/ab67616d0000b2732ffc2c580b6595a3e675a730","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 26 00:04:48 pi2 volumio[1209]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2U2ONBrf1HJCDxQlynpD6J","service":"spop","name":"Back in Time - featured in \"Men In Black 3\"","artist":"Pitbull","album":"Back in Time (featured in \"Men In Black 3\")","type":"song","duration":205,"albumart":"https://i.scdn.co/image/ab67616d0000b2731c7b77b961f8cd84326eb31f","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 26 00:04:48 pi2 volumio[1209]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0d1pu1YYdXKvfx7LOW6ym3","service":"spop","name":"Africville’s Revenge","artist":"Cadence Weapon","album":"Parallel World (Deluxe Edition)","type":"song","duration":86,"albumart":"https://i.scdn.co/image/ab67616d0000b273918ba4149c6b3e33cbfd27f2","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 26 00:04:48 pi2 volumio[1209]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3WPYapjyqcVpShYXQuChcs","service":"spop","name":"Back In the Saddle","artist":"Aerosmith","album":"Rocks","type":"song","duration":280,"albumart":"https://i.scdn.co/image/ab67616d0000b273763da84add664535b418ffb7","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 26 00:04:48 pi2 volumio[1209]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2SiXAy7TuUkycRVbbWDEpo","service":"spop","name":"You Shook Me All Night Long","artist":"AC/DC","album":"Back In Black","type":"song","duration":210,"albumart":"https://i.scdn.co/image/ab67616d0000b273ff191d7fbdb5a13eaf84132b","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 26 00:04:48 pi2 volumio[1209]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1yiPNrjkKr523bZnVNvxlK","service":"spop","name":"Chipz in Black (Who You Gonna Call)","artist":"CDM Project","album":"Groove Riders - Dance Dance Dance","type":"song","duration":182,"albumart":"https://i.scdn.co/image/ab67616d0000b27395c7255dbd4c8e664fd16c1b","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 26 00:04:48 pi2 volumio[1209]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0C80GCp0mMuBzLf3EAXqxv","service":"spop","name":"Shoot to Thrill","artist":"AC/DC","album":"Back In Black","type":"song","duration":318,"albumart":"https://i.scdn.co/image/ab67616d0000b273ff191d7fbdb5a13eaf84132b","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 26 00:04:48 pi2 volumio[1209]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4OgwXdylh75fHfwUzJTUqg","service":"spop","name":"Rockstar","artist":"Ilkay Sencan","album":"Rockstar","type":"song","duration":212,"albumart":"https://i.scdn.co/image/ab67616d0000b27397c8043dfc435740a467d0d7","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 26 00:04:48 pi2 volumio[1209]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2iEGj7kAwH7HAa5epwYwLB","service":"spop","name":"Back In Black","artist":"AC/DC","album":"Iron Man 2","type":"song","duration":257,"albumart":"https://i.scdn.co/image/ab67616d0000b27302df8239ad8626aa7acc144b","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 26 00:04:48 pi2 volumio[1209]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:30FURVTCpbKyykjSEQzGkH","service":"spop","name":"Back To Black","artist":"Amy Winehouse","album":"Back To Black","type":"song","duration":240,"albumart":"https://i.scdn.co/image/ab67616d0000b273dc65d5638a3de4a0bdf3c05f","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 26 00:04:48 pi2 volumio[1209]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7BAKWjphDrXRP6ygmxicfg","service":"spop","name":"Africville’s Revenge","artist":"Cadence Weapon","album":"Parallel World","type":"song","duration":86,"albumart":"https://i.scdn.co/image/ab67616d0000b273fa8d172597a33143fdeae54b","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 26 00:04:48 pi2 volumio[1209]: info: CoreCommandRouter::volumioPushQueue Aug 26 00:04:48 pi2 volumio[1209]: info: CorePlayQueue::saveQueue Aug 26 00:04:48 pi2 volumio[1209]: info: CoreStateMachine::updateTrackBlock Aug 26 00:04:48 pi2 volumio[1209]: info: CorePlayQueue::getTrackBlock Aug 26 00:04:50 pi2 volumio[1209]: info: Preload queue cleared Aug 26 00:04:50 pi2 volumio[1209]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 26 00:04:50 pi2 volumio[1209]: info: CoreStateMachine::ClearQueue Aug 26 00:04:50 pi2 volumio[1209]: info: CoreStateMachine::stop Aug 26 00:04:50 pi2 volumio[1209]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 26 00:04:50 pi2 volumio[1209]: info: CorePlayQueue::clearPlayQueue Aug 26 00:04:50 pi2 volumio[1209]: info: CorePlayQueue::saveQueue Aug 26 00:04:50 pi2 volumio[1209]: info: CoreCommandRouter::volumioPushQueue Aug 26 00:04:50 pi2 volumio[1209]: info: CoreStateMachine::addQueueItems Aug 26 00:04:50 pi2 volumio[1209]: info: CorePlayQueue::addQueueItems Aug 26 00:04:50 pi2 volumio[1209]: info: Preload queue cleared Aug 26 00:04:50 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:08mG3Y1vljYA6bvDt4Wqkj Aug 26 00:04:50 pi2 volumio[1209]: info: Using cached record of: spotify:track:08mG3Y1vljYA6bvDt4Wqkj Aug 26 00:04:50 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:57bgtoPSgt236HzfBOd8kj Aug 26 00:04:50 pi2 volumio[1209]: info: Using cached record of: spotify:track:57bgtoPSgt236HzfBOd8kj Aug 26 00:04:50 pi2 volumio[1209]: info: CoreCommandRouter::volumioPushQueue Aug 26 00:04:50 pi2 volumio[1209]: info: CorePlayQueue::saveQueue Aug 26 00:04:50 pi2 volumio[1209]: info: CoreStateMachine::updateTrackBlock Aug 26 00:04:50 pi2 volumio[1209]: info: CorePlayQueue::getTrackBlock Aug 26 00:04:50 pi2 volumio[1209]: info: CoreCommandRouter::volumioPlay Aug 26 00:04:50 pi2 volumio[1209]: info: CoreStateMachine::play index 1 Aug 26 00:04:50 pi2 volumio[1209]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 26 00:04:50 pi2 volumio[1209]: info: CoreStateMachine::addQueueItems Aug 26 00:04:50 pi2 volumio[1209]: info: CorePlayQueue::addQueueItems Aug 26 00:04:50 pi2 volumio[1209]: info: Preload queue cleared Aug 26 00:04:50 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:2iEGj7kAwH7HAa5epwYwLB Aug 26 00:04:50 pi2 volumio[1209]: info: Using cached record of: spotify:track:2iEGj7kAwH7HAa5epwYwLB Aug 26 00:04:50 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:30FURVTCpbKyykjSEQzGkH Aug 26 00:04:50 pi2 volumio[1209]: info: Using cached record of: spotify:track:30FURVTCpbKyykjSEQzGkH Aug 26 00:04:50 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:3dPQuX8Gs42Y7b454ybpMR Aug 26 00:04:50 pi2 volumio[1209]: info: Using cached record of: spotify:track:3dPQuX8Gs42Y7b454ybpMR Aug 26 00:04:50 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:2P884dqfjksDMSzUZksfrS Aug 26 00:04:50 pi2 volumio[1209]: info: Using cached record of: spotify:track:2P884dqfjksDMSzUZksfrS Aug 26 00:04:50 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:69QHm3pustz01CJRwdo20z Aug 26 00:04:50 pi2 volumio[1209]: info: Using cached record of: spotify:track:69QHm3pustz01CJRwdo20z Aug 26 00:04:50 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:2SiXAy7TuUkycRVbbWDEpo Aug 26 00:04:50 pi2 volumio[1209]: info: Using cached record of: spotify:track:2SiXAy7TuUkycRVbbWDEpo Aug 26 00:04:50 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:0C80GCp0mMuBzLf3EAXqxv Aug 26 00:04:50 pi2 volumio[1209]: info: Using cached record of: spotify:track:0C80GCp0mMuBzLf3EAXqxv Aug 26 00:04:50 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:7mocbWQc7a3Y7AOZNUpRJC Aug 26 00:04:50 pi2 volumio[1209]: info: Using cached record of: spotify:track:7mocbWQc7a3Y7AOZNUpRJC Aug 26 00:04:50 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:7ldGijnKCC5aN7HHUfSnp4 Aug 26 00:04:50 pi2 volumio[1209]: info: Using cached record of: spotify:track:7ldGijnKCC5aN7HHUfSnp4 Aug 26 00:04:50 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:3qhlB30KknSejmIvZZLjOD Aug 26 00:04:50 pi2 volumio[1209]: info: Using cached record of: spotify:track:3qhlB30KknSejmIvZZLjOD Aug 26 00:04:50 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:3WPYapjyqcVpShYXQuChcs Aug 26 00:04:50 pi2 volumio[1209]: info: Using cached record of: spotify:track:3WPYapjyqcVpShYXQuChcs Aug 26 00:04:50 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:2U2ONBrf1HJCDxQlynpD6J Aug 26 00:04:50 pi2 volumio[1209]: info: Using cached record of: spotify:track:2U2ONBrf1HJCDxQlynpD6J Aug 26 00:04:50 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:3eQlGeyuSibgAGPEJugaDW Aug 26 00:04:50 pi2 volumio[1209]: info: Using cached record of: spotify:track:3eQlGeyuSibgAGPEJugaDW Aug 26 00:04:50 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:7oI0ieXKsWdBxSgEsYSYxI Aug 26 00:04:50 pi2 volumio[1209]: info: Using cached record of: spotify:track:7oI0ieXKsWdBxSgEsYSYxI Aug 26 00:04:50 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:1yiPNrjkKr523bZnVNvxlK Aug 26 00:04:50 pi2 volumio[1209]: info: Using cached record of: spotify:track:1yiPNrjkKr523bZnVNvxlK Aug 26 00:04:50 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:4OgwXdylh75fHfwUzJTUqg Aug 26 00:04:50 pi2 volumio[1209]: info: Using cached record of: spotify:track:4OgwXdylh75fHfwUzJTUqg Aug 26 00:04:50 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:7BAKWjphDrXRP6ygmxicfg Aug 26 00:04:50 pi2 volumio[1209]: info: Using cached record of: spotify:track:7BAKWjphDrXRP6ygmxicfg Aug 26 00:04:50 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:0d1pu1YYdXKvfx7LOW6ym3 Aug 26 00:04:50 pi2 volumio[1209]: info: Using cached record of: spotify:track:0d1pu1YYdXKvfx7LOW6ym3 Aug 26 00:04:50 pi2 volumio[1209]: info: CoreStateMachine::stop Aug 26 00:04:50 pi2 volumio[1209]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 26 00:04:50 pi2 volumio[1209]: info: CoreCommandRouter::volumioPushQueue Aug 26 00:04:50 pi2 volumio[1209]: info: CorePlayQueue::saveQueue Aug 26 00:04:50 pi2 volumio[1209]: info: CoreStateMachine::play index undefined Aug 26 00:04:50 pi2 volumio[1209]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 26 00:04:50 pi2 volumio[1209]: info: CoreStateMachine::updateTrackBlock Aug 26 00:04:50 pi2 volumio[1209]: info: CorePlayQueue::getTrackBlock Aug 26 00:04:50 pi2 volumio[1209]: info: CorePlayQueue::getTrack 1 Aug 26 00:04:50 pi2 volumio[1209]: info: CoreStateMachine::startPlaybackTimer Aug 26 00:04:50 pi2 volumio[1209]: info: CorePlayQueue::getTrack 1 Aug 26 00:04:50 pi2 volumio[1209]: info: [1787724290662] ControllerSpotify::clearAddPlayTrack Aug 26 00:04:50 pi2 volumio[1209]: info: Sending Spotify command with payload to local API: /player/play Aug 26 00:04:50 pi2 go-librespot[1734]: time="2026-08-26T00:04:50-06:00" level=debug msg="renewing login5 access token" Aug 26 00:04:50 pi2 go-librespot[1734]: time="2026-08-26T00:04:50-06:00" level=error msg="failed handling request play" error="failed resolving context: spclient request failed: failed obtaining spclient access token: failed renewing login5 access token: failed authenticating with login5: UNKNOWN_ERROR" Aug 26 00:04:50 pi2 volumio[1209]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Aug 26 00:04:51 pi2 volumio[1209]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 00:04:51 pi2 volumio[1209]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 00:04:51 pi2 volumio[1209]: info: Discovery: Getting this device information Aug 26 00:04:51 pi2 volumio[1209]: info: CoreCommandRouter::volumioGetState Aug 26 00:04:51 pi2 volumio[1209]: info: CorePlayQueue::getTrack 1 Aug 26 00:04:51 pi2 volumio[1209]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 00:04:51 pi2 volumio[1209]: verbose: New Socket.io Connection to 192.168.1.77:3000 from 192.168.1.69 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 8 Aug 26 00:04:51 pi2 volumio[1209]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 26 00:04:51 pi2 volumio[1209]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 26 00:04:53 pi2 volumio[1209]: info: Preload queue cleared Aug 26 00:04:53 pi2 volumio[1209]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 26 00:04:53 pi2 volumio[1209]: info: CoreStateMachine::ClearQueue Aug 26 00:04:53 pi2 volumio[1209]: info: CoreStateMachine::stop Aug 26 00:04:53 pi2 volumio[1209]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 26 00:04:53 pi2 volumio[1209]: info: CorePlayQueue::clearPlayQueue Aug 26 00:04:53 pi2 volumio[1209]: info: CorePlayQueue::saveQueue Aug 26 00:04:53 pi2 volumio[1209]: info: CoreCommandRouter::volumioPushQueue Aug 26 00:04:53 pi2 volumio[1209]: info: CoreStateMachine::addQueueItems Aug 26 00:04:53 pi2 volumio[1209]: info: CorePlayQueue::addQueueItems Aug 26 00:04:53 pi2 volumio[1209]: info: Preload queue cleared Aug 26 00:04:53 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:08mG3Y1vljYA6bvDt4Wqkj Aug 26 00:04:53 pi2 volumio[1209]: info: Using cached record of: spotify:track:08mG3Y1vljYA6bvDt4Wqkj Aug 26 00:04:53 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:57bgtoPSgt236HzfBOd8kj Aug 26 00:04:53 pi2 volumio[1209]: info: Using cached record of: spotify:track:57bgtoPSgt236HzfBOd8kj Aug 26 00:04:53 pi2 volumio[1209]: info: CoreCommandRouter::volumioPushQueue Aug 26 00:04:53 pi2 volumio[1209]: info: CorePlayQueue::saveQueue Aug 26 00:04:53 pi2 volumio[1209]: info: CoreStateMachine::updateTrackBlock Aug 26 00:04:53 pi2 volumio[1209]: info: CorePlayQueue::getTrackBlock Aug 26 00:04:53 pi2 volumio[1209]: info: CoreCommandRouter::volumioPlay Aug 26 00:04:53 pi2 volumio[1209]: info: CoreStateMachine::play index 1 Aug 26 00:04:53 pi2 volumio[1209]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 26 00:04:53 pi2 volumio[1209]: info: CoreStateMachine::addQueueItems Aug 26 00:04:53 pi2 volumio[1209]: info: CorePlayQueue::addQueueItems Aug 26 00:04:53 pi2 volumio[1209]: info: Preload queue cleared Aug 26 00:04:53 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:2iEGj7kAwH7HAa5epwYwLB Aug 26 00:04:53 pi2 volumio[1209]: info: Using cached record of: spotify:track:2iEGj7kAwH7HAa5epwYwLB Aug 26 00:04:53 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:30FURVTCpbKyykjSEQzGkH Aug 26 00:04:53 pi2 volumio[1209]: info: Using cached record of: spotify:track:30FURVTCpbKyykjSEQzGkH Aug 26 00:04:53 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:3dPQuX8Gs42Y7b454ybpMR Aug 26 00:04:53 pi2 volumio[1209]: info: Using cached record of: spotify:track:3dPQuX8Gs42Y7b454ybpMR Aug 26 00:04:53 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:2P884dqfjksDMSzUZksfrS Aug 26 00:04:53 pi2 volumio[1209]: info: Using cached record of: spotify:track:2P884dqfjksDMSzUZksfrS Aug 26 00:04:53 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:69QHm3pustz01CJRwdo20z Aug 26 00:04:53 pi2 volumio[1209]: info: Using cached record of: spotify:track:69QHm3pustz01CJRwdo20z Aug 26 00:04:53 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:2SiXAy7TuUkycRVbbWDEpo Aug 26 00:04:53 pi2 volumio[1209]: info: Using cached record of: spotify:track:2SiXAy7TuUkycRVbbWDEpo Aug 26 00:04:53 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:0C80GCp0mMuBzLf3EAXqxv Aug 26 00:04:53 pi2 volumio[1209]: info: Using cached record of: spotify:track:0C80GCp0mMuBzLf3EAXqxv Aug 26 00:04:53 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:7mocbWQc7a3Y7AOZNUpRJC Aug 26 00:04:53 pi2 volumio[1209]: info: Using cached record of: spotify:track:7mocbWQc7a3Y7AOZNUpRJC Aug 26 00:04:53 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:7ldGijnKCC5aN7HHUfSnp4 Aug 26 00:04:53 pi2 volumio[1209]: info: Using cached record of: spotify:track:7ldGijnKCC5aN7HHUfSnp4 Aug 26 00:04:53 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:3qhlB30KknSejmIvZZLjOD Aug 26 00:04:53 pi2 volumio[1209]: info: Using cached record of: spotify:track:3qhlB30KknSejmIvZZLjOD Aug 26 00:04:53 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:3WPYapjyqcVpShYXQuChcs Aug 26 00:04:53 pi2 volumio[1209]: info: Using cached record of: spotify:track:3WPYapjyqcVpShYXQuChcs Aug 26 00:04:53 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:2U2ONBrf1HJCDxQlynpD6J Aug 26 00:04:53 pi2 volumio[1209]: info: Using cached record of: spotify:track:2U2ONBrf1HJCDxQlynpD6J Aug 26 00:04:53 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:3eQlGeyuSibgAGPEJugaDW Aug 26 00:04:53 pi2 volumio[1209]: info: Using cached record of: spotify:track:3eQlGeyuSibgAGPEJugaDW Aug 26 00:04:53 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:7oI0ieXKsWdBxSgEsYSYxI Aug 26 00:04:53 pi2 volumio[1209]: info: Using cached record of: spotify:track:7oI0ieXKsWdBxSgEsYSYxI Aug 26 00:04:53 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:1yiPNrjkKr523bZnVNvxlK Aug 26 00:04:53 pi2 volumio[1209]: info: Using cached record of: spotify:track:1yiPNrjkKr523bZnVNvxlK Aug 26 00:04:53 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:4OgwXdylh75fHfwUzJTUqg Aug 26 00:04:53 pi2 volumio[1209]: info: Using cached record of: spotify:track:4OgwXdylh75fHfwUzJTUqg Aug 26 00:04:53 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:7BAKWjphDrXRP6ygmxicfg Aug 26 00:04:53 pi2 volumio[1209]: info: Using cached record of: spotify:track:7BAKWjphDrXRP6ygmxicfg Aug 26 00:04:53 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:0d1pu1YYdXKvfx7LOW6ym3 Aug 26 00:04:53 pi2 volumio[1209]: info: Using cached record of: spotify:track:0d1pu1YYdXKvfx7LOW6ym3 Aug 26 00:04:53 pi2 volumio[1209]: info: CoreStateMachine::stop Aug 26 00:04:53 pi2 volumio[1209]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 26 00:04:53 pi2 volumio[1209]: info: CoreCommandRouter::volumioPushQueue Aug 26 00:04:53 pi2 volumio[1209]: info: CorePlayQueue::saveQueue Aug 26 00:04:53 pi2 volumio[1209]: info: CoreStateMachine::play index undefined Aug 26 00:04:53 pi2 volumio[1209]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 26 00:04:53 pi2 volumio[1209]: info: CoreStateMachine::updateTrackBlock Aug 26 00:04:53 pi2 volumio[1209]: info: CorePlayQueue::getTrackBlock Aug 26 00:04:53 pi2 volumio[1209]: info: CorePlayQueue::getTrack 1 Aug 26 00:04:53 pi2 volumio[1209]: info: CoreStateMachine::startPlaybackTimer Aug 26 00:04:53 pi2 volumio[1209]: info: CorePlayQueue::getTrack 1 Aug 26 00:04:53 pi2 volumio[1209]: info: [1787724293732] ControllerSpotify::clearAddPlayTrack Aug 26 00:04:53 pi2 volumio[1209]: info: Sending Spotify command with payload to local API: /player/play Aug 26 00:04:53 pi2 go-librespot[1734]: time="2026-08-26T00:04:53-06:00" level=debug msg="renewing login5 access token" Aug 26 00:04:53 pi2 go-librespot[1734]: time="2026-08-26T00:04:53-06:00" level=error msg="failed handling request play" error="failed resolving context: spclient request failed: failed obtaining spclient access token: failed renewing login5 access token: failed authenticating with login5: UNKNOWN_ERROR" Aug 26 00:04:53 pi2 volumio[1209]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Aug 26 00:04:58 pi2 volumio[1209]: info: Preload queue cleared Aug 26 00:04:58 pi2 volumio[1209]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 26 00:04:58 pi2 volumio[1209]: info: CoreStateMachine::ClearQueue Aug 26 00:04:58 pi2 volumio[1209]: info: CoreStateMachine::stop Aug 26 00:04:58 pi2 volumio[1209]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 26 00:04:58 pi2 volumio[1209]: info: CorePlayQueue::clearPlayQueue Aug 26 00:04:58 pi2 volumio[1209]: info: CorePlayQueue::saveQueue Aug 26 00:04:58 pi2 volumio[1209]: info: CoreCommandRouter::volumioPushQueue Aug 26 00:04:58 pi2 volumio[1209]: info: CoreStateMachine::addQueueItems Aug 26 00:04:58 pi2 volumio[1209]: info: CorePlayQueue::addQueueItems Aug 26 00:04:58 pi2 volumio[1209]: info: Preload queue cleared Aug 26 00:04:58 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:08mG3Y1vljYA6bvDt4Wqkj Aug 26 00:04:58 pi2 volumio[1209]: info: Using cached record of: spotify:track:08mG3Y1vljYA6bvDt4Wqkj Aug 26 00:04:58 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:57bgtoPSgt236HzfBOd8kj Aug 26 00:04:58 pi2 volumio[1209]: info: Using cached record of: spotify:track:57bgtoPSgt236HzfBOd8kj Aug 26 00:04:58 pi2 volumio[1209]: info: CoreCommandRouter::volumioPushQueue Aug 26 00:04:58 pi2 volumio[1209]: info: CorePlayQueue::saveQueue Aug 26 00:04:58 pi2 volumio[1209]: info: CoreStateMachine::updateTrackBlock Aug 26 00:04:58 pi2 volumio[1209]: info: CorePlayQueue::getTrackBlock Aug 26 00:04:58 pi2 volumio[1209]: info: CoreCommandRouter::volumioPlay Aug 26 00:04:58 pi2 volumio[1209]: info: CoreStateMachine::play index 1 Aug 26 00:04:58 pi2 volumio[1209]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 26 00:04:58 pi2 volumio[1209]: info: CoreStateMachine::addQueueItems Aug 26 00:04:58 pi2 volumio[1209]: info: CorePlayQueue::addQueueItems Aug 26 00:04:58 pi2 volumio[1209]: info: Preload queue cleared Aug 26 00:04:58 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:2iEGj7kAwH7HAa5epwYwLB Aug 26 00:04:58 pi2 volumio[1209]: info: Using cached record of: spotify:track:2iEGj7kAwH7HAa5epwYwLB Aug 26 00:04:58 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:30FURVTCpbKyykjSEQzGkH Aug 26 00:04:58 pi2 volumio[1209]: info: Using cached record of: spotify:track:30FURVTCpbKyykjSEQzGkH Aug 26 00:04:58 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:3dPQuX8Gs42Y7b454ybpMR Aug 26 00:04:58 pi2 volumio[1209]: info: Using cached record of: spotify:track:3dPQuX8Gs42Y7b454ybpMR Aug 26 00:04:58 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:2P884dqfjksDMSzUZksfrS Aug 26 00:04:58 pi2 volumio[1209]: info: Using cached record of: spotify:track:2P884dqfjksDMSzUZksfrS Aug 26 00:04:58 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:69QHm3pustz01CJRwdo20z Aug 26 00:04:58 pi2 volumio[1209]: info: Using cached record of: spotify:track:69QHm3pustz01CJRwdo20z Aug 26 00:04:58 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:2SiXAy7TuUkycRVbbWDEpo Aug 26 00:04:58 pi2 volumio[1209]: info: Using cached record of: spotify:track:2SiXAy7TuUkycRVbbWDEpo Aug 26 00:04:58 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:0C80GCp0mMuBzLf3EAXqxv Aug 26 00:04:58 pi2 volumio[1209]: info: Using cached record of: spotify:track:0C80GCp0mMuBzLf3EAXqxv Aug 26 00:04:58 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:7mocbWQc7a3Y7AOZNUpRJC Aug 26 00:04:58 pi2 volumio[1209]: info: Using cached record of: spotify:track:7mocbWQc7a3Y7AOZNUpRJC Aug 26 00:04:58 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:7ldGijnKCC5aN7HHUfSnp4 Aug 26 00:04:58 pi2 volumio[1209]: info: Using cached record of: spotify:track:7ldGijnKCC5aN7HHUfSnp4 Aug 26 00:04:58 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:3qhlB30KknSejmIvZZLjOD Aug 26 00:04:58 pi2 volumio[1209]: info: Using cached record of: spotify:track:3qhlB30KknSejmIvZZLjOD Aug 26 00:04:58 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:3WPYapjyqcVpShYXQuChcs Aug 26 00:04:58 pi2 volumio[1209]: info: Using cached record of: spotify:track:3WPYapjyqcVpShYXQuChcs Aug 26 00:04:58 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:2U2ONBrf1HJCDxQlynpD6J Aug 26 00:04:58 pi2 volumio[1209]: info: Using cached record of: spotify:track:2U2ONBrf1HJCDxQlynpD6J Aug 26 00:04:58 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:3eQlGeyuSibgAGPEJugaDW Aug 26 00:04:58 pi2 volumio[1209]: info: Using cached record of: spotify:track:3eQlGeyuSibgAGPEJugaDW Aug 26 00:04:58 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:7oI0ieXKsWdBxSgEsYSYxI Aug 26 00:04:58 pi2 volumio[1209]: info: Using cached record of: spotify:track:7oI0ieXKsWdBxSgEsYSYxI Aug 26 00:04:58 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:1yiPNrjkKr523bZnVNvxlK Aug 26 00:04:58 pi2 volumio[1209]: info: Using cached record of: spotify:track:1yiPNrjkKr523bZnVNvxlK Aug 26 00:04:58 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:4OgwXdylh75fHfwUzJTUqg Aug 26 00:04:58 pi2 volumio[1209]: info: Using cached record of: spotify:track:4OgwXdylh75fHfwUzJTUqg Aug 26 00:04:58 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:7BAKWjphDrXRP6ygmxicfg Aug 26 00:04:58 pi2 volumio[1209]: info: Using cached record of: spotify:track:7BAKWjphDrXRP6ygmxicfg Aug 26 00:04:58 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:0d1pu1YYdXKvfx7LOW6ym3 Aug 26 00:04:58 pi2 volumio[1209]: info: Using cached record of: spotify:track:0d1pu1YYdXKvfx7LOW6ym3 Aug 26 00:04:58 pi2 volumio[1209]: info: CoreStateMachine::stop Aug 26 00:04:58 pi2 volumio[1209]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 26 00:04:58 pi2 volumio[1209]: info: CoreCommandRouter::volumioPushQueue Aug 26 00:04:58 pi2 volumio[1209]: info: CorePlayQueue::saveQueue Aug 26 00:04:58 pi2 volumio[1209]: info: CoreStateMachine::play index undefined Aug 26 00:04:58 pi2 volumio[1209]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 26 00:04:58 pi2 volumio[1209]: info: CoreStateMachine::updateTrackBlock Aug 26 00:04:58 pi2 volumio[1209]: info: CorePlayQueue::getTrackBlock Aug 26 00:04:58 pi2 volumio[1209]: info: CorePlayQueue::getTrack 1 Aug 26 00:04:58 pi2 volumio[1209]: info: CoreStateMachine::startPlaybackTimer Aug 26 00:04:58 pi2 volumio[1209]: info: CorePlayQueue::getTrack 1 Aug 26 00:04:58 pi2 volumio[1209]: info: [1787724298807] ControllerSpotify::clearAddPlayTrack Aug 26 00:04:58 pi2 volumio[1209]: info: Sending Spotify command with payload to local API: /player/play Aug 26 00:04:58 pi2 go-librespot[1734]: time="2026-08-26T00:04:58-06:00" level=debug msg="renewing login5 access token" Aug 26 00:04:58 pi2 go-librespot[1734]: time="2026-08-26T00:04:58-06:00" level=error msg="failed handling request play" error="failed resolving context: spclient request failed: failed obtaining spclient access token: failed renewing login5 access token: failed authenticating with login5: UNKNOWN_ERROR" Aug 26 00:04:58 pi2 volumio[1209]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Aug 26 00:05:00 pi2 volumio[1209]: info: Preload queue cleared Aug 26 00:05:00 pi2 volumio[1209]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 26 00:05:00 pi2 volumio[1209]: info: CoreStateMachine::ClearQueue Aug 26 00:05:00 pi2 volumio[1209]: info: CoreStateMachine::stop Aug 26 00:05:00 pi2 volumio[1209]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 26 00:05:00 pi2 volumio[1209]: info: CorePlayQueue::clearPlayQueue Aug 26 00:05:00 pi2 volumio[1209]: info: CorePlayQueue::saveQueue Aug 26 00:05:00 pi2 volumio[1209]: info: CoreCommandRouter::volumioPushQueue Aug 26 00:05:00 pi2 volumio[1209]: info: CoreStateMachine::addQueueItems Aug 26 00:05:00 pi2 volumio[1209]: info: CorePlayQueue::addQueueItems Aug 26 00:05:00 pi2 volumio[1209]: info: Preload queue cleared Aug 26 00:05:00 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:08mG3Y1vljYA6bvDt4Wqkj Aug 26 00:05:00 pi2 volumio[1209]: info: Using cached record of: spotify:track:08mG3Y1vljYA6bvDt4Wqkj Aug 26 00:05:00 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:57bgtoPSgt236HzfBOd8kj Aug 26 00:05:00 pi2 volumio[1209]: info: Using cached record of: spotify:track:57bgtoPSgt236HzfBOd8kj Aug 26 00:05:00 pi2 volumio[1209]: info: CoreCommandRouter::volumioPushQueue Aug 26 00:05:00 pi2 volumio[1209]: info: CorePlayQueue::saveQueue Aug 26 00:05:00 pi2 volumio[1209]: info: CoreStateMachine::updateTrackBlock Aug 26 00:05:00 pi2 volumio[1209]: info: CorePlayQueue::getTrackBlock Aug 26 00:05:00 pi2 volumio[1209]: info: CoreCommandRouter::volumioPlay Aug 26 00:05:00 pi2 volumio[1209]: info: CoreStateMachine::play index 1 Aug 26 00:05:00 pi2 volumio[1209]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 26 00:05:00 pi2 volumio[1209]: info: CoreStateMachine::addQueueItems Aug 26 00:05:00 pi2 volumio[1209]: info: CorePlayQueue::addQueueItems Aug 26 00:05:00 pi2 volumio[1209]: info: Preload queue cleared Aug 26 00:05:00 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:2iEGj7kAwH7HAa5epwYwLB Aug 26 00:05:00 pi2 volumio[1209]: info: Using cached record of: spotify:track:2iEGj7kAwH7HAa5epwYwLB Aug 26 00:05:00 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:30FURVTCpbKyykjSEQzGkH Aug 26 00:05:00 pi2 volumio[1209]: info: Using cached record of: spotify:track:30FURVTCpbKyykjSEQzGkH Aug 26 00:05:00 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:3dPQuX8Gs42Y7b454ybpMR Aug 26 00:05:00 pi2 volumio[1209]: info: Using cached record of: spotify:track:3dPQuX8Gs42Y7b454ybpMR Aug 26 00:05:00 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:2P884dqfjksDMSzUZksfrS Aug 26 00:05:00 pi2 volumio[1209]: info: Using cached record of: spotify:track:2P884dqfjksDMSzUZksfrS Aug 26 00:05:00 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:69QHm3pustz01CJRwdo20z Aug 26 00:05:00 pi2 volumio[1209]: info: Using cached record of: spotify:track:69QHm3pustz01CJRwdo20z Aug 26 00:05:00 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:2SiXAy7TuUkycRVbbWDEpo Aug 26 00:05:00 pi2 volumio[1209]: info: Using cached record of: spotify:track:2SiXAy7TuUkycRVbbWDEpo Aug 26 00:05:00 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:0C80GCp0mMuBzLf3EAXqxv Aug 26 00:05:00 pi2 volumio[1209]: info: Using cached record of: spotify:track:0C80GCp0mMuBzLf3EAXqxv Aug 26 00:05:00 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:7mocbWQc7a3Y7AOZNUpRJC Aug 26 00:05:00 pi2 volumio[1209]: info: Using cached record of: spotify:track:7mocbWQc7a3Y7AOZNUpRJC Aug 26 00:05:00 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:7ldGijnKCC5aN7HHUfSnp4 Aug 26 00:05:00 pi2 volumio[1209]: info: Using cached record of: spotify:track:7ldGijnKCC5aN7HHUfSnp4 Aug 26 00:05:00 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:3qhlB30KknSejmIvZZLjOD Aug 26 00:05:00 pi2 volumio[1209]: info: Using cached record of: spotify:track:3qhlB30KknSejmIvZZLjOD Aug 26 00:05:00 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:3WPYapjyqcVpShYXQuChcs Aug 26 00:05:00 pi2 volumio[1209]: info: Using cached record of: spotify:track:3WPYapjyqcVpShYXQuChcs Aug 26 00:05:00 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:2U2ONBrf1HJCDxQlynpD6J Aug 26 00:05:00 pi2 volumio[1209]: info: Using cached record of: spotify:track:2U2ONBrf1HJCDxQlynpD6J Aug 26 00:05:00 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:3eQlGeyuSibgAGPEJugaDW Aug 26 00:05:00 pi2 volumio[1209]: info: Using cached record of: spotify:track:3eQlGeyuSibgAGPEJugaDW Aug 26 00:05:00 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:7oI0ieXKsWdBxSgEsYSYxI Aug 26 00:05:00 pi2 volumio[1209]: info: Using cached record of: spotify:track:7oI0ieXKsWdBxSgEsYSYxI Aug 26 00:05:00 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:1yiPNrjkKr523bZnVNvxlK Aug 26 00:05:00 pi2 volumio[1209]: info: Using cached record of: spotify:track:1yiPNrjkKr523bZnVNvxlK Aug 26 00:05:00 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:4OgwXdylh75fHfwUzJTUqg Aug 26 00:05:00 pi2 volumio[1209]: info: Using cached record of: spotify:track:4OgwXdylh75fHfwUzJTUqg Aug 26 00:05:00 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:7BAKWjphDrXRP6ygmxicfg Aug 26 00:05:00 pi2 volumio[1209]: info: Using cached record of: spotify:track:7BAKWjphDrXRP6ygmxicfg Aug 26 00:05:00 pi2 volumio[1209]: info: Adding Item to queue: spotify:track:0d1pu1YYdXKvfx7LOW6ym3 Aug 26 00:05:00 pi2 volumio[1209]: info: Using cached record of: spotify:track:0d1pu1YYdXKvfx7LOW6ym3 Aug 26 00:05:00 pi2 volumio[1209]: info: CoreStateMachine::stop Aug 26 00:05:00 pi2 volumio[1209]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 26 00:05:00 pi2 volumio[1209]: info: CoreCommandRouter::volumioPushQueue Aug 26 00:05:00 pi2 volumio[1209]: info: CorePlayQueue::saveQueue Aug 26 00:05:00 pi2 volumio[1209]: info: CoreStateMachine::play index undefined Aug 26 00:05:00 pi2 volumio[1209]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 26 00:05:00 pi2 volumio[1209]: info: CoreStateMachine::updateTrackBlock Aug 26 00:05:00 pi2 volumio[1209]: info: CorePlayQueue::getTrackBlock Aug 26 00:05:00 pi2 volumio[1209]: info: CorePlayQueue::getTrack 1 Aug 26 00:05:00 pi2 volumio[1209]: info: CoreStateMachine::startPlaybackTimer Aug 26 00:05:00 pi2 volumio[1209]: info: CorePlayQueue::getTrack 1 Aug 26 00:05:00 pi2 volumio[1209]: info: [1787724300875] ControllerSpotify::clearAddPlayTrack Aug 26 00:05:00 pi2 volumio[1209]: info: Sending Spotify command with payload to local API: /player/play Aug 26 00:05:00 pi2 go-librespot[1734]: time="2026-08-26T00:05:00-06:00" level=debug msg="renewing login5 access token" Aug 26 00:05:01 pi2 go-librespot[1734]: time="2026-08-26T00:05:01-06:00" level=error msg="failed handling request play" error="failed resolving context: spclient request failed: failed obtaining spclient access token: failed renewing login5 access token: failed authenticating with login5: UNKNOWN_ERROR" Aug 26 00:05:01 pi2 volumio[1209]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Aug 26 00:05:10 pi2 volumio[1209]: info: CoreCommandRouter::volumioGetState Aug 26 00:05:10 pi2 volumio[1209]: info: CorePlayQueue::getTrack 1 Aug 26 00:05:11 pi2 volumio[1209]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 26 00:05:11 pi2 volumio[1209]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Aug 26 00:05:17 pi2 volumio[1209]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 26 00:05:21 pi2 volumio[1209]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Aug 26 00:05:21 pi2 volumio[1209]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Aug 26 00:05:21 pi2 volumio[1209]: info: Creating Spotify config file Aug 26 00:05:21 pi2 volumio[1209]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 00:05:21 pi2 volumio[1209]: info: Spotify config file written Aug 26 00:05:21 pi2 sudo[31986]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 26 00:05:21 pi2 sudo[31986]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 00:05:21 pi2 systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Aug 26 00:05:21 pi2 systemd[1]: go-librespot-daemon.service: Deactivated successfully. Aug 26 00:05:21 pi2 volumio[1209]: info: Connection to go-librespot Websocket closed Aug 26 00:05:21 pi2 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 00:05:21 pi2 systemd[1]: go-librespot-daemon.service: Consumed 2w 22h 8min 21.733s CPU time. Aug 26 00:05:21 pi2 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 00:05:21 pi2 sudo[31986]: pam_unix(sudo:session): session closed for user root Aug 26 00:05:22 pi2 go-librespot[31988]: go-librespot daemon starting... Aug 26 00:05:22 pi2 go-librespot[31991]: time="2026-08-26T00:05:22-06:00" level=info msg="running go-librespot 0.7.1" Aug 26 00:05:22 pi2 go-librespot[31991]: time="2026-08-26T00:05:22-06:00" level=debug msg="app state loaded" Aug 26 00:05:22 pi2 go-librespot[31991]: time="2026-08-26T00:05:22-06:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 00:05:22 pi2 go-librespot[31991]: time="2026-08-26T00:05:22-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 26 00:05:22 pi2 go-librespot[31991]: time="2026-08-26T00:05:22-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 26 00:05:22 pi2 go-librespot[31991]: time="2026-08-26T00:05:22-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 26 00:05:23 pi2 go-librespot[31991]: time="2026-08-26T00:05:23-06:00" level=info msg="zeroconf server listening on port 40383" Aug 26 00:05:23 pi2 go-librespot[31991]: time="2026-08-26T00:05:23-06:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 00:05:23 pi2 go-librespot[31991]: time="2026-08-26T00:05:23-06:00" level=debug msg="obtained new client token: AAGZBpi6GFXkOC9U9BcFoDvweaW4SE05A27rBycqa0MShNKnsIBb3qHo3pCAkeyQ5d9f0GNZudEYjRd+yT+HTOhc+5SJuMWp32qm3dFJd6AknHgVHgB6+Hw8FHQo2SjYxSZnIrmbek9XajncsC+AY7t+AsEECPX2jdf7fjnab07Wn9kw5l6RyLGxl0NKWlIb63yWPwO1CyzYQjhDOcHHePNzBYx2WcbVzeJHyrHUgeYgA3EADuhe3w==" Aug 26 00:05:23 pi2 go-librespot[31991]: time="2026-08-26T00:05:23-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 26 00:05:23 pi2 go-librespot[31991]: time="2026-08-26T00:05:23-06:00" level=debug msg="completed keyexchange" Aug 26 00:05:23 pi2 go-librespot[31991]: time="2026-08-26T00:05:23-06:00" level=debug msg="completed challenge" Aug 26 00:05:23 pi2 go-librespot[31991]: time="2026-08-26T00:05:23-06:00" level=info msg="authenticated AP" username="22*********************uq" Aug 26 00:05:23 pi2 go-librespot[31991]: time="2026-08-26T00:05:23-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 00:05:23 pi2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 00:05:23 pi2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 00:05:24 pi2 volumio[1209]: info: Initializing connection to go-librespot Websocket Aug 26 00:05:24 pi2 volumio[1209]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 26 00:05:24 pi2 volumio[1209]: info: go-librespot daemon successfully initialized Aug 26 00:05:25 pi2 volumio[1209]: info: CoreCommandRouter::volumioGetState Aug 26 00:05:25 pi2 volumio[1209]: info: CorePlayQueue::getTrack 1 Aug 26 00:05:26 pi2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 26 00:05:26 pi2 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 00:05:26 pi2 volumio[1209]: info: CoreCommandRouter::volumioPlay Aug 26 00:05:26 pi2 volumio[1209]: info: CoreStateMachine::play index undefined Aug 26 00:05:26 pi2 volumio[1209]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 26 00:05:26 pi2 volumio[1209]: info: CorePlayQueue::getTrack 1 Aug 26 00:05:26 pi2 volumio[1209]: info: CoreStateMachine::startPlaybackTimer Aug 26 00:05:26 pi2 volumio[1209]: info: CorePlayQueue::getTrack 1 Aug 26 00:05:26 pi2 volumio[1209]: info: [1787724326944] ControllerSpotify::clearAddPlayTrack Aug 26 00:05:26 pi2 volumio[1209]: info: Sending Spotify command with payload to local API: /player/play Aug 26 00:05:26 pi2 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 00:05:26 pi2 volumio[1209]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 26 00:05:26 pi2 go-librespot[32016]: go-librespot daemon starting... Aug 26 00:05:27 pi2 go-librespot[32017]: time="2026-08-26T00:05:27-06:00" level=info msg="running go-librespot 0.7.1" Aug 26 00:05:27 pi2 go-librespot[32017]: time="2026-08-26T00:05:27-06:00" level=debug msg="app state loaded" Aug 26 00:05:27 pi2 go-librespot[32017]: time="2026-08-26T00:05:27-06:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 00:05:27 pi2 volumio[1209]: info: Initializing connection to go-librespot Websocket Aug 26 00:05:27 pi2 go-librespot[32017]: time="2026-08-26T00:05:27-06:00" level=debug msg="new websocket client" Aug 26 00:05:27 pi2 volumio[1209]: info: Connection to go-librespot Websocket established Aug 26 00:05:27 pi2 volumio[1209]: info: Initializing connection to go-librespot Websocket Aug 26 00:05:27 pi2 go-librespot[32017]: time="2026-08-26T00:05:27-06:00" level=debug msg="new websocket client" Aug 26 00:05:27 pi2 volumio[1209]: info: Connection to go-librespot Websocket established Aug 26 00:05:27 pi2 go-librespot[32017]: time="2026-08-26T00:05:27-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 26 00:05:27 pi2 go-librespot[32017]: time="2026-08-26T00:05:27-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 26 00:05:27 pi2 go-librespot[32017]: time="2026-08-26T00:05:27-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 26 00:05:27 pi2 go-librespot[32017]: time="2026-08-26T00:05:27-06:00" level=info msg="zeroconf server listening on port 34047" Aug 26 00:05:27 pi2 go-librespot[32017]: time="2026-08-26T00:05:27-06:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 00:05:27 pi2 go-librespot[32017]: time="2026-08-26T00:05:27-06:00" level=debug msg="obtained new client token: AAHaROxV3sVhTdkmFulCdAbiSdzZh7BQ9HY0+7AWWccMs2KpNHtFRI6B8gb166sWo4HcL1s9gXCHl+9iBTzYuMDWGHrcfAicE9fShDY+HCud+BB9YefP7vgw4j4UKufS4elfShsoUix/6z/tmo/SDQ2vO/SYRUkFW3mrQDMe5tF/KIOHxIdxWYklhFyck4CiqaIP+sR4TajbZ02rzxHDGhmno56vcPl8x9l3CtnUAbMZc5jZAqVHZeO8" Aug 26 00:05:28 pi2 go-librespot[32017]: time="2026-08-26T00:05:28-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 26 00:05:28 pi2 go-librespot[32017]: time="2026-08-26T00:05:28-06:00" level=debug msg="completed keyexchange" Aug 26 00:05:28 pi2 go-librespot[32017]: time="2026-08-26T00:05:28-06:00" level=debug msg="completed challenge" Aug 26 00:05:28 pi2 go-librespot[32017]: time="2026-08-26T00:05:28-06:00" level=info msg="authenticated AP" username="22*********************uq" Aug 26 00:05:28 pi2 go-librespot[32017]: time="2026-08-26T00:05:28-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 00:05:28 pi2 volumio[1209]: info: Connection to go-librespot Websocket closed Aug 26 00:05:28 pi2 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 00:05:28 pi2 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 00:05:28 pi2 volumio[1209]: info: Connection to go-librespot Websocket closed Aug 26 00:05:30 pi2 volumio[1209]: info: Getting Spotify volume Aug 26 00:05:30 pi2 volumio[1209]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 26 00:05:30 pi2 volumio[1209]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 26 00:05:30 pi2 volumio[1209]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 26 00:05:30 pi2 volumio[1209]: errno: -111, Aug 26 00:05:30 pi2 volumio[1209]: code: 'ECONNREFUSED', Aug 26 00:05:30 pi2 volumio[1209]: syscall: 'connect', Aug 26 00:05:30 pi2 volumio[1209]: address: '127.0.0.1', Aug 26 00:05:30 pi2 volumio[1209]: port: 9879, Aug 26 00:05:30 pi2 volumio[1209]: response: undefined Aug 26 00:05:30 pi2 volumio[1209]: } Aug 26 00:05:30 pi2 volumio[1209]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 26 00:05:31 pi2 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 26 00:05:31 pi2 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 00:05:31 pi2 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 00:05:31 pi2 go-librespot[32040]: go-librespot daemon starting... Aug 26 00:05:31 pi2 go-librespot[32041]: time="2026-08-26T00:05:31-06:00" level=info msg="running go-librespot 0.7.1" Aug 26 00:05:31 pi2 go-librespot[32041]: time="2026-08-26T00:05:31-06:00" level=debug msg="app state loaded" Aug 26 00:05:31 pi2 go-librespot[32041]: time="2026-08-26T00:05:31-06:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 00:05:32 pi2 go-librespot[32041]: time="2026-08-26T00:05:32-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 26 00:05:32 pi2 go-librespot[32041]: time="2026-08-26T00:05:32-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 26 00:05:32 pi2 go-librespot[32041]: time="2026-08-26T00:05:32-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 26 00:05:32 pi2 go-librespot[32041]: time="2026-08-26T00:05:32-06:00" level=info msg="zeroconf server listening on port 37241" Aug 26 00:05:32 pi2 go-librespot[32041]: time="2026-08-26T00:05:32-06:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 00:05:32 pi2 sudo[32054]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-26 00:04' Aug 26 00:05:32 pi2 sudo[32054]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 00:05:32 pi2 go-librespot[32041]: time="2026-08-26T00:05:32-06:00" level=debug msg="obtained new client token: AAG/wrQlh7GRRcnZWI1LgqxTCc/VGJ0rkGgXqw2EjCTKrxZWqGaBdC1JHKY4OxhuZC/LXMMxTeWWb2d6X64Z3M6QmkMohCuRSzAliEjvxnu6DJrs79+7DtaImOpNerOYVrIoDwD52PSsCtGprwpompQy8gZuu0uKG63t0SXC8cYmbusvgZBPBzI3tetpwZmR5h7mCido6RTx7/rOSCk8ebeq29QdzFCpyKzXoLvLjzFmRqErhx9DDIG8" Aug 26 00:05:32 pi2 go-librespot[32041]: time="2026-08-26T00:05:32-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 26 00:05:33 pi2 go-librespot[32041]: time="2026-08-26T00:05:33-06:00" level=debug msg="completed keyexchange" Aug 26 00:05:33 pi2 go-librespot[32041]: time="2026-08-26T00:05:33-06:00" level=debug msg="completed challenge" PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"