Feb 24 16:21:00 raspi2 volumio[1128]: error: updateQueue error: null Feb 24 16:21:00 raspi2 volumio[1128]: error: updateQueue error: null Feb 24 16:21:00 raspi2 volumio[1128]: verbose: ControllerMpd::sendMpdCommand addid "http://100.93.223.101:8096/Audio/0ce89be2ff7b15e21aa4698b89b86d0f/stream.flac?static=true&mediaSourceId=0ce89be2ff7b15e21aa4698b89b86d0f&tag=33f2063093329a5d068537c86fd87da5&t.flac" Feb 24 16:21:00 raspi2 volumio[1128]: info: ------------------------------ 624ms Feb 24 16:21:00 raspi2 volumio[1128]: info: ------------------------------ 621ms Feb 24 16:21:00 raspi2 volumio[1128]: info: Feb 24 16:21:00 raspi2 volumio[1128]: ---------------------------- MPD announces system playlist update Feb 24 16:21:00 raspi2 volumio[1128]: info: Ignoring MPD Status Update Feb 24 16:21:00 raspi2 volumio[1128]: info: sendMpdCommand addid "http://100.93.223.101:8096/Audio/0ce89be2ff7b15e21aa4698b89b86d0f/stream.flac?static=true&mediaSourceId=0ce89be2ff7b15e21aa4698b89b86d0f&tag=33f2063093329a5d068537c86fd87da5&t.flac" took 17 milliseconds Feb 24 16:21:00 raspi2 volumio[1128]: verbose: MPD COMMAND [object Object] Feb 24 16:21:00 raspi2 volumio[1128]: verbose: MPD COMMAND [object Object] Feb 24 16:21:00 raspi2 volumio[1128]: verbose: MPD COMMAND [object Object] Feb 24 16:21:00 raspi2 volumio[1128]: info: Feb 24 16:21:00 raspi2 volumio[1128]: ---------------------------- MPD announces system playlist update Feb 24 16:21:00 raspi2 volumio[1128]: info: Ignoring MPD Status Update Feb 24 16:21:00 raspi2 volumio[1128]: info: Feb 24 16:21:00 raspi2 volumio[1128]: ---------------------------- MPD announces system playlist update Feb 24 16:21:00 raspi2 volumio[1128]: info: Ignoring MPD Status Update Feb 24 16:21:00 raspi2 volumio[1128]: info: Feb 24 16:21:00 raspi2 volumio[1128]: ---------------------------- MPD announces system playlist update Feb 24 16:21:00 raspi2 volumio[1128]: info: Ignoring MPD Status Update Feb 24 16:21:00 raspi2 volumio[1128]: info: ------------------------------ 37ms Feb 24 16:21:00 raspi2 volumio[1128]: info: ------------------------------ 26ms Feb 24 16:21:00 raspi2 volumio[1128]: info: ------------------------------ 24ms Feb 24 16:21:00 raspi2 volumio[1128]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 24 16:21:00 raspi2 volumio[1128]: verbose: ControllerMpd::sendMpdCommand play Feb 24 16:21:00 raspi2 volumio[1128]: info: Feb 24 16:21:00 raspi2 volumio[1128]: ---------------------------- MPD announces system playlist update Feb 24 16:21:00 raspi2 volumio[1128]: info: Ignoring MPD Status Update Feb 24 16:21:00 raspi2 volumio[1128]: info: Feb 24 16:21:00 raspi2 volumio[1128]: ---------------------------- MPD announces system playlist update Feb 24 16:21:00 raspi2 volumio[1128]: info: Ignoring MPD Status Update Feb 24 16:21:00 raspi2 volumio[1128]: info: ControllerMpd::getState Feb 24 16:21:00 raspi2 volumio[1128]: verbose: ControllerMpd::sendMpdCommand status Feb 24 16:21:00 raspi2 volumio[1128]: info: Feb 24 16:21:00 raspi2 volumio[1128]: ---------------------------- MPD announces state update: player Feb 24 16:21:00 raspi2 volumio[1128]: info: ------------------------------ 231ms Feb 24 16:21:00 raspi2 volumio[1128]: info: sendMpdCommand play took 227 milliseconds Feb 24 16:21:00 raspi2 volumio[1128]: info: ------------------------------ 227ms Feb 24 16:21:00 raspi2 volumio[1128]: info: ------------------------------ 224ms Feb 24 16:21:00 raspi2 volumio[1128]: info: ControllerMpd::getState Feb 24 16:21:00 raspi2 volumio[1128]: verbose: ControllerMpd::sendMpdCommand status Feb 24 16:21:01 raspi2 volumio[1128]: info: Feb 24 16:21:01 raspi2 volumio[1128]: ---------------------------- MPD announces system playlist update Feb 24 16:21:01 raspi2 volumio[1128]: info: Ignoring MPD Status Update Feb 24 16:21:01 raspi2 volumio[1128]: info: ControllerMpd::getState Feb 24 16:21:01 raspi2 volumio[1128]: verbose: ControllerMpd::sendMpdCommand status Feb 24 16:21:01 raspi2 volumio[1128]: info: Feb 24 16:21:01 raspi2 volumio[1128]: ---------------------------- MPD announces state update: player Feb 24 16:21:01 raspi2 volumio[1128]: info: ControllerMpd::getState Feb 24 16:21:01 raspi2 volumio[1128]: verbose: ControllerMpd::sendMpdCommand status Feb 24 16:21:01 raspi2 volumio[1128]: info: sendMpdCommand status took 424 milliseconds Feb 24 16:21:01 raspi2 volumio[1128]: info: sendMpdCommand status took 393 milliseconds Feb 24 16:21:01 raspi2 volumio[1128]: verbose: ControllerMpd::parseState Feb 24 16:21:01 raspi2 volumio[1128]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 16:21:01 raspi2 volumio[1128]: verbose: ControllerMpd::parseState Feb 24 16:21:01 raspi2 volumio[1128]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 16:21:01 raspi2 volumio[1128]: info: Feb 24 16:21:01 raspi2 volumio[1128]: ---------------------------- MPD announces state update: player Feb 24 16:21:01 raspi2 volumio[1128]: info: ControllerMpd::getState Feb 24 16:21:01 raspi2 volumio[1128]: verbose: ControllerMpd::sendMpdCommand status Feb 24 16:21:01 raspi2 volumio[1128]: info: Feb 24 16:21:01 raspi2 volumio[1128]: ---------------------------- MPD announces state update: player Feb 24 16:21:01 raspi2 volumio[1128]: info: ControllerMpd::getState Feb 24 16:21:01 raspi2 volumio[1128]: verbose: ControllerMpd::sendMpdCommand status Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreCommandRouter::volumioPushQueue Feb 24 16:21:01 raspi2 volumio[1128]: info: CorePlayQueue::saveQueue Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreStateMachine::updateTrackBlock Feb 24 16:21:01 raspi2 volumio[1128]: info: CorePlayQueue::getTrackBlock Feb 24 16:21:01 raspi2 volumio[1128]: info: sendMpdCommand status took 96 milliseconds Feb 24 16:21:01 raspi2 volumio[1128]: info: ------------------------------ 98ms Feb 24 16:21:01 raspi2 volumio[1128]: info: sendMpdCommand status took 93 milliseconds Feb 24 16:21:01 raspi2 volumio[1128]: info: sendMpdCommand playlistinfo took 87 milliseconds Feb 24 16:21:01 raspi2 volumio[1128]: info: sendMpdCommand playlistinfo took 87 milliseconds Feb 24 16:21:01 raspi2 volumio[1128]: info: sendMpdCommand status took 84 milliseconds Feb 24 16:21:01 raspi2 volumio[1128]: info: sendMpdCommand status took 81 milliseconds Feb 24 16:21:01 raspi2 volumio[1128]: verbose: ControllerMpd::parseState Feb 24 16:21:01 raspi2 volumio[1128]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 16:21:01 raspi2 volumio[1128]: verbose: ControllerMpd::parseState Feb 24 16:21:01 raspi2 volumio[1128]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 16:21:01 raspi2 volumio[1128]: verbose: ControllerMpd::parseTrackInfo Feb 24 16:21:01 raspi2 volumio[1128]: verbose: ControllerMpd::parseTrackInfo Feb 24 16:21:01 raspi2 volumio[1128]: verbose: ControllerMpd::parseState Feb 24 16:21:01 raspi2 volumio[1128]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 16:21:01 raspi2 volumio[1128]: verbose: ControllerMpd::parseState Feb 24 16:21:01 raspi2 volumio[1128]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 16:21:01 raspi2 volumio[1128]: info: ControllerMpd::pushState Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreCommandRouter::servicePushState Feb 24 16:21:01 raspi2 volumio[1128]: info: CorePlayQueue::getTrack 0 Feb 24 16:21:01 raspi2 volumio[1128]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1236,"duration":363,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1743 Kbps","isStreaming":false,"title":"Vuelo Blanco de Gaviota (Days of Pearly Spencer)","artist":"Ana Belén","album":"Ana Belén 70","uri":"http://100.93.223.101:8096/Audio/0ce89be2ff7b15e21aa4698b89b86d0f/stream.flac?static=true&mediaSourceId=0ce89be2ff7b15e21aa4698b89b86d0f&tag=33f2063093329a5d068537c86fd87da5&t.flac","trackType":"flac"} Feb 24 16:21:01 raspi2 volumio[1128]: verbose: CURRENT POSITION 0 Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreStateMachine::syncState stateService play Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreStateMachine::syncState currentStatus stop Feb 24 16:21:01 raspi2 volumio[1128]: info: ------------------------------ 537ms Feb 24 16:21:01 raspi2 volumio[1128]: info: Pushing Favourites {"favourite":false} Feb 24 16:21:01 raspi2 volumio[1128]: info: Feb 24 16:21:01 raspi2 volumio[1128]: ---------------------------- MPD announces system playlist update Feb 24 16:21:01 raspi2 volumio[1128]: info: Ignoring MPD Status Update Feb 24 16:21:01 raspi2 volumio[1128]: info: Feb 24 16:21:01 raspi2 volumio[1128]: ---------------------------- MPD announces state update: player Feb 24 16:21:01 raspi2 volumio[1128]: info: ControllerMpd::getState Feb 24 16:21:01 raspi2 volumio[1128]: verbose: ControllerMpd::sendMpdCommand status Feb 24 16:21:01 raspi2 volumio[1128]: info: Feb 24 16:21:01 raspi2 volumio[1128]: ---------------------------- MPD announces system playlist update Feb 24 16:21:01 raspi2 volumio[1128]: info: Ignoring MPD Status Update Feb 24 16:21:01 raspi2 volumio[1128]: info: Feb 24 16:21:01 raspi2 volumio[1128]: ---------------------------- MPD announces state update: player Feb 24 16:21:01 raspi2 volumio[1128]: info: ControllerMpd::getState Feb 24 16:21:01 raspi2 volumio[1128]: verbose: ControllerMpd::sendMpdCommand status Feb 24 16:21:01 raspi2 volumio[1128]: info: sendMpdCommand playlistinfo took 105 milliseconds Feb 24 16:21:01 raspi2 volumio[1128]: info: sendMpdCommand playlistinfo took 104 milliseconds Feb 24 16:21:01 raspi2 volumio[1128]: info: sendMpdCommand playlistinfo took 101 milliseconds Feb 24 16:21:01 raspi2 volumio[1128]: info: sendMpdCommand playlistinfo took 99 milliseconds Feb 24 16:21:01 raspi2 volumio[1128]: info: ------------------------------ 61ms Feb 24 16:21:01 raspi2 volumio[1128]: info: sendMpdCommand status took 59 milliseconds Feb 24 16:21:01 raspi2 volumio[1128]: info: ------------------------------ 57ms Feb 24 16:21:01 raspi2 volumio[1128]: info: sendMpdCommand status took 55 milliseconds Feb 24 16:21:01 raspi2 volumio[1128]: verbose: ControllerMpd::parseTrackInfo Feb 24 16:21:01 raspi2 volumio[1128]: verbose: ControllerMpd::parseTrackInfo Feb 24 16:21:01 raspi2 volumio[1128]: verbose: ControllerMpd::parseTrackInfo Feb 24 16:21:01 raspi2 volumio[1128]: verbose: ControllerMpd::parseTrackInfo Feb 24 16:21:01 raspi2 volumio[1128]: verbose: ControllerMpd::parseState Feb 24 16:21:01 raspi2 volumio[1128]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 16:21:01 raspi2 volumio[1128]: verbose: ControllerMpd::parseState Feb 24 16:21:01 raspi2 volumio[1128]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 16:21:01 raspi2 volumio[1128]: info: ControllerMpd::pushState Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreCommandRouter::servicePushState Feb 24 16:21:01 raspi2 volumio[1128]: info: CorePlayQueue::getTrack 0 Feb 24 16:21:01 raspi2 volumio[1128]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2358,"duration":363,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1730 Kbps","isStreaming":false,"title":"Vuelo Blanco de Gaviota (Days of Pearly Spencer)","artist":"Ana Belén","album":"Ana Belén 70","uri":"http://100.93.223.101:8096/Audio/0ce89be2ff7b15e21aa4698b89b86d0f/stream.flac?static=true&mediaSourceId=0ce89be2ff7b15e21aa4698b89b86d0f&tag=33f2063093329a5d068537c86fd87da5&t.flac","trackType":"flac"} Feb 24 16:21:01 raspi2 volumio[1128]: verbose: CURRENT POSITION 0 Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreStateMachine::syncState stateService play Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreStateMachine::syncState currentStatus play Feb 24 16:21:01 raspi2 volumio[1128]: info: Received an update from plugin. extracting info from payload Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreStateMachine::pushState Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreCommandRouter::volumioPushState Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreStateMachine::pushState Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreCommandRouter::volumioPushState Feb 24 16:21:01 raspi2 volumio[1128]: info: ControllerMpd::pushState Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreCommandRouter::servicePushState Feb 24 16:21:01 raspi2 volumio[1128]: info: CorePlayQueue::getTrack 0 Feb 24 16:21:01 raspi2 volumio[1128]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2358,"duration":363,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1730 Kbps","isStreaming":false,"title":"Vuelo Blanco de Gaviota (Days of Pearly Spencer)","artist":"Ana Belén","album":"Ana Belén 70","uri":"http://100.93.223.101:8096/Audio/0ce89be2ff7b15e21aa4698b89b86d0f/stream.flac?static=true&mediaSourceId=0ce89be2ff7b15e21aa4698b89b86d0f&tag=33f2063093329a5d068537c86fd87da5&t.flac","trackType":"flac"} Feb 24 16:21:01 raspi2 volumio[1128]: verbose: CURRENT POSITION 0 Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreStateMachine::syncState stateService play Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreStateMachine::syncState currentStatus play Feb 24 16:21:01 raspi2 volumio[1128]: info: Received an update from plugin. extracting info from payload Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreStateMachine::pushState Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreCommandRouter::volumioPushState Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreStateMachine::pushState Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreCommandRouter::volumioPushState Feb 24 16:21:01 raspi2 volumio[1128]: info: ControllerMpd::pushState Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreCommandRouter::servicePushState Feb 24 16:21:01 raspi2 volumio[1128]: info: CorePlayQueue::getTrack 0 Feb 24 16:21:01 raspi2 volumio[1128]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2358,"duration":363,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1730 Kbps","isStreaming":false,"title":"Vuelo Blanco de Gaviota (Days of Pearly Spencer)","artist":"Ana Belén","album":"Ana Belén 70","uri":"http://100.93.223.101:8096/Audio/0ce89be2ff7b15e21aa4698b89b86d0f/stream.flac?static=true&mediaSourceId=0ce89be2ff7b15e21aa4698b89b86d0f&tag=33f2063093329a5d068537c86fd87da5&t.flac","trackType":"flac"} Feb 24 16:21:01 raspi2 volumio[1128]: verbose: CURRENT POSITION 0 Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreStateMachine::syncState stateService play Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreStateMachine::syncState currentStatus play Feb 24 16:21:01 raspi2 volumio[1128]: info: Received an update from plugin. extracting info from payload Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreStateMachine::pushState Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreCommandRouter::volumioPushState Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreStateMachine::pushState Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreCommandRouter::volumioPushState Feb 24 16:21:01 raspi2 volumio5-onboarding[1643]: time=2026-02-24T16:21:01.502-06:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.3.6:41562 @ 0x34bb050" state=STATUS_PLAYING positionMs=1236 volume=28 Feb 24 16:21:01 raspi2 volumio5-onboarding[1643]: time=2026-02-24T16:21:01.503-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.3.6:41562 @ 0x34bb050" id="jellyfin/admin@84ed3b41aa974799902e0fb151c2db45/song@songId=0ce89be2ff7b15e21aa4698b89b86d0f" title="Vuelo Blanco de Gaviota (Days of Pearly Spencer)" Feb 24 16:21:01 raspi2 volumio5-onboarding[1643]: time=2026-02-24T16:21:01.511-06:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.3.6:41562 @ 0x34bb050" state=STATUS_PLAYING positionMs=1236 volume=28 Feb 24 16:21:01 raspi2 volumio5-onboarding[1643]: time=2026-02-24T16:21:01.513-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.3.6:41562 @ 0x34bb050" id="jellyfin/admin@84ed3b41aa974799902e0fb151c2db45/song@songId=0ce89be2ff7b15e21aa4698b89b86d0f" title="Vuelo Blanco de Gaviota (Days of Pearly Spencer)" Feb 24 16:21:01 raspi2 volumio5-onboarding[1643]: time=2026-02-24T16:21:01.520-06:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.3.6:41562 @ 0x34bb050" state=STATUS_PLAYING positionMs=1236 volume=28 Feb 24 16:21:01 raspi2 volumio5-onboarding[1643]: time=2026-02-24T16:21:01.521-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.3.6:41562 @ 0x34bb050" id="jellyfin/admin@84ed3b41aa974799902e0fb151c2db45/song@songId=0ce89be2ff7b15e21aa4698b89b86d0f" title="Vuelo Blanco de Gaviota (Days of Pearly Spencer)" Feb 24 16:21:01 raspi2 volumio5-onboarding[1643]: time=2026-02-24T16:21:01.523-06:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.3.6:41562 @ 0x34bb050" state=STATUS_PLAYING positionMs=1236 volume=28 Feb 24 16:21:01 raspi2 volumio5-onboarding[1643]: time=2026-02-24T16:21:01.524-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.3.6:41562 @ 0x34bb050" id="jellyfin/admin@84ed3b41aa974799902e0fb151c2db45/song@songId=0ce89be2ff7b15e21aa4698b89b86d0f" title="Vuelo Blanco de Gaviota (Days of Pearly Spencer)" Feb 24 16:21:01 raspi2 volumio5-onboarding[1643]: time=2026-02-24T16:21:01.528-06:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.3.6:41562 @ 0x34bb050" state=STATUS_PLAYING positionMs=1236 volume=28 Feb 24 16:21:01 raspi2 volumio5-onboarding[1643]: time=2026-02-24T16:21:01.530-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.3.6:41562 @ 0x34bb050" id="jellyfin/admin@84ed3b41aa974799902e0fb151c2db45/song@songId=0ce89be2ff7b15e21aa4698b89b86d0f" title="Vuelo Blanco de Gaviota (Days of Pearly Spencer)" Feb 24 16:21:01 raspi2 volumio5-onboarding[1643]: time=2026-02-24T16:21:01.533-06:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.3.6:41562 @ 0x34bb050" state=STATUS_PLAYING positionMs=1236 volume=28 Feb 24 16:21:01 raspi2 volumio5-onboarding[1643]: time=2026-02-24T16:21:01.534-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.3.6:41562 @ 0x34bb050" id="jellyfin/admin@84ed3b41aa974799902e0fb151c2db45/song@songId=0ce89be2ff7b15e21aa4698b89b86d0f" title="Vuelo Blanco de Gaviota (Days of Pearly Spencer)" Feb 24 16:21:01 raspi2 volumio[1128]: info: ------------------------------ 348ms Feb 24 16:21:01 raspi2 volumio[1128]: info: ------------------------------ 340ms Feb 24 16:21:01 raspi2 volumio[1128]: info: ------------------------------ 340ms Feb 24 16:21:01 raspi2 volumio[1128]: info: Pushing Favourites {"favourite":false} Feb 24 16:21:01 raspi2 volumio[1128]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Feb 24 16:21:01 raspi2 volumio[1128]: info: FusionDsp - ---- read samplerate from file: 44100 Feb 24 16:21:01 raspi2 volumio[1128]: info: sendMpdCommand playlistinfo took 201 milliseconds Feb 24 16:21:01 raspi2 volumio[1128]: info: sendMpdCommand playlistinfo took 203 milliseconds Feb 24 16:21:01 raspi2 volumio[1128]: verbose: ControllerMpd::parseTrackInfo Feb 24 16:21:01 raspi2 volumio[1128]: verbose: ControllerMpd::parseTrackInfo Feb 24 16:21:01 raspi2 volumio[1128]: info: ControllerMpd::pushState Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreCommandRouter::servicePushState Feb 24 16:21:01 raspi2 volumio[1128]: info: CorePlayQueue::getTrack 0 Feb 24 16:21:01 raspi2 volumio[1128]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2358,"duration":363,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1730 Kbps","isStreaming":false,"title":"Vuelo Blanco de Gaviota (Days of Pearly Spencer)","artist":"Ana Belén","album":"Ana Belén 70","uri":"http://100.93.223.101:8096/Audio/0ce89be2ff7b15e21aa4698b89b86d0f/stream.flac?static=true&mediaSourceId=0ce89be2ff7b15e21aa4698b89b86d0f&tag=33f2063093329a5d068537c86fd87da5&t.flac","trackType":"flac"} Feb 24 16:21:01 raspi2 volumio[1128]: verbose: CURRENT POSITION 0 Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreStateMachine::syncState stateService play Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreStateMachine::syncState currentStatus play Feb 24 16:21:01 raspi2 volumio[1128]: info: Received an update from plugin. extracting info from payload Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreStateMachine::pushState Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreCommandRouter::volumioPushState Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreStateMachine::pushState Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreCommandRouter::volumioPushState Feb 24 16:21:01 raspi2 volumio[1128]: info: ControllerMpd::pushState Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreCommandRouter::servicePushState Feb 24 16:21:01 raspi2 volumio[1128]: info: CorePlayQueue::getTrack 0 Feb 24 16:21:01 raspi2 volumio[1128]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2358,"duration":363,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1730 Kbps","isStreaming":false,"title":"Vuelo Blanco de Gaviota (Days of Pearly Spencer)","artist":"Ana Belén","album":"Ana Belén 70","uri":"http://100.93.223.101:8096/Audio/0ce89be2ff7b15e21aa4698b89b86d0f/stream.flac?static=true&mediaSourceId=0ce89be2ff7b15e21aa4698b89b86d0f&tag=33f2063093329a5d068537c86fd87da5&t.flac","trackType":"flac"} Feb 24 16:21:01 raspi2 volumio[1128]: verbose: CURRENT POSITION 0 Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreStateMachine::syncState stateService play Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreStateMachine::syncState currentStatus play Feb 24 16:21:01 raspi2 volumio[1128]: info: Received an update from plugin. extracting info from payload Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreStateMachine::pushState Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreCommandRouter::volumioPushState Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreStateMachine::pushState Feb 24 16:21:01 raspi2 volumio[1128]: info: CoreCommandRouter::volumioPushState Feb 24 16:21:01 raspi2 volumio5-onboarding[1643]: time=2026-02-24T16:21:01.671-06:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.3.6:41562 @ 0x34bb050" state=STATUS_PLAYING positionMs=1614 volume=28 Feb 24 16:21:01 raspi2 volumio5-onboarding[1643]: time=2026-02-24T16:21:01.673-06:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.3.6:41562 @ 0x34bb050" state=STATUS_PLAYING positionMs=1614 volume=28 Feb 24 16:21:01 raspi2 volumio5-onboarding[1643]: time=2026-02-24T16:21:01.674-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.3.6:41562 @ 0x34bb050" id="jellyfin/admin@84ed3b41aa974799902e0fb151c2db45/song@songId=0ce89be2ff7b15e21aa4698b89b86d0f" title="Vuelo Blanco de Gaviota (Days of Pearly Spencer)" Feb 24 16:21:01 raspi2 volumio5-onboarding[1643]: time=2026-02-24T16:21:01.678-06:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.3.6:41562 @ 0x34bb050" state=STATUS_PLAYING positionMs=1614 volume=28 Feb 24 16:21:01 raspi2 volumio5-onboarding[1643]: time=2026-02-24T16:21:01.682-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.3.6:41562 @ 0x34bb050" id="jellyfin/admin@84ed3b41aa974799902e0fb151c2db45/song@songId=0ce89be2ff7b15e21aa4698b89b86d0f" title="Vuelo Blanco de Gaviota (Days of Pearly Spencer)" Feb 24 16:21:01 raspi2 volumio5-onboarding[1643]: time=2026-02-24T16:21:01.679-06:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.3.6:41562 @ 0x34bb050" state=STATUS_PLAYING positionMs=1614 volume=28 Feb 24 16:21:01 raspi2 volumio5-onboarding[1643]: time=2026-02-24T16:21:01.680-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.3.6:41562 @ 0x34bb050" id="jellyfin/admin@84ed3b41aa974799902e0fb151c2db45/song@songId=0ce89be2ff7b15e21aa4698b89b86d0f" title="Vuelo Blanco de Gaviota (Days of Pearly Spencer)" Feb 24 16:21:01 raspi2 volumio5-onboarding[1643]: time=2026-02-24T16:21:01.689-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.3.6:41562 @ 0x34bb050" id="jellyfin/admin@84ed3b41aa974799902e0fb151c2db45/song@songId=0ce89be2ff7b15e21aa4698b89b86d0f" title="Vuelo Blanco de Gaviota (Days of Pearly Spencer)" Feb 24 16:21:01 raspi2 volumio[1128]: info: ------------------------------ 347ms Feb 24 16:21:01 raspi2 volumio[1128]: info: ------------------------------ 345ms Feb 24 16:21:01 raspi2 volumio[1128]: info: [jellyfin-play]: Reported 'start' for song: Vuelo Blanco de Gaviota (Days of Pearly Spencer) (at 1110 ms) Feb 24 16:21:01 raspi2 volumio[1128]: info: [jellyfin-play]: Reported 'timeupdate' for song: Vuelo Blanco de Gaviota (Days of Pearly Spencer) (at 2358 ms) Feb 24 16:21:01 raspi2 volumio[1128]: info: [jellyfin-play]: Mark song Vuelo Blanco de Gaviota (Days of Pearly Spencer) as played by admin. Feb 24 16:21:01 raspi2 volumio[1128]: info: FusionDsp - If filter freq >samplerate/2 then disable it Feb 24 16:21:04 raspi2 tailscaled[623]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 24 16:21:05 raspi2 volumio5-onboarding[1643]: time=2026-02-24T16:21:05.552-06:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.3.6:41562 @ 0x34bb050" latency=399.622959ms timeout=3s volume=29 Feb 24 16:21:05 raspi2 volumio[1128]: info: VolumeController::SetAlsaVolume29 Feb 24 16:21:05 raspi2 volumio[1128]: info: CoreStateMachine::pushState Feb 24 16:21:05 raspi2 volumio[1128]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 16:21:05 raspi2 volumio[1128]: info: CoreCommandRouter::volumioPushState Feb 24 16:21:05 raspi2 volumio5-onboarding[1643]: time=2026-02-24T16:21:05.604-06:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.3.6:41562 @ 0x34bb050" state=STATUS_PLAYING positionMs=5403 volume=29 Feb 24 16:21:05 raspi2 volumio5-onboarding[1643]: time=2026-02-24T16:21:05.606-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.3.6:41562 @ 0x34bb050" id="jellyfin/admin@84ed3b41aa974799902e0fb151c2db45/song@songId=0ce89be2ff7b15e21aa4698b89b86d0f" title="Vuelo Blanco de Gaviota (Days of Pearly Spencer)" Feb 24 16:21:09 raspi2 tailscaled[623]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 24 16:21:11 raspi2 volumio[1128]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:21:11 raspi2 volumio[1128]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Feb 24 16:21:11 raspi2 volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 16:21:11 raspi2 volumio[1128]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 24 16:21:11 raspi2 volumio[1128]: info: Getting Alsa Cards List without I2S DAC Feb 24 16:21:11 raspi2 volumio[1128]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Feb 24 16:21:11 raspi2 volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 16:21:12 raspi2 volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 16:21:12 raspi2 volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 16:21:12 raspi2 volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 16:21:12 raspi2 volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 16:21:12 raspi2 volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 16:21:12 raspi2 volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 16:21:12 raspi2 volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 16:21:12 raspi2 volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Feb 24 16:21:12 raspi2 volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Feb 24 16:21:14 raspi2 tailscaled[623]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 24 16:21:20 raspi2 tailscaled[623]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 24 16:21:25 raspi2 tailscaled[623]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 24 16:21:30 raspi2 tailscaled[623]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 24 16:21:35 raspi2 tailscaled[623]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 24 16:21:40 raspi2 tailscaled[623]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 24 16:21:46 raspi2 tailscaled[623]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 24 16:21:50 raspi2 volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Feb 24 16:21:50 raspi2 volumio[1128]: info: CURURI: music-library Feb 24 16:21:50 raspi2 volumio[1128]: error: Failed LSINFO: null Feb 24 16:21:50 raspi2 volumio[1128]: info: Preload queue cleared Feb 24 16:21:51 raspi2 tailscaled[623]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 24 16:21:56 raspi2 tailscaled[623]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 24 16:22:01 raspi2 tailscaled[623]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 24 16:22:02 raspi2 tailscaled[623]: control: NetInfo: NetInfo{varies=false ipv6=false ipv6os=false udp=true icmpv4=false derp=#9 portmap= link="" firewallmode="ipt-default"} Feb 24 16:22:03 raspi2 volumio[1128]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Feb 24 16:22:03 raspi2 volumio[1128]: info: Preload queue cleared Feb 24 16:22:06 raspi2 tailscaled[623]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 24 16:22:11 raspi2 tailscaled[623]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 24 16:22:12 raspi2 volumio[1128]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Feb 24 16:22:12 raspi2 volumio[1128]: info: READ Feb 24 16:22:12 raspi2 volumio[1128]: info: Preload queue cleared Feb 24 16:22:17 raspi2 tailscaled[623]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 24 16:22:18 raspi2 volumio[1128]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Feb 24 16:22:18 raspi2 volumio[1128]: info: Preload queue cleared Feb 24 16:22:22 raspi2 tailscaled[623]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 24 16:22:22 raspi2 volumio[1128]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Feb 24 16:22:24 raspi2 volumio[1128]: info: Preload queue cleared Feb 24 16:22:27 raspi2 tailscaled[623]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 24 16:22:32 raspi2 tailscaled[623]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 24 16:22:35 raspi2 volumio[1128]: info: Preload queue cleared Feb 24 16:22:35 raspi2 volumio[1128]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 24 16:22:35 raspi2 volumio[1128]: info: CoreStateMachine::ClearQueue Feb 24 16:22:35 raspi2 volumio[1128]: info: CoreStateMachine::stop Feb 24 16:22:35 raspi2 volumio[1128]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 16:22:35 raspi2 volumio[1128]: info: CoreStateMachine::stPlaybackTimer Feb 24 16:22:35 raspi2 volumio[1128]: info: CoreStateMachine::updateTrackBlock Feb 24 16:22:35 raspi2 volumio[1128]: info: CorePlayQueue::getTrackBlock Feb 24 16:22:35 raspi2 volumio[1128]: info: CoreStateMachine::pushState Feb 24 16:22:35 raspi2 volumio[1128]: info: CorePlayQueue::getTrack 0 Feb 24 16:22:35 raspi2 volumio[1128]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 16:22:35 raspi2 volumio[1128]: info: CoreCommandRouter::volumioPushState Feb 24 16:22:35 raspi2 volumio[1128]: info: CoreStateMachine::serviceStop Feb 24 16:22:35 raspi2 volumio[1128]: info: CorePlayQueue::getTrack 0 Feb 24 16:22:35 raspi2 volumio[1128]: info: CoreCommandRouter::serviceStop Feb 24 16:22:35 raspi2 volumio[1128]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 24 16:22:35 raspi2 volumio[1128]: info: ControllerMpd::stop Feb 24 16:22:35 raspi2 volumio[1128]: verbose: ControllerMpd::sendMpdCommand stop Feb 24 16:22:35 raspi2 volumio[1128]: info: CorePlayQueue::clearPlayQueue Feb 24 16:22:35 raspi2 volumio[1128]: info: CorePlayQueue::saveQueue Feb 24 16:22:35 raspi2 volumio[1128]: info: CoreCommandRouter::volumioPushQueue Feb 24 16:22:35 raspi2 volumio[1128]: info: CoreStateMachine::addQueueItems Feb 24 16:22:35 raspi2 volumio[1128]: info: CorePlayQueue::addQueueItems Feb 24 16:22:35 raspi2 volumio[1128]: info: Preload queue cleared Feb 24 16:22:35 raspi2 volumio[1128]: info: Adding Item to queue: http://yp.shoutcast.com/sbin/tunein-station.m3u?id=1132806 Feb 24 16:22:35 raspi2 volumio[1128]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Feb 24 16:22:35 raspi2 volumio5-onboarding[1643]: time=2026-02-24T16:22:35.871-06:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.3.6:41562 @ 0x34bb050" state=STATUS_STOPPED positionMs=0 volume=29 Feb 24 16:22:35 raspi2 volumio5-onboarding[1643]: time=2026-02-24T16:22:35.872-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.3.6:41562 @ 0x34bb050" id="jellyfin/admin@84ed3b41aa974799902e0fb151c2db45/song@songId=0ce89be2ff7b15e21aa4698b89b86d0f" title="Vuelo Blanco de Gaviota (Days of Pearly Spencer)" Feb 24 16:22:35 raspi2 volumio[1128]: info: CoreCommandRouter::volumioPushQueue Feb 24 16:22:35 raspi2 volumio[1128]: info: CorePlayQueue::saveQueue Feb 24 16:22:35 raspi2 volumio[1128]: info: CoreStateMachine::updateTrackBlock Feb 24 16:22:35 raspi2 volumio[1128]: info: CorePlayQueue::getTrackBlock Feb 24 16:22:35 raspi2 volumio[1128]: info: CoreCommandRouter::volumioPlay Feb 24 16:22:35 raspi2 volumio[1128]: info: CoreStateMachine::play index 0 Feb 24 16:22:35 raspi2 volumio[1128]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 16:22:35 raspi2 volumio[1128]: info: CoreStateMachine::stop Feb 24 16:22:35 raspi2 volumio[1128]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 16:22:35 raspi2 volumio[1128]: info: CoreStateMachine::play index undefined Feb 24 16:22:35 raspi2 volumio[1128]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 16:22:35 raspi2 volumio[1128]: info: CorePlayQueue::getTrack 0 Feb 24 16:22:35 raspi2 volumio[1128]: info: CoreStateMachine::startPlaybackTimer Feb 24 16:22:35 raspi2 volumio[1128]: info: CorePlayQueue::getTrack 0 Feb 24 16:22:35 raspi2 volumio[1128]: info: [1771971755904] ControllerWebradio::clearAddPlayTrack Feb 24 16:22:35 raspi2 volumio[1128]: verbose: ControllerMpd::sendMpdCommand stop Feb 24 16:22:35 raspi2 volumio[1128]: info: sendMpdCommand stop took 59 milliseconds Feb 24 16:22:35 raspi2 volumio[1128]: info: ControllerMpd::getState Feb 24 16:22:35 raspi2 volumio[1128]: verbose: ControllerMpd::sendMpdCommand status Feb 24 16:22:35 raspi2 volumio[1128]: info: Feb 24 16:22:35 raspi2 volumio[1128]: ---------------------------- MPD announces state update: player Feb 24 16:22:35 raspi2 volumio[1128]: info: ControllerMpd::getState Feb 24 16:22:35 raspi2 volumio[1128]: verbose: ControllerMpd::sendMpdCommand status Feb 24 16:22:35 raspi2 volumio[1128]: info: sendMpdCommand stop took 22 milliseconds Feb 24 16:22:35 raspi2 volumio[1128]: verbose: ControllerMpd::sendMpdCommand clear Feb 24 16:22:35 raspi2 volumio[1128]: info: Feb 24 16:22:35 raspi2 volumio[1128]: ---------------------------- MPD announces state update: player Feb 24 16:22:35 raspi2 volumio[1128]: info: ControllerMpd::getState Feb 24 16:22:35 raspi2 volumio[1128]: verbose: ControllerMpd::sendMpdCommand status Feb 24 16:22:35 raspi2 volumio[1128]: info: Feb 24 16:22:35 raspi2 volumio[1128]: ---------------------------- MPD announces state update: player Feb 24 16:22:35 raspi2 volumio[1128]: info: ControllerMpd::getState Feb 24 16:22:35 raspi2 volumio[1128]: verbose: ControllerMpd::sendMpdCommand status Feb 24 16:22:35 raspi2 volumio[1128]: info: Feb 24 16:22:35 raspi2 volumio[1128]: ---------------------------- MPD announces system playlist update Feb 24 16:22:35 raspi2 volumio[1128]: info: Ignoring MPD Status Update Feb 24 16:22:35 raspi2 volumio[1128]: info: sendMpdCommand status took 19 milliseconds Feb 24 16:22:35 raspi2 volumio[1128]: info: sendMpdCommand status took 18 milliseconds Feb 24 16:22:35 raspi2 volumio[1128]: info: sendMpdCommand clear took 16 milliseconds Feb 24 16:22:35 raspi2 volumio[1128]: info: sendMpdCommand status took 12 milliseconds Feb 24 16:22:35 raspi2 volumio[1128]: info: sendMpdCommand status took 11 milliseconds Feb 24 16:22:35 raspi2 volumio[1128]: verbose: ControllerMpd::parseState Feb 24 16:22:35 raspi2 volumio[1128]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 16:22:35 raspi2 volumio[1128]: verbose: ControllerMpd::parseState Feb 24 16:22:35 raspi2 volumio[1128]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 16:22:35 raspi2 volumio[1128]: verbose: ControllerMpd::sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=1132806" Feb 24 16:22:35 raspi2 volumio[1128]: verbose: ControllerMpd::parseState Feb 24 16:22:35 raspi2 volumio[1128]: verbose: ControllerMpd::parseState Feb 24 16:22:35 raspi2 volumio[1128]: info: ControllerMpd::pushState Feb 24 16:22:35 raspi2 volumio[1128]: info: CoreCommandRouter::servicePushState Feb 24 16:22:35 raspi2 volumio[1128]: info: CoreStateMachine::pushState Feb 24 16:22:35 raspi2 volumio[1128]: info: CorePlayQueue::getTrack 0 Feb 24 16:22:35 raspi2 volumio[1128]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 16:22:35 raspi2 volumio[1128]: info: CoreCommandRouter::volumioPushState Feb 24 16:22:35 raspi2 volumio[1128]: info: CorePlayQueue::getTrack 0 Feb 24 16:22:35 raspi2 volumio[1128]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Feb 24 16:22:35 raspi2 volumio[1128]: info: ControllerMpd::pushState Feb 24 16:22:35 raspi2 volumio[1128]: info: CoreCommandRouter::servicePushState Feb 24 16:22:35 raspi2 volumio[1128]: info: CoreStateMachine::pushState Feb 24 16:22:35 raspi2 volumio[1128]: info: CorePlayQueue::getTrack 0 Feb 24 16:22:35 raspi2 volumio[1128]: info: CoreCommandRouter::volumioPushState Feb 24 16:22:35 raspi2 volumio[1128]: info: CorePlayQueue::getTrack 0 Feb 24 16:22:35 raspi2 volumio[1128]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Feb 24 16:22:35 raspi2 volumio5-onboarding[1643]: time=2026-02-24T16:22:35.977-06:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.3.6:41562 @ 0x34bb050" state=STATUS_STOPPED positionMs=0 volume=29 Feb 24 16:22:35 raspi2 volumio5-onboarding[1643]: time=2026-02-24T16:22:35.978-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.3.6:41562 @ 0x34bb050" id="http://yp.shoutcast.com/sbin/tunein-station.m3u?id=1132806" title="Hot Hitz 80's" Feb 24 16:22:35 raspi2 volumio[1128]: info: ------------------------------ 57ms Feb 24 16:22:35 raspi2 volumio[1128]: info: ------------------------------ 55ms Feb 24 16:22:35 raspi2 volumio[1128]: info: Feb 24 16:22:35 raspi2 volumio[1128]: ---------------------------- MPD announces system playlist update Feb 24 16:22:35 raspi2 volumio[1128]: info: Ignoring MPD Status Update Feb 24 16:22:35 raspi2 volumio5-onboarding[1643]: time=2026-02-24T16:22:35.992-06:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.3.6:41562 @ 0x34bb050" state=STATUS_STOPPED positionMs=0 volume=29 Feb 24 16:22:35 raspi2 volumio5-onboarding[1643]: time=2026-02-24T16:22:35.993-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.3.6:41562 @ 0x34bb050" id="http://yp.shoutcast.com/sbin/tunein-station.m3u?id=1132806" title="Hot Hitz 80's" Feb 24 16:22:35 raspi2 volumio[1128]: info: Feb 24 16:22:35 raspi2 volumio[1128]: ---------------------------- MPD announces system playlist update Feb 24 16:22:35 raspi2 volumio[1128]: info: Ignoring MPD Status Update Feb 24 16:22:36 raspi2 volumio[1128]: error: updateQueue error: null Feb 24 16:22:36 raspi2 volumio[1128]: info: ------------------------------ 66ms Feb 24 16:22:36 raspi2 volumio[1128]: info: sendMpdCommand playlistinfo took 62 milliseconds Feb 24 16:22:36 raspi2 volumio[1128]: info: sendMpdCommand playlistinfo took 62 milliseconds Feb 24 16:22:36 raspi2 volumio[1128]: verbose: ControllerMpd::parseTrackInfo Feb 24 16:22:36 raspi2 volumio[1128]: verbose: ControllerMpd::parseTrackInfo Feb 24 16:22:36 raspi2 volumio[1128]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Feb 24 16:22:36 raspi2 volumio[1128]: info: ------------------------------ 90ms Feb 24 16:22:36 raspi2 volumio[1128]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 24 16:22:36 raspi2 volumio[1128]: TypeError: Cannot read properties of undefined (reading 'split') Feb 24 16:22:36 raspi2 volumio[1128]: at Promise._successFn (/volumio/app/plugins/music_service/mpd/index.js:280:60) Feb 24 16:22:36 raspi2 volumio[1128]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Feb 24 16:22:36 raspi2 volumio[1128]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Feb 24 16:22:36 raspi2 volumio[1128]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 24 16:22:37 raspi2 sudo[6154]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-24 16:21' Feb 24 16:22:37 raspi2 sudo[6154]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="a78d359cf1dc63ac74e9d151015afd30d31a709a" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Feb 5 14:07:07 UTC 2026" VOLUMIO_VERSION="4.096" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5e37060f9823263a753eb5e84030104f"